Hi I was first asking about SA's performance and I had a tip from the list to use spamd/spamc instead of the regular spamassassin client. I did that but the problem still continues. SpamAssassin will take 5 minutes to classify the first message.
So I turned on debugging and I am attaching the debug log so maybe someone can help me out. I also thought of filing a bug, but I'd better ask to the list first. Here's the log with the message that makes SA wait for 5 minutes with 100% cpu usage: spamd[5975]: [debug] bayes: Can't use estimation method for expiry, something fishy, calculating optimal atime delta (first pass)_ cheers Gustavo
spamd[5975]: [logmsg] info: setuid to gmichels succeeded_ spamd[5975]: [info] setuid to gmichels succeeded_ spamd[5975]: [debug] user has changed_ spamd[5975]: [debug] bayes: 5975 untie-ing_ spamd[5975]: [debug] using "/home/gmichels/.spamassassin" for user state dir_ spamd[5975]: [debug] bayes: 5975 tie-ing to DB file R/O /home/gmichels/.spamassassin/bayes_toks_ spamd[5975]: [debug] bayes: 5975 tie-ing to DB file R/O /home/gmichels/.spamassassin/bayes_seen_ spamd[5975]: [debug] bayes: found bayes db version 2_ spamd[5975]: [debug] Score set 2 chosen._ spamd[5975]: [logmsg] processing message <[EMAIL PROTECTED]> for gmichels:1000._ spamd[5975]: [processing message <[EMAIL PROTECTED]> for gmichels] 1000._ spamd[5975]: [debug] is DNS available? 0_ spamd[5975]: [debug] received-header: parsed as [ ip=200.199.143.192 rdns= helo=MIRELLA by=mail.digiweb.com.br ident= ]_ spamd[5975]: [debug] received-header: cannot use DNS, do not trust any hosts from here on_ spamd[5975]: [debug] received-header: relay 200.199.143.192 trusted? no_ spamd[5975]: [debug] running header regexp tests; score so far=0_ spamd[5975]: [debug] running body-text per-line regexp tests; score so far=0_ spamd[5975]: [debug] bayes corpus size: nspam = 270, nham = 622_ spamd[5975]: [debug] uri tests: Done uriRE_ spamd[5975]: [debug] tokenize: header tokens for *p = "U*qualidade D*colortechdp.com.br D*com.br D*br"_ spamd[5975]: [debug] tokenize: header tokens for *M = " 20040321030319 4838 qmail mail digiweb com br "_ spamd[5975]: [debug] tokenize: header tokens for *F = "U*qualidade D*colortechdp.com.br D*com.br D*br"_ spamd[5975]: [debug] tokenize: header tokens for To = "U*qualidade D*colortechdp.com.br D*com.br D*br"_ spamd[5975]: [debug] tokenize: header tokens for *c = "/html;"_ spamd[5975]: [debug] tokenize: header tokens for X-Priority = "3"_ spamd[5975]: [debug] tokenize: header tokens for *r = " unknown (HELO MIRELLA) (200.199.143) by mail.digiweb.com.br ; "_ spamd[5975]: [debug] tokenize: header tokens for *r = " unknown (HELO MIRELLA) (200.199.143) by mail.digiweb.com.br ; (qmail 4802 invoked by uid 508); "_ spamd[5975]: [debug] bayes token 'CLIQUE' => 0.998159362549801_ spamd[5975]: [debug] bayes token 'removido' => 0.996940397350993_ spamd[5975]: [debug] bayes token 'promo��o' => 0.995837837837838_ spamd[5975]: [debug] bayes token 'Super' => 0.994296296296296_ spamd[5975]: [debug] bayes token 'remover' => 0.989464415491109_ spamd[5975]: [debug] bayes token 'aviso' => 0.0105490196078431_ spamd[5975]: [debug] bayes token 'legisla��o' => 0.988731707317073_ spamd[5975]: [debug] bayes token 'correio' => 0.985096774193548_ spamd[5975]: [debug] bayes token 'classe' => 0.0173548387096774_ spamd[5975]: [debug] bayes token 'AQUI' => 0.980464645956246_ spamd[5975]: [debug] bayes token 'Jo�o' => 0.978_ spamd[5975]: [debug] bayes token 'enviada' => 0.978_ spamd[5975]: [debug] bayes token 'eletr�nico' => 0.978_ spamd[5975]: [debug] bayes token '105' => 0.978_ spamd[5975]: [debug] bayes token 'T�tulo' => 0.978_ spamd[5975]: [debug] bayes token 'direito' => 0.977749115183011_ spamd[5975]: [debug] bayes token 'lista' => 0.969666906499059_ spamd[5975]: [debug] bayes token 'sk:_______' => 0.038913933809032_ spamd[5975]: [debug] bayes token 'Par�grafo' => 0.958_ spamd[5975]: [debug] bayes token '1618' => 0.958_ spamd[5975]: [debug] bayes token 'vagas' => 0.958_ spamd[5975]: [debug] bayes token 'considerado' => 0.958_ spamd[5975]: [debug] bayes token 'Terceiro' => 0.958_ spamd[5975]: [debug] bayes token '301' => 0.958_ spamd[5975]: [debug] bayes token 'UD:jpg' => 0.954628790767451_ spamd[5975]: [debug] bayes token 'UD:gif' => 0.945209985658714_ spamd[5975]: [debug] bayes token 'poder�' => 0.936626169422017_ spamd[5975]: [debug] bayes token 'news' => 0.923880778704544_ spamd[5975]: [debug] bayes token 'H*c:html' => 0.923685451294334_ spamd[5975]: [debug] bayes token 'H*M:digiweb' => 0.904141511102017_ spamd[5975]: [debug] bayes token 'SPAM' => 0.894963699185258_ spamd[5975]: [debug] bayes token 'URI' => 0.888405746445158_ spamd[5975]: [debug] bayes token 'UD:asp' => 0.873130047219062_ spamd[5975]: [debug] bayes token 'H*r:508' => 0.869772476335288_ spamd[5975]: [debug] bayes token 'alterar' => 0.869452351227632_ spamd[5975]: [debug] bayes token 'PARA' => 0.857000117843544_ spamd[5975]: [debug] bayes token 'aqui' => 0.847118241328722_ spamd[5975]: [debug] bayes: score = 0.99999992267334_ spamd[5975]: [debug] using "/home/gmichels/.spamassassin" for user state dir_ spamd[5975]: [debug] Syncing Bayes journal and expiring old tokens..._ spamd[5975]: [debug] using "/home/gmichels/.spamassassin" for user state dir_ spamd[5975]: [debug] lock: 5975 created /home/gmichels/.spamassassin/bayes.lock.gustavo.5975_ spamd[5975]: [debug] lock: 5975 trying to get lock on /home/gmichels/.spamassassin/bayes with 0 retries_ spamd[5975]: [debug] lock: 5975 link to /home/gmichels/.spamassassin/bayes.lock: link ok_ spamd[5975]: [debug] bayes: 5975 tie-ing to DB file R/W /home/gmichels/.spamassassin/bayes_toks_ spamd[5975]: [debug] bayes: 5975 tie-ing to DB file R/W /home/gmichels/.spamassassin/bayes_seen_ spamd[5975]: [debug] bayes: found bayes db version 2_ spamd[5975]: [debug] synced Bayes databases from journal in 1 seconds: 159 unique entries (168 total entries)_ spamd[5975]: [debug] bayes: 5975 untie-ing_ spamd[5975]: [debug] bayes: 5975 untie-ing db_toks_ spamd[5975]: [debug] bayes: 5975 untie-ing db_seen_ spamd[5975]: [debug] bayes: files locked, now unlocking lock_ spamd[5975]: [debug] unlock: 5975 unlink /home/gmichels/.spamassassin/bayes.lock_ spamd[5975]: [debug] using "/home/gmichels/.spamassassin" for user state dir_ spamd[5975]: [debug] lock: 5975 created /home/gmichels/.spamassassin/bayes.lock.gustavo.5975_ spamd[5975]: [debug] lock: 5975 trying to get lock on /home/gmichels/.spamassassin/bayes with 0 retries_ spamd[5975]: [debug] lock: 5975 link to /home/gmichels/.spamassassin/bayes.lock: link ok_ spamd[5975]: [debug] bayes: 5975 tie-ing to DB file R/W /home/gmichels/.spamassassin/bayes_toks_ spamd[5975]: [debug] bayes: 5975 tie-ing to DB file R/W /home/gmichels/.spamassassin/bayes_seen_ spamd[5975]: [debug] bayes: found bayes db version 2_ spamd[5975]: [debug] using "/home/gmichels/.spamassassin" for user state dir_ spamd[5975]: [debug] bayes: expiry check keep size, 75% of max: 112500_ spamd[5975]: [debug] bayes: token count: 887218, final goal reduction size: 774718_ spamd[5975]: [debug] bayes: First pass? Current: 1079885486, Last: 1079812486, atime: 1382400, count: 1789, newdelta: 3192, ratio: 433.045276690889_ spamd[5975]: [debug] bayes: Can't use estimation method for expiry, something fishy, calculating optimal atime delta (first pass)_ *** here it waits for 5 minutes with 100% cpu usage *** spamd[5975]: [debug] bayes: atime_token reduction_ spamd[5975]: [debug] bayes: ========_===============_ spamd[5975]: [debug] bayes: 43200_887081_ spamd[5975]: [debug] bayes: 86400_887062_ spamd[5975]: [debug] bayes: 172800_885496_ spamd[5975]: [debug] bayes: 345600_883823_ spamd[5975]: [debug] bayes: 691200_880512_ spamd[5975]: [debug] bayes: 1382400_877509_ spamd[5975]: [debug] bayes: 2764800_873664_ spamd[5975]: [debug] bayes: 5529600_865582_ spamd[5975]: [debug] bayes: 11059200_0_ spamd[5975]: [debug] bayes: 22118400_0_ spamd[5975]: [debug] bayes: couldn't find a good delta atime, need more token difference, skipping expire._ spamd[5975]: [debug] bayes: 5975 untie-ing_ spamd[5975]: [debug] bayes: 5975 untie-ing db_toks_ spamd[5975]: [debug] bayes: 5975 untie-ing db_seen_ spamd[5975]: [debug] bayes: files locked, now unlocking lock_ spamd[5975]: [debug] unlock: 5975 unlink /home/gmichels/.spamassassin/bayes.lock_ spamd[5975]: [debug] Syncing complete._ spamd[5975]: [debug] bayes: 5975 untie-ing_ spamd[5975]: [debug] running raw-body-text per-line regexp tests; score so far=1.886_ spamd[5975]: [debug] running uri tests; score so far=2.916_ spamd[5975]: [debug] uri tests: Done uriRE_ spamd[5975]: [debug] running full-text regexp tests; score so far=2.916_ spamd[5975]: [debug] all '*From' addrs: [EMAIL PROTECTED] spamd[5975]: [debug] all '*To' addrs: [EMAIL PROTECTED] [EMAIL PROTECTED] spamd[5975]: [debug] forged-HELO: from= helo=mirella by=digiweb.com.br_ spamd[5975]: [debug] running meta tests; score so far=2.916_ spamd[5975]: [debug] auto-learn? ham=0.1, spam=12, body-hits=2.916, head-hits=1.03_ spamd[5975]: [debug] auto-learn: currently using scoreset 2. recomputing score based on scoreset 0._ spamd[5975]: [debug] Score set 0 chosen._ spamd[5975]: [debug] auto-learn: original score: 6.594, recomputed score: 7.124_ spamd[5975]: [debug] Score set 2 chosen._ spamd[5975]: [debug] auto-learn? no: inside auto-learn thresholds_ spamd[5975]: [debug] using "/home/gmichels/.spamassassin" for user state dir_ spamd[5975]: [debug] lock: 5975 created /home/gmichels/.spamassassin/auto-whitelist.lock.gustavo.5975_ spamd[5975]: [debug] lock: 5975 trying to get lock on /home/gmichels/.spamassassin/auto-whitelist with 0 retries_ spamd[5975]: [debug] lock: 5975 link to /home/gmichels/.spamassassin/auto-whitelist.lock: link ok_ spamd[5975]: [debug] Tie-ing to DB file R/W in /home/gmichels/.spamassassin/auto-whitelist_ spamd[5975]: [debug] auto-whitelist (db-based): [EMAIL PROTECTED]|ip=200.199 scores 0/0_ spamd[5975]: [debug] auto-whitelist (db-based): [EMAIL PROTECTED]|ip=cmd scores 0/0_ spamd[5975]: [debug] AWL active, pre-score: 11.994, mean: undef, originating-ip: 200.199.143.192_ spamd[5975]: [debug] add_score: New count: 1, new totscore: 11.994_ spamd[5975]: [debug] Post AWL score: 11.994_ spamd[5975]: [debug] DB addr list: untie-ing and unlocking._ spamd[5975]: [debug] DB addr list: file locked, breaking lock._ spamd[5975]: [debug] unlock: 5975 unlink /home/gmichels/.spamassassin/auto-whitelist.lock_ spamd[5975]: [debug] is spam? score=11.994 required=5 tests=BAYES_99,HTML_70_80,HTML_FONTCOLOR_BLUE,HTML_FONTCOLOR_RED,HTML_FONT_BIG,HTML_IMAGE_ONLY_10,HTML_MESSAGE,HTML_TAG_BALANCE_BODY,HTML_TAG_BALANCE_HTML,MIME_HEADER_CTYPE_ONLY,MIME_HTML_NO_CHARSET,MIME_HTML_ONLY,MSGID_FROM_MTA_HEADER,PRIORITY_NO_NAME_ spamd[5975]: [logmsg] identified spam (12.0/5.0) for gmichels:1000 in 354.4 seconds, 4488 bytes._ spamd[5975]: [identified spam (12.0/5.0) for gmichels] 1000 in 354.4 seconds, 4488 bytes._
