https://issues.apache.org/SpamAssassin/show_bug.cgi?id=6934
--- Comment #5 from Paul.LKW <[email protected]> --- WOW... The debug message is very long @.@ Sat May 4 03:17:45 2013 [87865] dbg: prefork: ordered 87870 to accept Sat May 4 03:17:45 2013 [87865] dbg: prefork: sysread(6) not ready, wait max 300 secs Sat May 4 03:17:45 2013 [87865] dbg: prefork: child 87870: entering state 2 Sat May 4 03:17:45 2013 [87865] dbg: prefork: new lowest idle kid: 87871 Sat May 4 03:17:45 2013 [87870] info: spamd: connection from localhost [127.0.0.1] at port 55258 Sat May 4 03:17:45 2013 [87870] dbg: config: Conf::SQL: executing SQL: SELECT preference, value FROM userpref WHERE username = 'spamd' OR username = '@GLOBAL' OR username = CONCAT('%',NULL) ORDER BY username ASC Sat May 4 03:17:45 2013 [87870] dbg: config: retrieving prefs for spamd from SQL server Sat May 4 03:17:45 2013 [87870] dbg: info: user has changed Sat May 4 03:17:45 2013 [87870] dbg: bayes: learner_new self=Mail::SpamAssassin::Plugin::Bayes=HASH(0x8050e8960), bayes_store_module=Mail::SpamAssassin::BayesStore::DBM Sat May 4 03:17:45 2013 [87870] dbg: bayes: learner_new: got store=Mail::SpamAssassin::BayesStore::DBM=HASH(0x8085a3fd8) Sat May 4 03:17:45 2013 [87870] dbg: bayes: tie-ing to DB file R/O /root/.spamassassin/bayes_toks Sat May 4 03:17:45 2013 [87870] dbg: bayes: tie-ing to DB file R/O /root/.spamassassin/bayes_seen Sat May 4 03:17:45 2013 [87870] dbg: bayes: found bayes db version 3 Sat May 4 03:17:45 2013 [87870] dbg: bayes: DB journal sync: last sync: 0 Sat May 4 03:17:45 2013 [87870] dbg: bayes: not available for scanning, only 118 spam(s) in bayes DB < 200 Sat May 4 03:17:45 2013 [87870] dbg: bayes: untie-ing Sat May 4 03:17:45 2013 [87870] dbg: config: score set 1 chosen. Sat May 4 03:17:45 2013 [87870] warn: spamd: still running as root: user not specified with -u, not found, or set to root, falling back to nobody Sat May 4 03:17:45 2013 [87870] dbg: info: user has changed Sat May 4 03:17:45 2013 [87870] dbg: bayes: learner_new self=Mail::SpamAssassin::Plugin::Bayes=HASH(0x8050e8960), bayes_store_module=Mail::SpamAssassin::BayesStore::DBM Sat May 4 03:17:45 2013 [87870] dbg: bayes: learner_new: got store=Mail::SpamAssassin::BayesStore::DBM=HASH(0x808509e88) Sat May 4 03:17:45 2013 [87870] dbg: bayes: tie-ing to DB file R/O /root/.spamassassin/bayes_toks Sat May 4 03:17:45 2013 [87870] dbg: bayes: tie-ing to DB file R/O /root/.spamassassin/bayes_seen Sat May 4 03:17:45 2013 [87870] dbg: bayes: found bayes db version 3 Sat May 4 03:17:45 2013 [87870] dbg: bayes: DB journal sync: last sync: 0 Sat May 4 03:17:45 2013 [87870] dbg: bayes: not available for scanning, only 118 spam(s) in bayes DB < 200 Sat May 4 03:17:45 2013 [87870] dbg: bayes: untie-ing Sat May 4 03:17:45 2013 [87870] dbg: config: score set 1 chosen. Sat May 4 03:17:45 2013 [87870] dbg: spamd: running as uid 65534 Sat May 4 03:17:45 2013 [87870] dbg: config: time limit 300.0 s Sat May 4 03:17:45 2013 [87870] dbg: message: main message type: multipart/alternative Sat May 4 03:17:45 2013 [87870] info: spamd: processing message <[email protected]> for spamd:65534 Sat May 4 03:17:45 2013 [87870] dbg: check: pms new, time limit in 299.993 s Sat May 4 03:17:45 2013 [87870] dbg: bayes: tie-ing to DB file R/O /root/.spamassassin/bayes_toks Sat May 4 03:17:45 2013 [87870] dbg: bayes: tie-ing to DB file R/O /root/.spamassassin/bayes_seen Sat May 4 03:17:45 2013 [87870] dbg: bayes: found bayes db version 3 Sat May 4 03:17:45 2013 [87870] dbg: bayes: DB journal sync: last sync: 0 Sat May 4 03:17:45 2013 [87870] dbg: bayes: not available for scanning, only 118 spam(s) in bayes DB < 200 Sat May 4 03:17:45 2013 [87870] dbg: bayes: untie-ing Sat May 4 03:17:45 2013 [87870] dbg: config: trusted_networks are not configured; it is recommended that you configure trusted_networks manually Sat May 4 03:17:45 2013 [87870] dbg: received-header: parsed as [ ip=XXX.XX.XXX.XX rdns= helo=mx.xxx.com by=mx.yyy.com ident= envfrom= intl=0 id=9526F87D873 auth= msa=0 ] Sat May 4 03:17:45 2013 [87870] dbg: received-header: do not trust any hosts from here on Sat May 4 03:17:45 2013 [87870] dbg: received-header: relay XXX.XX.XXX.XX trusted? no internal? no msa? no Sat May 4 03:17:45 2013 [87870] dbg: received-header: parsed as [ ip=127.0.0.1 rdns=localhost helo=mx.xxx.com by=mx.xxx.com ident= envfrom= intl=0 id=6C76B2E5CE8 auth= msa=0 ] Sat May 4 03:17:45 2013 [87870] dbg: received-header: relay 127.0.0.1 trusted? no internal? no msa? no Sat May 4 03:17:45 2013 [87870] dbg: received-header: parsed as [ ip=XXX.XX.XXX.XX rdns= helo=!10.10.100.32! by=mx.xxx.com ident= envfrom= intl=0 id=32FB52E5CE8 auth=ESMTPA msa=0 ] Sat May 4 03:17:45 2013 [87870] dbg: received-header: relay XXX.XX.XXX.XX trusted? no internal? no msa? no Sat May 4 03:17:45 2013 [87870] dbg: metadata: X-Spam-Relays-Trusted: Sat May 4 03:17:45 2013 [87870] dbg: metadata: X-Spam-Relays-Untrusted: [ ip=XXX.XX.XXX.XX rdns= helo=mx.xxx.com by=mx.yyy.com ident= envfrom= intl=0 id=9526F87D873 auth= msa=0 ] [ ip=127.0.0.1 rdns=localhost helo=mx.xxx.com by=mx.xxx.com ident= envfrom= intl=0 id=6C76B2E5CE8 auth= msa=0 ] [ ip=XXX.XX.XXX.XX rdns= helo=!10.10.100.32! by=mx.xxx.com ident= envfrom= intl=0 id=32FB52E5CE8 auth=ESMTPA msa=0 ] Sat May 4 03:17:45 2013 [87870] dbg: metadata: X-Spam-Relays-Internal: Sat May 4 03:17:45 2013 [87870] dbg: metadata: X-Spam-Relays-External: [ ip=XXX.XX.XXX.XX rdns= helo=mx.xxx.com by=mx.yyy.com ident= envfrom= intl=0 id=9526F87D873 auth= msa=0 ] [ ip=127.0.0.1 rdns=localhost helo=mx.xxx.com by=mx.xxx.com ident= envfrom= intl=0 id=6C76B2E5CE8 auth= msa=0 ] [ ip=XXX.XX.XXX.XX rdns= helo=!10.10.100.32! by=mx.xxx.com ident= envfrom= intl=0 id=32FB52E5CE8 auth=ESMTPA msa=0 ] Sat May 4 03:17:45 2013 [87870] dbg: message: ---- MIME PARSER START ---- Sat May 4 03:17:45 2013 [87870] dbg: message: parsing multipart, got boundary: ------------030306050101060202070904 Sat May 4 03:17:45 2013 [87870] dbg: message: found part of type text/plain, boundary: ------------030306050101060202070904 Sat May 4 03:17:45 2013 [87870] dbg: message: added part, type: text/plain Sat May 4 03:17:45 2013 [87870] dbg: message: found part of type text/html, boundary: ------------030306050101060202070904 Sat May 4 03:17:45 2013 [87870] dbg: message: added part, type: text/html Sat May 4 03:17:45 2013 [87870] dbg: message: parsing normal part Sat May 4 03:17:45 2013 [87870] dbg: message: parsing normal part Sat May 4 03:17:45 2013 [87870] dbg: message: ---- MIME PARSER END ---- Sat May 4 03:17:45 2013 [87870] dbg: message: decoding other encoding type (8bit), ignoring Sat May 4 03:17:45 2013 [87870] dbg: message: decoding other encoding type (8bit), ignoring Sat May 4 03:17:45 2013 [87870] dbg: textcat: classifying, skipping: yi sco lv sl la sa rm cy lt gd Sat May 4 03:17:45 2013 [87870] dbg: textcat: language possibly: en Sat May 4 03:17:45 2013 [87870] dbg: textcat: X-Languages: "en", X-Languages-Length: 451 Sat May 4 03:17:45 2013 [87870] dbg: uridnsbl: domain facebook.com in skip list Sat May 4 03:17:45 2013 [87870] dbg: uridnsbl: domain adobe.com in skip list Sat May 4 03:17:45 2013 [87870] dbg: uridnsbl: domain adobe.com in skip list Sat May 4 03:17:45 2013 [87870] dbg: uridnsbl: domains to query: adobe-gcevent.com adobehk-events.com Sat May 4 03:17:45 2013 [87870] dbg: dns: name server: XXX.XX.XXX.XXX, LocalAddr: 0.0.0.0 Sat May 4 03:17:45 2013 [87870] dbg: dns: resolver socket rx buffer size is 42080 bytes Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 13290/adobe-gcevent.com.multi.surbl.org/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:multi.surbl.org.:adobe-gcevent.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_PH_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 57067/adobe-gcevent.com.multi.uribl.com/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:multi.uribl.com.:adobe-gcevent.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_BLACK lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_RED lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_GREY lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 36345/adobe-gcevent.com.dob.sibl.support-intelligence.net/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:adobe-gcevent.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_RHS_DOB lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_SC_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_JP_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_AB_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_WS_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_BLOCKED lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 46135/adobe-gcevent.com.dbl.spamhaus.org/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:dbl.spamhaus.org.:adobe-gcevent.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_DBL_ERROR lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_DBL_SPAM lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_DBL_REDIR lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 60781/adobe-gcevent.com/NS/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-NS, NS:adobe-gcevent.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_SBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 36318/adobehk-events.com.multi.surbl.org/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:multi.surbl.org.:adobehk-events.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_PH_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 58055/adobehk-events.com.multi.uribl.com/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:multi.uribl.com.:adobehk-events.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_BLACK lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_RED lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_GREY lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 30250/adobehk-events.com.dob.sibl.support-intelligence.net/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:adobehk-events.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_RHS_DOB lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_SC_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_JP_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_AB_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_WS_SURBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_BLOCKED lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 55549/adobehk-events.com.dbl.spamhaus.org/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:dbl.spamhaus.org.:adobehk-events.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_DBL_ERROR lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_DBL_SPAM lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_DBL_REDIR lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 38632/adobehk-events.com/NS/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-NS, NS:adobehk-events.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: URIBL_SBL lookup start Sat May 4 03:17:45 2013 [87870] dbg: dns: checking A and MX for host xxx.com Sat May 4 03:17:45 2013 [87870] dbg: dns: launching DNS A query for xxx.com in background Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 63610/xxx.com/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: NO_DNS_FOR_FROM, DNSBL-A, dns:A:xxx.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: launching DNS MX query for xxx.com in background Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 8988/xxx.com/MX/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: NO_DNS_FOR_FROM, DNSBL-MX, dns:MX:xxx.com (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: check: check_main, time limit in 299.970 s Sat May 4 03:17:45 2013 [87870] dbg: check: running tests for priority: -1000 Sat May 4 03:17:45 2013 [87870] dbg: dns: hit <dns:xxx.com> XXX.XX.XXX.XXX Sat May 4 03:17:45 2013 [87870] dbg: dns: hit <dns:xxx.com?type=MX> 10 mail.xxx.com. Sat May 4 03:17:45 2013 [87870] dbg: async: select found 10 responses ready (t.o.=0.0) Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.004 s: URI-NS, NS:adobehk-events.com Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 34523/c.ns.joker.com/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-A, A:c.ns.joker.com. (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 61071/a.ns.joker.com/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-A, A:a.ns.joker.com. (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 16744/b.ns.joker.com/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-A, A:b.ns.joker.com. (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.005 s: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:adobe-gcevent.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.005 s: URI-DNSBL, DNSBL:multi.surbl.org.:adobehk-events.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.005 s: URI-DNSBL, DNSBL:multi.surbl.org.:adobe-gcevent.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.004 s: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:adobehk-events.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.004 s: NO_DNS_FOR_FROM, DNSBL-MX, dns:MX:xxx.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.005 s: URI-NS, NS:adobe-gcevent.com Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 59324/hmisdns.hmis.com.tw/A/IN Sat May 4 03:17:45 2013 [87870] dbg: async: starting: URI-A, A:hmisdns.hmis.com.tw. (timeout 15.0s, min 3.0s) Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.004 s: URI-DNSBL, DNSBL:dbl.spamhaus.org.:adobehk-events.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.005 s: URI-DNSBL, DNSBL:dbl.spamhaus.org.:adobe-gcevent.com Sat May 4 03:17:45 2013 [87870] dbg: async: completed in 0.004 s: NO_DNS_FOR_FROM, DNSBL-A, dns:A:xxx.com Sat May 4 03:17:45 2013 [87870] dbg: async: queries completed: 10, started: 4 Sat May 4 03:17:45 2013 [87870] dbg: async: queries active: URI-A=4 URI-DNSBL=2 at Sat May 4 03:17:45 2013 Sat May 4 03:17:45 2013 [87870] dbg: dns: harvested completed queries Sat May 4 03:17:45 2013 [87870] dbg: rules: running one_line_body tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head_eval tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: eval: all '*From' addrs: [email protected] Sat May 4 03:17:45 2013 [87870] dbg: eval: all '*To' addrs: [email protected] Sat May 4 03:17:45 2013 [87870] dbg: rules: running body tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running uri tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running body_eval tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running rawbody tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running full tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running meta tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: check: running tests for priority: -950 Sat May 4 03:17:45 2013 [87870] dbg: rules: running one_line_body tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head_eval tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running body tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running uri tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running body_eval tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running rawbody tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running full tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running meta tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: check: running tests for priority: -900 Sat May 4 03:17:45 2013 [87870] dbg: rules: running one_line_body tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head_eval tests; score so far=0 Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule SUBJECT_IN_BLACKLIST ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: running body tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running uri tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running body_eval tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running rawbody tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running full tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running meta tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: check: running tests for priority: -400 Sat May 4 03:17:45 2013 [87870] dbg: rules: running one_line_body tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running head tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running body tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running uri tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running body_eval tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running rawbody tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running full tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: running meta tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: check: running tests for priority: 0 Sat May 4 03:17:45 2013 [87870] dbg: rules: running one_line_body tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: zoom: run_body_fast_scan for body_0 start Sat May 4 03:17:45 2013 [87870] dbg: zoom: run_body_fast_scan for body_0 done Sat May 4 03:17:45 2013 [87870] dbg: rules: running head tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __LAST_EXTERNAL_RELAY_NO_AUTH ======> got hit: "[ ip=XXX.XX.XXX.XX rdns= helo=mx.xxx.com by=mx.yyy.com ident= envfrom= intl=0 id=9526F87D873 auth= " Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __RDNS_NONE ======> got hit: "[ ip=XXX.XX.XXX.XX rdns= " Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __DOS_RELAYED_EXT ======> got hit: "Received: from mx.xxx.com (unknown [XXX.XX.XXX.XX]) Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] by mx.yyy.com (Postfix) with ESMTP id 9526F87D873 Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] for <[email protected]>; Sat, 4 May 2013 03:17:44 +0800 (HKT) Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Received: from mx.xxx.com (localhost [127.0.0.1]) Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] by mx.xxx.com (Postfix) with ESMTP id 6C76B2E5CE8; Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat, 4 May 2013 03:17:44 +0800 (HKT) Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Received: by mx.xxx.com (Postfix, from userid 58) Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] id 4D7122E5D0B; Sat, 4 May 2013 03:17:44 +0800 (HKT) Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on MAIL.XXX.COM Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] X-Spam-Level: Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] X-Spam-Status: No, score=-10000.2 required=6.0 tests=ALL_TRUSTED, Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] HTML_IMAGE_RATIO_02,HTML_MESSAGE,USER_IN_WHITELIST autolearn=no version=3.3.2 Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] Received: " Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __CTYPE_MULTIPART_ALT ======> got hit: "multipart/alternative" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __CTYPE_HAS_BOUNDARY ======> got hit: "boundary" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __CT ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __MIME_BDRY_0D0D ======> got hit: "boundary="------------030306050101060202070904" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __CTYPE_MULTIPART_ANY ======> got hit: "multipart/alternative" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_DATE ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __LAST_UNTRUSTED_RELAY_NO_AUTH ======> got hit: "[ ip=XXX.XX.XXX.XX rdns= helo=mx.xxx.com by=mx.yyy.com ident= envfrom= intl=0 id=9526F87D873 auth= " Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __MSGID_OK_HOST ======> got hit: "@xxx.com>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __MUA_TBIRD ======> got hit: "Thunderbird" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_UA ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_MESSAGE_ID ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __MIME_VERSION ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __TOCC_EXISTS ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_RCVD ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __DOS_RCVD_SAT ======> got hit: " Sat, " Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __SUBJECT_NEEDS_MIME ======> got hit: "▒" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_SUBJECT ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __SUBJECT_ENCODED_B64 ======> got hit: "=?Big5?B?" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_MSGID ======> got hit: "<" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __SANE_MSGID ======> got hit: "<[email protected]> Sat May 4 03:17:45 2013 [87870] dbg: rules: [...] " Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __MOZILLA_MSGID ======> got hit: "<[email protected]>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_TO ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_IN_REPLY_TO ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_X_REF ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran header rule __HAS_FROM ======> got hit: "<YES>" Sat May 4 03:17:45 2013 [87870] dbg: rules: running head_eval tests; score so far=100 Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: RULE (FREEMAIL_FROM) check_freemail_from Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: all from-addresses: [email protected] Sat May 4 03:17:45 2013 [87870] dbg: dkim: performing public key lookup and signature verification Sat May 4 03:17:45 2013 [87870] dbg: dkim: signature verification result: none Sat May 4 03:17:45 2013 [87870] dbg: dkim: adsp: performing lookup on _adsp._domainkey.xxx.com Sat May 4 03:17:45 2013 [87870] dbg: dkim: adsp result: U/unknown (dns: unknown), author domain 'xxx.com' Sat May 4 03:17:45 2013 [87870] dbg: spf: checking to see if the message has a Received-SPF header that we can use Sat May 4 03:17:45 2013 [87870] dbg: spf: checking HELO (helo=mx.xxx.com, ip=XXX.XX.XXX.XX) Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 33559/mx.xxx.com/SPF/IN Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 18629/mx.xxx.com/TXT/IN Sat May 4 03:17:45 2013 [87870] dbg: spf: query for /XXX.XX.XXX.XX/mx.xxx.com: result: none, comment: , text: No applicable sender policy available Sat May 4 03:17:45 2013 [87870] dbg: dkim: author [email protected], not in any dkim whitelist Sat May 4 03:17:45 2013 [87870] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks Sat May 4 03:17:45 2013 [87870] dbg: spf: checking EnvelopeFrom (helo=mx.xxx.com, ip=XXX.XX.XXX.XX, [email protected]) Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 17591/xxx.com/SPF/IN Sat May 4 03:17:45 2013 [87870] dbg: dns: providing a callback for id: 62517/xxx.com/TXT/IN Sat May 4 03:17:45 2013 [87870] dbg: spf: query for [email protected]/XXX.XX.XXX.XX/mx.xxx.com: result: pass, comment: , text: Mechanism 'ip4:XXX.XX.XXX.XX' matched Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: RULE (__freemail_reply) check_freemail_replyto Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: From address: [email protected] Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: No Reply-To and From is not freemail, skipping check Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule SPF_PASS ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: RULE (FREEMAIL_REPLYTO_END_DIGIT) check_freemail_header regex:\d@ Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: header Reply-To not found from mail Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: RULE (__freemail_replyto) check_freemail_replyto Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: From address: [email protected] Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: Reply-To is not freemail, skipping check Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __ENV_AND_HDR_FROM_MATCH ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: RULE (__freemail_hdr_replyto) check_freemail_header Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: header Reply-To not found from mail Sat May 4 03:17:45 2013 [87870] dbg: spf: def_whitelist_from_spf: [email protected] is not in DEF_WHITELIST_FROM_SPF Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: RULE (FREEMAIL_ENVFROM_END_DIGIT) check_freemail_header regex:\d@ Sat May 4 03:17:45 2013 [87870] dbg: FreeMail: address from header EnvelopeFrom: [email protected] Sat May 4 03:17:45 2013 [87870] dbg: spf: whitelist_from_spf: [email protected] is not in user's WHITELIST_FROM_SPF Sat May 4 03:17:45 2013 [87870] dbg: rules: running body tests; score so far=99.999 Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __FB_NUM_PERCNT ======> got hit: "0%" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __NONEMPTY_BODY ======> got hit: "A" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __BODY_TEXT_LINE ======> got hit: "A" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __BODY_TEXT_LINE ======> got hit: "A" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __BODY_TEXT_LINE ======> got hit: "A" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __BODY_TEXT_LINE ======> got hit: " I" Sat May 4 03:17:45 2013 [87870] dbg: rules: ran body rule __HIGHBITS ======> got hit: "▒@▒ɨ▒▒j" Sat May 4 03:17:45 2013 [87870] dbg: rules: running uri tests; score so far=99.999 Sat May 4 03:17:45 2013 [87870] dbg: rules: ran uri rule __URI_MAILTO ======> got hit: "mailto:"; Sat May 4 03:17:45 2013 [87870] dbg: rules: ran uri rule __LOCAL_PP_NONPPURL ======> got hit: "http://edm2.adobehk-events.com"; Sat May 4 03:17:45 2013 [87870] dbg: rules: ran uri rule __DOS_HAS_ANY_URI ======> got hit: "h" Sat May 4 03:17:45 2013 [87870] dbg: rules: running body_eval tests; score so far=99.999 Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm2.adobehk-events.com/eNewsImage/ADS_1866_CreateNowCN.jpg' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm2.adobehk-events.com/ott.asp?l=4310&n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=2&tlink=http://www.adobe-gcevent.com/VOD/ZH/?trackingid=KFMGJ' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?jobno=ADS-1866&lnkno=99&tlink=http://www.adobehk-events.com/oocheck.asp?n=1866%26p=tUHsaHyz%26u=Yj56T8anx5t2510' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edmot.adobehk-events.com/otimages/1866_tUHsaHyz_Yj56T8anx5t2510.gif' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?jobno=ADS-1866&lnkno=1&tlink=http://edm2.adobehk-events.com/ott.asp?l=4310&n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=6&tlink=http://edm2.adobehk-events.com/ce/ads/1866/edm130426CreateNowHKEN.htm' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=3&tlink=http://www.facebook.com/adobehongkong' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=5&tlink=http://www.adobe.com/hk_zh/support/contact/' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?jobno=ADS-1866&lnkno=1&tlink=http://edm2.adobehk-events.com/ott.asp?l=4310%26n=1866%26p=tUHsaHyz%26u=Yj56T8anx5t2510' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: type matched: 'a' =~ /(?^:^a$)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=4&tlink=http://www.adobe.com/ap/misc/privacy.html' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_CANPOST_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'mailto:[email protected]' !~ /(?^:canadapost\.)/ Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __TAG_EXISTS_BODY ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: eval: text words: 18, html words: 17 Sat May 4 03:17:45 2013 [87870] dbg: eval: madiff: left: 1, orig: 17, max-difference: 5.88% Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule HTML_IMAGE_RATIO_02 ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm2.adobehk-events.com/eNewsImage/ADS_1866_CreateNowCN.jpg' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm2.adobehk-events.com/ott.asp?l=4310&n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=2&tlink=http://www.adobe-gcevent.com/VOD/ZH/?trackingid=KFMGJ' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?jobno=ADS-1866&lnkno=99&tlink=http://www.adobehk-events.com/oocheck.asp?n=1866%26p=tUHsaHyz%26u=Yj56T8anx5t2510' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edmot.adobehk-events.com/otimages/1866_tUHsaHyz_Yj56T8anx5t2510.gif' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?jobno=ADS-1866&lnkno=1&tlink=http://edm2.adobehk-events.com/ott.asp?l=4310&n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=6&tlink=http://edm2.adobehk-events.com/ce/ads/1866/edm130426CreateNowHKEN.htm' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=3&tlink=http://www.facebook.com/adobehongkong' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=5&tlink=http://www.adobe.com/hk_zh/support/contact/' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?jobno=ADS-1866&lnkno=1&tlink=http://edm2.adobehk-events.com/ott.asp?l=4310%26n=1866%26p=tUHsaHyz%26u=Yj56T8anx5t2510' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: type matched: 'a' =~ /(?^:^a$)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'http://edm1.adobehk-events.com/ce/adobe/go2link.asp?n=1866&p=tUHsaHyz&u=Yj56T8anx5t2510&jobno=ADS-1866&lnkno=4&tlink=http://www.adobe.com/ap/misc/privacy.html' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_AJB_UTUBE_BADLINK Sat May 4 03:17:45 2013 [87870] dbg: uri: raw matched: 'mailto:[email protected]' !~ /(?^:youtube\.)/ Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __ANY_TEXT_ATTACH_DOC ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __MIME_HTML ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule HTML_MESSAGE ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __TAG_EXISTS_HTML ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __ANY_TEXT_ATTACH ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __TVD_MIME_ATT_TP ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: uri: running T_KHOP_FOREIGN_CLICK Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __TAG_EXISTS_HEAD ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: ran eval rule __TAG_EXISTS_META ======> got hit (1) Sat May 4 03:17:45 2013 [87870] dbg: rules: running rawbody tests; score so far=100.805 Sat May 4 03:17:45 2013 [87870] dbg: rules: running rawbody_eval tests; score so far=100.805 Sat May 4 03:17:45 2013 [87870] dbg: rules: running full tests; score so far=100.805 Sat May 4 03:17:45 2013 [87870] dbg: rules: running full_eval tests; score so far=100.805 Sat May 4 03:17:45 2013 [87870] dbg: dcc: dccifd is not available; no r/w socket at /usr/local/dcc/dccifd Sat May 4 03:17:45 2013 [87870] dbg: dns: entering helper-app run mode Sat May 4 03:17:45 2013 [87870] dbg: dcc: opening pipe to /usr/local/bin/dccproc -C -x 0 -a XXX.XX.XXX.XX -w whiteclnt </tmp/.spamassassin87870eOtlq4tmp Sat May 4 03:17:45 2013 [87960] dbg: util: changing real uid from 0 to match effective uid 65534 Sat May 4 03:17:45 2013 [87960] dbg: util: setuid: ruid=65534 euid=65534 Sat May 4 03:17:46 2013 [87870] dbg: dns: leaving helper-app run mode Sat May 4 03:17:46 2013 [87870] dbg: dcc: dccproc responded with 'X-DCC-x.dcc-servers-Metrics: MX.YYY.COM 104; Body=1 Fuz1=2 Fuz2=2' Sat May 4 03:17:46 2013 [87870] dbg: dns: entering helper-app run mode Sat May 4 03:17:49 2013 [87870] dbg: dns: leaving helper-app run mode Sat May 4 03:17:49 2013 [87870] dbg: razor2: part=0 engine=8 contested=0 confidence=0 Sat May 4 03:17:49 2013 [87870] dbg: razor2: part=1 engine=8 contested=0 confidence=0 Sat May 4 03:17:49 2013 [87870] dbg: razor2: results: spam? 0 Sat May 4 03:17:49 2013 [87870] dbg: razor2: results: engine 8, highest cf score: 0 Sat May 4 03:17:49 2013 [87870] dbg: razor2: results: engine 4, highest cf score: 0 Sat May 4 03:17:49 2013 [87870] dbg: rules: ran eval rule __DKIM_DEPENDABLE ======> got hit (1) Sat May 4 03:17:49 2013 [87870] dbg: pyzor: pyzor is not available: no pyzor executable found Sat May 4 03:17:49 2013 [87870] dbg: pyzor: no pyzor found, disabling Pyzor Sat May 4 03:17:49 2013 [87870] dbg: async: select found 2 responses ready (t.o.=0.0) Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.020 s: URI-A, A:hmisdns.hmis.com.tw. Sat May 4 03:17:49 2013 [87870] dbg: dns: providing a callback for id: 6209/234.170.222.61.zen.spamhaus.org/A/IN Sat May 4 03:17:49 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:zen.spamhaus.org.:234.170.222.61 (timeout 15.0s, min 3.0s) Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.020 s: URI-A, A:c.ns.joker.com. Sat May 4 03:17:49 2013 [87870] dbg: dns: providing a callback for id: 35672/21.237.197.66.zen.spamhaus.org/A/IN Sat May 4 03:17:49 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:zen.spamhaus.org.:21.237.197.66 (timeout 15.0s, min 3.0s) Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 4.030 s: URI-DNSBL, DNSBL:multi.uribl.com.:adobe-gcevent.com Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.020 s: URI-A, A:b.ns.joker.com. Sat May 4 03:17:49 2013 [87870] dbg: dns: providing a callback for id: 9379/69.97.25.159.zen.spamhaus.org/A/IN Sat May 4 03:17:49 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:zen.spamhaus.org.:69.97.25.159 (timeout 15.0s, min 3.0s) Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.020 s: URI-A, A:a.ns.joker.com. Sat May 4 03:17:49 2013 [87870] dbg: dns: providing a callback for id: 11888/218.157.172.184.zen.spamhaus.org/A/IN Sat May 4 03:17:49 2013 [87870] dbg: async: starting: URI-DNSBL, DNSBL:zen.spamhaus.org.:218.157.172.184 (timeout 15.0s, min 3.0s) Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 4.029 s: URI-DNSBL, DNSBL:multi.uribl.com.:adobehk-events.com Sat May 4 03:17:49 2013 [87870] dbg: async: queries completed: 6, started: 4 Sat May 4 03:17:49 2013 [87870] dbg: async: queries active: URI-DNSBL=4 at Sat May 4 03:17:49 2013 Sat May 4 03:17:49 2013 [87870] dbg: dns: harvested completed queries Sat May 4 03:17:49 2013 [87870] dbg: rules: running meta tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: check: running tests for priority: 500 Sat May 4 03:17:49 2013 [87870] dbg: dns: harvest_dnsbl_queries Sat May 4 03:17:49 2013 [87870] dbg: async: select found 4 responses ready (t.o.=0.0) Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.003 s: URI-DNSBL, DNSBL:zen.spamhaus.org.:21.237.197.66 Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.003 s: URI-DNSBL, DNSBL:zen.spamhaus.org.:69.97.25.159 Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.002 s: URI-DNSBL, DNSBL:zen.spamhaus.org.:234.170.222.61 Sat May 4 03:17:49 2013 [87870] dbg: async: completed in 0.003 s: URI-DNSBL, DNSBL:zen.spamhaus.org.:218.157.172.184 Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.002 . DNSBL:zen.spamhaus.org.:234.170.222.61 Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.003 . DNSBL:zen.spamhaus.org.:218.157.172.184 Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.003 . DNSBL:zen.spamhaus.org.:69.97.25.159 Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.003 . DNSBL:zen.spamhaus.org.:21.237.197.66 Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.004 . dns:A:xxx.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.004 . NS:adobehk-events.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.004 . DNSBL:dbl.spamhaus.org.:adobehk-events.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.004 . dns:MX:xxx.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.004 . DNSBL:dob.sibl.support-intelligence.net:adobehk-events.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.005 . DNSBL:multi.surbl.org.:adobehk-events.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.005 . NS:adobe-gcevent.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.005 . DNSBL:dbl.spamhaus.org.:adobe-gcevent.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.005 . DNSBL:dob.sibl.support-intelligence.net:adobe-gcevent.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.005 . DNSBL:multi.surbl.org.:adobe-gcevent.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.020 . A:c.ns.joker.com. Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.020 . A:hmisdns.hmis.com.tw. Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.020 . A:a.ns.joker.com. Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 0.020 . A:b.ns.joker.com. Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 4.029 . DNSBL:multi.uribl.com.:adobehk-events.com Sat May 4 03:17:49 2013 [87870] dbg: async: timing: 4.030 . DNSBL:multi.uribl.com.:adobe-gcevent.com Sat May 4 03:17:49 2013 [87870] dbg: rules: running one_line_body tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: rules: running head tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: rules: running body tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: rules: running uri tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: rules: running rawbody tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: rules: running full tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: rules: running meta tests; score so far=100.805 Sat May 4 03:17:49 2013 [87870] dbg: learn: auto-learn: currently using scoreset 1 Sat May 4 03:17:49 2013 [87870] dbg: learn: auto-learn: message score: 102.079, computed score for autolearn: 2.08 Sat May 4 03:17:49 2013 [87870] dbg: learn: auto-learn? ham=0.1, spam=12, body-points=2.08, head-points=2.08, learned-points=0 Sat May 4 03:17:49 2013 [87870] dbg: learn: auto-learn? no: inside auto-learn thresholds, not considered ham or spam Sat May 4 03:17:49 2013 [87870] dbg: check: is spam? score=102.079 required=6 Sat May 4 03:17:49 2013 [87870] dbg: check: tests=HTML_IMAGE_RATIO_02,HTML_MESSAGE,RDNS_NONE,SPF_PASS,SUBJECT_IN_BLACKLIST Sat May 4 03:17:49 2013 [87870] dbg: check: subtests=__ANY_TEXT_ATTACH,__ANY_TEXT_ATTACH_DOC,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__CT,__CTYPE_HAS_BOUNDARY,__CTYPE_MULTIPART_ALT,__CTYPE_MULTIPART_ANY,__DKIM_DEPENDABLE,__DOS_HAS_ANY_URI,__DOS_RCVD_SAT,__DOS_RELAYED_EXT,__ENV_AND_HDR_FROM_MATCH,__FB_NUM_PERCNT,__HAS_ANY_URI,__HAS_DATE,__HAS_FROM,__HAS_IN_REPLY_TO,__HAS_MESSAGE_ID,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__HAS_TO,__HAS_UA,__HAS_URI,__HAS_X_REF,__HIGHBITS,__LAST_EXTERNAL_RELAY_NO_AUTH,__LAST_UNTRUSTED_RELAY_NO_AUTH,__LOCAL_PP_NONPPURL,__MIME_BDRY_0D0D,__MIME_HTML,__MIME_VERSION,__MOZILLA_MSGID,__MSGID_OK_HOST,__MUA_TBIRD,__NONEMPTY_BODY,__NOT_SPOOFED,__RDNS_NONE,__SANE_MSGID,__SUBJECT_ENCODED_B64,__SUBJECT_NEEDS_MIME,__TAG_EXISTS_BODY,__TAG_EXISTS_HEAD,__TAG_EXISTS_HTML,__TAG_EXISTS_META,__THREADED,__TOCC_EXISTS,__TVD_MIME_ATT_TP,__URI_MAILTO Sat May 4 03:17:49 2013 [87870] info: spamd: identified spam (102.1/6.0) for spamd:65534 in 4.1 seconds, 6327 bytes. Sat May 4 03:17:49 2013 [87870] info: spamd: result: Y 102 - HTML_IMAGE_RATIO_02,HTML_MESSAGE,RDNS_NONE,SPF_PASS,SUBJECT_IN_BLACKLIST scantime=4.1,size=6327,user=spamd,uid=65534,required_score=6.0,rhost=localhost,raddr=127.0.0.1,rport=55258,mid=<[email protected]>,autolearn=no Sat May 4 03:17:49 2013 [87870] dbg: config: copying current conf from backup Sat May 4 03:17:49 2013 [87870] dbg: timing: total 4099 ms - load_scoreonly_sql: 1.51 (0.0%), signal_user_changed: 2 (0.1%), parse: 1.03 (0.0%), extract_message_metadata: 21 (0.5%), get_uri_detail_list: 1.79 (0.0%), tests_pri_-1000: 9 (0.2%), tests_pri_-950: 1.10 (0.0%), tests_pri_-900: 1.44 (0.0%), tests_pri_-400: 0.98 (0.0%), tests_pri_0: 4017 (98.0%), check_dkim_signature: 0.67 (0.0%), check_dkim_adsp: 3 (0.1%), check_spf: 8 (0.2%), poll_dns_idle: 0.94 (0.0%), check_dcc: 301 (7.3%), check_razor2: 3660 (89.3%), check_pyzor: 0.23 (0.0%), tests_pri_500: 6 (0.1%), rewrite_mail: 1.57 (0.0%), copy_config: 31 (0.8%) Sat May 4 03:17:49 2013 [87870] dbg: prefork: sysread(7) not ready, wait max 300 secs Sat May 4 03:17:49 2013 [87865] dbg: prefork: child 87870: entering state 1 Sat May 4 03:17:49 2013 [87865] dbg: prefork: new lowest idle kid: 87870 Sat May 4 03:17:49 2013 [87865] dbg: prefork: child reports idle Sat May 4 03:17:49 2013 [87865] info: prefork: child states: II again many thanks for your effort for open source, and hope the problem could fix recently. ^_^ -- You are receiving this mail because: You are the assignee for the bug.
