I have been having a few issues with the sa-learn feature of spamassassin with roundcube webmail lately. The command 'sa-learn --spam /var/vmail/mydomain/user/.Junk/cur' from terminal will find and learn all the junk which is in the folder. When I then go to run 'sa-learn --dump magic' it returns the stats of the 3 junk mails it has learned. Using the markasjunk2 plugin for roundcube, I learn the commands using cmd_learn which runs the same command is first stated above, except when I run the --dump magic after marking as junk in the webmail, the database stats haven't changed. As I would expect there to be an increase in the number of spam messages it has learned. Anyone know what I'm doing wrong? heres an edited log file of the markasjunk2: Code: [16-Nov-2010 21:23:17 +0000]: sa-learn -D --spam --username=admin /tmp/rcmSALearnb1vy39 2>&1 [16-Nov-2010 21:23:17 +0000]: array ( 0 => 'Nov 16 21:23:15.653 [15117] dbg: logger: adding facilities: all', 1 => 'Nov 16 21:23:15.653 [15117] dbg: logger: logging level is DBG', 2 => 'Nov 16 21:23:15.654 [15117] dbg: generic: SpamAssassin version 3.3.1', 3 => 'Nov 16 21:23:15.654 [15117] dbg: generic: Perl 5.010001, PREFIX=/usr, DEF_RULES_DIR=/usr/share/spamassassin, LOCAL_RULES_DIR=/etc/spamassassin, LOCAL_STATE_DIR=/var/lib/spamassassin', 4 => 'Nov 16 21:23:15.654 [15117] dbg: config: timing enabled', 5 => 'Nov 16 21:23:15.655 [15117] dbg: config: score set 0 chosen.', 6 => 'Nov 16 21:23:15.657 [15117] dbg: util: running in taint mode? yes', 7 => 'Nov 16 21:23:15.657 [15117] dbg: util: taint mode: deleting unsafe environment variables, resetting PATH', 8 => 'Nov 16 21:23:15.657 [15117] dbg: util: PATH included \'/usr/local/bin\', keeping', 9 => 'Nov 16 21:23:15.657 [15117] dbg: util: PATH included \'/usr/bin\', keeping', 10 => 'Nov 16 21:23:15.658 [15117] dbg: util: PATH included \'/bin\', keeping', 11 => 'Nov 16 21:23:15.658 [15117] dbg: util: final PATH set to: /usr/local/bin:/usr/bin:/bin', 12 => 'Nov 16 21:23:15.664 [15117] dbg: dns: is Net::DNS::Resolver available? yes', 13 => 'Nov 16 21:23:15.665 [15117] dbg: dns: Net::DNS version: 0.65', 14 => 'Nov 16 21:23:15.665 [15117] dbg: config: using "/etc/spamassassin" for site rules pre files', 15 => 'Nov 16 21:23:15.665 [15117] dbg: config: read file /etc/spamassassin/init.pre', 16 => 'Nov 16 21:23:15.666 [15117] dbg: config: read file /etc/spamassassin/v310.pre', 17 => 'Nov 16 21:23:15.666 [15117] dbg: config: read file /etc/spamassassin/v312.pre', 18 => 'Nov 16 21:23:15.666 [15117] dbg: config: read file /etc/spamassassin/v320.pre', 19 => 'Nov 16 21:23:15.666 [15117] dbg: config: read file /etc/spamassassin/v330.pre', 20 => 'Nov 16 21:23:15.666 [15117] dbg: config: using "/var/lib/spamassassin/3.003001" for sys rules pre files', 21 => 'Nov 16 21:23:15.666 [15117] dbg: config: using "/var/lib/spamassassin/3.003001" for default rules dir', 22 => 'Nov 16 21:23:15.667 [15117] dbg: config: read file /var/lib/spamassassin/3.003001/updates_spamassassin_org.cf', 23 => 'Nov 16 21:23:15.667 [15117] dbg: config: using "/etc/spamassassin" for site rules dir', 24 => 'Nov 16 21:23:15.667 [15117] dbg: config: read file /etc/spamassassin/65_debian.cf', 25 => 'Nov 16 21:23:15.667 [15117] dbg: config: read file /etc/spamassassin/local.cf', 26 => 'Nov 16 21:23:15.669 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDNSBL from @INC', 27 => 'Nov 16 21:23:15.678 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::Hashcash from @INC', 28 => 'Nov 16 21:23:15.691 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::SPF from @INC', 29 => 'Nov 16 21:23:15.697 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::Pyzor from @INC', 30 => 'Nov 16 21:23:15.701 [15117] dbg: pyzor: network tests on, attempting Pyzor', 31 => 'Nov 16 21:23:15.701 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::Razor2 from @INC', 32 => 'Nov 16 21:23:15.705 [15117] dbg: razor2: razor2 is not available', 33 => 'Nov 16 21:23:15.705 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::SpamCop from @INC', 34 => 'Nov 16 21:23:15.726 [15117] dbg: reporter: network tests on, attempting SpamCop', 35 => 'Nov 16 21:23:15.726 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC', 36 => 'Nov 16 21:23:15.728 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::WhiteListSubject from @INC', 37 => 'Nov 16 21:23:15.730 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEHeader from @INC', 38 => 'Nov 16 21:23:15.732 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::ReplaceTags from @INC', 39 => 'Nov 16 21:23:15.734 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::DKIM from @INC', 40 => 'Nov 16 21:23:15.742 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::Check from @INC', 41 => 'Nov 16 21:23:15.754 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTTPSMismatch from @INC', 42 => 'Nov 16 21:23:15.755 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDetail from @INC', 43 => 'Nov 16 21:23:15.758 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::Bayes from @INC', 44 => 'Nov 16 21:23:15.773 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::BodyEval from @INC', 45 => 'Nov 16 21:23:15.776 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::DNSEval from @INC', 46 => 'Nov 16 21:23:15.780 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTMLEval from @INC', 47 => 'Nov 16 21:23:15.783 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::HeaderEval from @INC', 48 => 'Nov 16 21:23:15.794 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEEval from @INC', 49 => 'Nov 16 21:23:15.799 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::RelayEval from @INC', 50 => 'Nov 16 21:23:15.803 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIEval from @INC', 51 => 'Nov 16 21:23:15.805 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::WLBLEval from @INC', 52 => 'Nov 16 21:23:15.808 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::VBounce from @INC', 53 => 'Nov 16 21:23:15.810 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::ImageInfo from @INC', 54 => 'Nov 16 21:23:15.814 [15117] dbg: plugin: loading Mail::SpamAssassin::Plugin::FreeMail from @INC', 55 => 'Nov 16 21:23:15.820 [15117] dbg: config: fixed relative path: /var/lib/spamassassin/3.003001/updates_spamassassin_org/10_default_prefs.cf', ................. 61 => 'Nov 16 21:23:15.833 [15117] dbg: config: fixed relative path: /var/lib/spamassassin/3.003001/updates_spamassassin_org/20_aux_tlds.cf', 62 => 'Nov 16 21:23:15.833 [15117] dbg: config: using "/var/lib/spamassassin/3.003001/updates_spamassassin_org/20_aux_tlds.cf" for included file', 63 => 'Nov 16 21:23:15.833 [15117] dbg: config: read file /var/lib/spamassassin/3.003001/updates_spamassassin_org/20_aux_tlds.cf', 64 => 'Nov 16 21:23:15.842 [15117] dbg: config: fixed relative path: /var/lib/spamassassin/3.003001/updates_spamassassin_org/20_body_tests.cf', 65 => 'Nov 16 21:23:15.842 [15117] dbg: config: using "/var/lib/spamassassin/3.003001/updates_spamassassin_org/20_body_tests.cf" "/var/lib/spamassassin/3.003001/updates_spamassassin_org/20_phrases.cf" for included file', 175 => 'Nov 16 21:23:16.137 [15117] dbg: config: read file /var/lib/spamassassin/3.003001/updates_spamassassin_org/30_text_pt_br.cf', 176 => 'Nov 16 21:23:16.138 [15117] dbg: config: fixed relative path: /var/lib/spamassassin/3.003001/updates_spamassassin_org/50_scores.cf', 228 => 'Nov 16 21:23:17.206 [15117] dbg: rules: __MO_OL_25340 merged duplicates: __MO_OL_4EEDB __MO_OL_7533E', 229 => 'Nov 16 21:23:17.207 [15117] dbg: rules: __DOS_HAS_MAILING_LIST merged duplicates: __ML4 __freemail_safe_ml2', 230 => 'Nov 16 21:23:17.207 [15117] dbg: rules: __ML2 merged duplicates: __freemail_safe_ml1', 231 => 'Nov 16 21:23:17.207 [15117] dbg: rules: __MO_OL_58CB5 merged duplicates: __MO_OL_B4B40', 232 => 'Nov 16 21:23:17.207 [15117] dbg: rules: __DOS_HAS_ANY_URI merged duplicates: __HAS_ANY_URI', 233 => 'Nov 16 21:23:17.207 [15117] dbg: rules: __FH_HAS_XMSMAIL merged duplicates: __HAS_MSMAIL_PRI', 234 => 'Nov 16 21:23:17.207 [15117] dbg: rules: CTYPE_001C_A merged duplicates: DATE_IN_FUTURE_96_XX', 235 => 'Nov 16 21:23:17.207 [15117] dbg: rules: __MO_OL_72641 merged duplicates: __MO_OL_A842E', 236 => 'Nov 16 21:23:17.208 [15117] dbg: rules: __HAS_X_MAILING_LIST merged duplicates: __freemail_safe_ml3', 237 => 'Nov 16 21:23:17.208 [15117] dbg: rules: __MO_OL_4BF4C merged duplicates: __MO_OL_F6D01', 238 => 'Nov 16 21:23:17.208 [15117] dbg: rules: __MO_OL_F475E merged duplicates: __MO_OL_FF5C8', 239 => 'Nov 16 21:23:17.209 [15117] dbg: config: finish parsing', 240 => 'Nov 16 21:23:17.255 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::ReplaceTags=HASH(0xa4d01b0) implements \'finish_parsing_end\', priority 0', 241 => 'Nov 16 21:23:17.255 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::FreeMail=HASH(0xa731ff0) implements \'finish_parsing_end\', priority 0', 242 => 'Nov 16 21:23:17.255 [15117] dbg: replacetags: replacing tags', 243 => 'Nov 16 21:23:17.319 [15117] dbg: replacetags: done replacing tags', 244 => 'Nov 16 21:23:17.319 [15117] dbg: FreeMail: loaded freemail_domains entries: 2106 normal, 23 wildcard', 245 => 'Nov 16 21:23:17.322 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learner_new\', priority 0', 246 => 'Nov 16 21:23:17.323 [15117] dbg: bayes: learner_new self=Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8), bayes_store_module=Mail::SpamAssassin::BayesStore::DBM', 247 => 'Nov 16 21:23:17.345 [15117] dbg: bayes: learner_new: got store=Mail::SpamAssassin::BayesStore::DBM=HASH(0xaa276f0)', 248 => 'Nov 16 21:23:17.345 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learner_is_scan_available\', priority 0', 249 => 'Nov 16 21:23:17.345 [15117] dbg: bayes: tie-ing to DB file R/O /var/www/.spamassassin/bayes_toks', 250 => 'Nov 16 21:23:17.346 [15117] dbg: bayes: tie-ing to DB file R/O /var/www/.spamassassin/bayes_seen', 251 => 'Nov 16 21:23:17.347 [15117] dbg: bayes: found bayes db version 3', 252 => 'Nov 16 21:23:17.348 [15117] dbg: bayes: DB journal sync: last sync: 0', 253 => 'Nov 16 21:23:17.348 [15117] dbg: bayes: not available for scanning, only 6 spam(s) in bayes DB < 200', 254 => 'Nov 16 21:23:17.348 [15117] dbg: bayes: untie-ing', 255 => 'Nov 16 21:23:17.349 [15117] dbg: config: score set 1 chosen.', 256 => 'Nov 16 21:23:17.349 [15117] dbg: sa-learn: spamtest initialized', 257 => 'Nov 16 21:23:17.349 [15117] dbg: learn: initializing learner', 258 => 'Nov 16 21:23:17.349 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learner_sync\', priority 0', 259 => 'Nov 16 21:23:17.350 [15117] dbg: bayes: bayes journal sync starting', 260 => 'Nov 16 21:23:17.350 [15117] dbg: bayes: bayes journal sync completed', 261 => 'Nov 16 21:23:17.350 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learner_expire_old_training\', priority 0', 262 => 'Nov 16 21:23:17.350 [15117] dbg: bayes: expiry starting', 263 => 'Nov 16 21:23:17.350 [15117] dbg: locker: mode is 438', 264 => 'Nov 16 21:23:17.351 [15117] dbg: locker: safe_lock: created /var/www/.spamassassin/bayes.mutex', 265 => 'Nov 16 21:23:17.351 [15117] dbg: locker: safe_lock: trying to get lock on /var/www/.spamassassin/bayes with 300 timeout', 266 => 'Nov 16 21:23:17.351 [15117] dbg: locker: safe_lock: link to /var/www/.spamassassin/bayes.mutex: link ok', 267 => 'Nov 16 21:23:17.351 [15117] dbg: bayes: tie-ing to DB file R/W /var/www/.spamassassin/bayes_toks', 268 => 'Nov 16 21:23:17.352 [15117] dbg: bayes: tie-ing to DB file R/W /var/www/.spamassassin/bayes_seen', 269 => 'Nov 16 21:23:17.353 [15117] dbg: bayes: found bayes db version 3', 270 => 'Nov 16 21:23:17.353 [15117] dbg: locker: refresh_lock: refresh /var/www/.spamassassin/bayes.mutex', 271 => 'Nov 16 21:23:17.354 [15117] dbg: bayes: DB expiry: tokens in DB: 831, Expiry max size: 150000, Oldest atime: 1286495412, Newest atime: 1289863912, Last expire: 0, Current time: 1289942597', 272 => 'Nov 16 21:23:17.354 [15117] dbg: bayes: expiry completed', 273 => 'Nov 16 21:23:17.355 [15117] dbg: config: time limit 300.0 s', 274 => 'Nov 16 21:23:17.357 [15117] dbg: message: main message type: text/plain', 275 => 'Nov 16 21:23:17.357 [15117] dbg: learn: learning spam', 276 => 'Nov 16 21:23:17.357 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learn_message\', priority 0', 277 => 'Nov 16 21:23:17.358 [15117] dbg: check: pms new, time limit in 299.997 s', 278 => 'Nov 16 21:23:17.358 [15117] dbg: config: trusted_networks are not configured; it is recommended that you configure trusted_networks manually', 279 => 'Nov 16 21:23:17.359 [15117] dbg: received-header: parsed as [ ip=127.0.0.1 rdns=localhost.localdomain helo=localhost by=server1. ident= envfrom= intl=0 id=D00B2440CE9 auth= msa=0 ]', 280 => 'Nov 16 21:23:17.359 [15117] dbg: received-header: \'from\' 127.0.0.1 has private IP', 281 => 'Nov 16 21:23:17.359 [15117] dbg: received-header: relay 127.0.0.1 trusted? yes internal? yes msa? no', 282 => 'Nov 16 21:23:17.364 [15117] dbg: received-header: parsed as [ ip=127.0.0.1 rdns= helo=server1. by=localhost ident= envfrom= intl=0 id=chfEDqnYaeCw auth= msa=0 ]', 283 => 'Nov 16 21:23:17.364 [15117] dbg: received-header: \'from\' 127.0.0.1 has private IP', 284 => 'Nov 16 21:23:17.364 [15117] dbg: received-header: relay 127.0.0.1 trusted? yes internal? yes msa? no', 285 => 'Nov 16 21:23:17.365 [15117] dbg: metadata: X-Spam-Relays-Trusted: [ ip=127.0.0.1 rdns=localhost.localdomain helo=localhost by=server1. ident= envfrom= intl=1 id=D00B2440CE9 auth= msa=0 ] [ ip=127.0.0.1 rdns= helo=server1. by=localhost ident= envfrom= intl=1 id=chfEDqnYaeCw auth= msa=0 ]', 286 => 'Nov 16 21:23:17.365 [15117] dbg: metadata: X-Spam-Relays-Untrusted:', 287 => 'Nov 16 21:23:17.365 [15117] dbg: metadata: X-Spam-Relays-Internal: [ ip=127.0.0.1 rdns=localhost.localdomain helo=localhost by=server1. ident= envfrom= intl=1 id=D00B2440CE9 auth= msa=0 ] [ ip=127.0.0.1 rdns= helo=server1. by=localhost ident= envfrom= intl=1 id=chfEDqnYaeCw auth= msa=0 ]', 288 => 'Nov 16 21:23:17.365 [15117] dbg: metadata: X-Spam-Relays-External:', 289 => 'Nov 16 21:23:17.366 [15117] dbg: message: ---- MIME PARSER START ----', 290 => 'Nov 16 21:23:17.366 [15117] dbg: message: parsing normal part', 291 => 'Nov 16 21:23:17.366 [15117] dbg: message: ---- MIME PARSER END ----', 292 => 'Nov 16 21:23:17.366 [15117] dbg: message: decoding other encoding type (8bit), ignoring', 293 => 'Nov 16 21:23:17.370 [15117] dbg: locker: refresh_lock: refresh /var/www/.spamassassin/bayes.mutex', 295 => 'Nov 16 21:23:17.371 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'forget_message\', priority 0', 296 => 'Nov 16 21:23:17.371 [15117] dbg: check: pms new, time limit in 299.984 s', 297 => 'Nov 16 21:23:17.374 [15117] dbg: locker: refresh_lock: refresh /var/www/.spamassassin/bayes.mutex', 298 => 'Nov 16 21:23:17.430 [15117] dbg: bayes: learned \'2f8c9a31b9ea78085b6b71edf7e93e1320c4f7e5@sa_generated\', atime: 1288001391', 299 => 'Nov 16 21:23:17.430 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learner_close\', priority 0', 300 => 'Nov 16 21:23:17.431 [15117] dbg: bayes: untie-ing', 301 => 'Nov 16 21:23:17.448 [15117] dbg: bayes: files locked, now unlocking lock', 302 => 'Nov 16 21:23:17.448 [15117] dbg: locker: safe_unlock: unlocked /var/www/.spamassassin/bayes.mutex', 303 => 'Learned tokens from 1 message(s) (1 message(s) examined)', ) 294 => 'Nov 16 21:23:17.370 [15117] dbg: bayes: 2f8c9a31b9ea78085b6b71edf7e93e1320c4f7e5@sa_generated already learnt as opposite, forgetting first', 295 => 'Nov 16 21:23:17.371 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'forget_message\', priority 0', 296 => 'Nov 16 21:23:17.371 [15117] dbg: check: pms new, time limit in 299.984 s', 297 => 'Nov 16 21:23:17.374 [15117] dbg: locker: refresh_lock: refresh /var/www/.spamassassin/bayes.mutex', 298 => 'Nov 16 21:23:17.430 [15117] dbg: bayes: learned \'2f8c9a31b9ea78085b6b71edf7e93e1320c4f7e5@sa_generated\', atime: 1288001391', 299 => 'Nov 16 21:23:17.430 [15117] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0x9b645f8) implements \'learner_close\', priority 0', 300 => 'Nov 16 21:23:17.431 [15117] dbg: bayes: untie-ing', 301 => 'Nov 16 21:23:17.448 [15117] dbg: bayes: files locked, now unlocking lock', 302 => 'Nov 16 21:23:17.448 [15117] dbg: locker: safe_unlock: unlocked /var/www/.spamassassin/bayes.mutex', 303 => 'Learned tokens from 1 message(s) (1 message(s) examined)', )
I have the same problem. When I mark mail as spam the log of markasjunk2 says: Code: Learned tokens from 0 message(s) (1 message(s) examined) when it should say: Code: Learned tokens from [b]1[/b] message(s) (1 message(s) examined) I believe there is something wrong with the plugin, I think it can't read the message correctly because when the plugin marks message as junk it uses temporary file, that's what I think is the problem. I guess the correct way of doing this is to mark file as spam when it is still in the inbox and than move it to Junk folder, without checking it in "temporary" state. If anyone comes up with idea on how to fix this let us know.
