On 2012-08-14 21:20, John Evans wrote:
On 2012-08-14 21:13, Kevin A. McGrail wrote:
Here's the output of -D -t on the file. I let it run for about 10
minutes before giving up and killing the process.
Out of interest, can you let it run longer? Say an hour just to see
if does finish processing?
regards,
KAM
You bet! I'll fire it up in a screen session tonight (about to go to
bed) and check on it in the morning when I get to work. That should
give it PLENTY of time to finish up if it's going to finish.
I'll be in touch tomorrow with (hopefully) more information.
The SA check finally finished. Here are the full debug logs from the
scan. As you can see at the "23:59:21.418" mark, a timeout hits and
forces SA to move on. It looks like that time out is set to many
minutes, and I thought the default config for time_limit was 300
seconds?
Aug 14 22:21:29.635 [6233] dbg: rules: run_generic_tests - compiling
eval code: meta, priority -900
Aug 14 22:21:29.635 [6233] dbg: rules: compiled meta tests
Aug 14 22:21:29.635 [6233] dbg: check: running tests for priority: -400
Aug 14 22:21:29.635 [6233] dbg: rules: running head tests; score so
far=-0.0001
Aug 14 22:21:29.635 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 280 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_neg400_1
Aug 14 22:21:29.636 [6233] dbg: rules: run_generic_tests - compiling
eval code: head, priority -400
Aug 14 22:21:29.636 [6233] dbg: rules: compiled head tests
Aug 14 22:21:29.636 [6233] dbg: rules: running body tests; score so
far=-0.0001
Aug 14 22:21:29.636 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 223 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_neg400_1
Aug 14 22:21:29.636 [6233] dbg: rules: run_generic_tests - compiling
eval code: body, priority -400
Aug 14 22:21:29.636 [6233] dbg: rules: compiled body tests
Aug 14 22:21:29.636 [6233] dbg: rules: running uri tests; score so
far=-0.0001
Aug 14 22:21:29.636 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 221 chars of
Mail::SpamAssassin::Plugin::Check::_uri_tests_neg400_1
Aug 14 22:21:29.637 [6233] dbg: rules: run_generic_tests - compiling
eval code: uri, priority -400
Aug 14 22:21:29.637 [6233] dbg: rules: compiled uri tests
Aug 14 22:21:29.637 [6233] dbg: rules: running body_eval tests; score
so far=-0.0001
Aug 14 22:21:29.637 [6233] dbg: rules: run_eval_tests - compiling eval
code: 11, priority -400
Aug 14 22:21:29.637 [6233] dbg: rules: running rawbody tests; score so
far=-0.0001
Aug 14 22:21:29.637 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 229 chars of
Mail::SpamAssassin::Plugin::Check::_rawbody_tests_neg400_1
Aug 14 22:21:29.638 [6233] dbg: rules: run_generic_tests - compiling
eval code: rawbody, priority -400
Aug 14 22:21:29.638 [6233] dbg: rules: compiled rawbody tests
Aug 14 22:21:29.638 [6233] dbg: rules: running full tests; score so
far=-0.0001
Aug 14 22:21:29.638 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 258 chars of
Mail::SpamAssassin::Plugin::Check::_full_tests_neg400_1
Aug 14 22:21:29.638 [6233] dbg: rules: run_generic_tests - compiling
eval code: full, priority -400
Aug 14 22:21:29.638 [6233] dbg: rules: compiled full tests
Aug 14 22:21:29.638 [6233] dbg: rules: running meta tests; score so
far=-0.0001
Aug 14 22:21:29.638 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 283 chars of
Mail::SpamAssassin::Plugin::Check::_meta_tests_neg400_1
Aug 14 22:21:29.639 [6233] dbg: rules: run_generic_tests - compiling
eval code: meta, priority -400
Aug 14 22:21:29.639 [6233] dbg: rules: compiled meta tests
Aug 14 22:21:29.639 [6233] dbg: check: running tests for priority: 0
Aug 14 22:21:29.639 [6233] dbg: rules: running head tests; score so
far=-0.0001
Aug 14 22:21:29.657 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60279 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_0_1
Aug 14 22:21:29.666 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60481 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_0_2
Aug 14 22:21:29.674 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60404 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_0_3
Aug 14 22:21:29.681 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60257 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_0_4
Aug 14 22:21:29.689 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60504 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_0_5
Aug 14 22:21:29.698 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 58923 chars of
Mail::SpamAssassin::Plugin::Check::_head_tests_0_6
Aug 14 22:21:29.703 [6233] dbg: rules: run_generic_tests - compiling
eval code: head, priority 0
Aug 14 22:21:29.703 [6233] dbg: rules: compiled head tests
Aug 14 22:21:29.704 [6233] dbg: rules: ran header rule
__LAST_EXTERNAL_RELAY_NO_AUTH ======> got hit: "[ ip=65.55.116.91
rdns=blu0-omc3-s16.blu0.hotmail.com helo=blu0-omc3-s16.blu0.hotmail.com
by=kilnar.com ident= envfrom= intl=0 id=30434200283 auth= "
Aug 14 22:21:29.705 [6233] dbg: rules: ran header rule __HOST_HOTMAIL
======> got hit: "[ ip=65.55.116.91 rdns=blu0-omc3-s16.blu0.hotmail.com
"
Aug 14 22:21:29.705 [6233] dbg: rules: ran header rule
__RCD_RDNS_MAIL_MESSY ======> got hit: "[ ip=65.55.116.91
rdns=blu0-omc3-s16.blu0.hotmail"
Aug 14 22:21:29.705 [6233] dbg: rules: ran header rule
__DOS_RELAYED_EXT ======> got hit: "Received: from
blu0-omc3-s16.blu0.hotmail.com (blu0-omc3-s16.blu0.hotmail.com
[65.55.116.91])
Aug 14 22:21:29.705 [6233] dbg: rules: [...]
Aug 14 22:21:29.705 [6233] dbg: rules: [...] by kilnar.com (Postfix)
with ESMTP id 30434200283
Aug 14 22:21:29.705 [6233] dbg: rules: [...]
Aug 14 22:21:29.705 [6233] dbg: rules: [...] for <anthol...@csfwg.org>;
Tue, 14 Aug 2012 17:23:25 -0600 (MDT)
Aug 14 22:21:29.705 [6233] dbg: rules: [...]
Aug 14 22:21:29.705 [6233] dbg: rules: [...] Received: "
Aug 14 22:21:29.706 [6233] dbg: rules: ran header rule
__CTYPE_HAS_BOUNDARY ======> got hit: "boundary"
Aug 14 22:21:29.706 [6233] dbg: rules: ran header rule __CT ======> got
hit: "<YES>"
Aug 14 22:21:29.706 [6233] dbg: rules: ran header rule
__CTYPE_MULTIPART_ANY ======> got hit: "multipart/mixed"
Aug 14 22:21:29.706 [6233] dbg: rules: ran header rule __HAS_DATE
======> got hit: "<YES>"
Aug 14 22:21:29.706 [6233] dbg: rules: ran header rule
__LAST_UNTRUSTED_RELAY_NO_AUTH ======> got hit: "[ ip=65.55.116.91
rdns=blu0-omc3-s16.blu0.hotmail.com helo=blu0-omc3-s16.blu0.hotmail.com
by=kilnar.com ident= envfrom= intl=0 id=30434200283 auth= "
Aug 14 22:21:29.707 [6233] dbg: rules: ran header rule __MSGID_OK_HOST
======> got hit: "@phx.gbl>"
Aug 14 22:21:29.707 [6233] dbg: rules: ran header rule __HAS_MESSAGE_ID
======> got hit: "<YES>"
Aug 14 22:21:29.707 [6233] dbg: rules: ran header rule __MIME_VERSION
======> got hit: "<YES>"
Aug 14 22:21:29.708 [6233] dbg: rules: ran header rule __TOCC_EXISTS
======> got hit: "<YES>"
Aug 14 22:21:29.708 [6233] dbg: rules: ran header rule __HAS_RCVD
======> got hit: "<YES>"
Aug 14 22:21:29.708 [6233] dbg: rules: ran header rule __DOS_RCVD_TUE
======> got hit: " Tue, "
Aug 14 22:21:29.708 [6233] dbg: rules: ran header rule __HS_SUBJ_RE_FW
======> got hit: "RE:"
Aug 14 22:21:29.709 [6233] dbg: rules: ran header rule __HAS_SUBJECT
======> got hit: "<YES>"
Aug 14 22:21:29.709 [6233] dbg: rules: ran header rule __SUBJ_RE
======> got hit: "RE:"
Aug 14 22:21:29.710 [6233] dbg: rules: ran header rule __HAS_MSGID
======> got hit: "<"
Aug 14 22:21:29.710 [6233] dbg: rules: ran header rule __SANE_MSGID
======> got hit: "<blu166-w3502167a19eb605f932121f5...@phx.gbl>
Aug 14 22:21:29.710 [6233] dbg: rules: [...] "
Aug 14 22:21:29.710 [6233] dbg: rules: ran header rule __HAS_TO ======>
got hit: "<YES>"
Aug 14 22:21:29.711 [6233] dbg: rules: ran header rule
__HAS_IN_REPLY_TO ======> got hit: "<YES>"
Aug 14 22:21:29.711 [6233] dbg: rules: ran header rule __HAS_X_REF
======> got hit: "<YES>"
Aug 14 22:21:29.711 [6233] dbg: rules: ran header rule __HAS_FROM
======> got hit: "<YES>"
Aug 14 22:21:29.711 [6233] dbg: rules: ran header rule __FROM_FREEMAIL
======> got hit: "@hotmail."
Aug 14 22:21:29.711 [6233] dbg: rules: ran header rule
__FROM_HOTMAIL_COM ======> got hit: "@hotmail.com"
Aug 14 22:21:29.714 [6233] dbg: async: select found 7 responses ready
(t.o.=0.0)
Aug 14 22:21:29.714 [6233] dbg: async: completed in 0.098 s: URI-A,
A:dns2.csfwg.org.
Aug 14 22:21:29.714 [6233] dbg: dns: providing a callback for id:
45168/230.18.111.64.zen.spamhaus.org/A/IN
Aug 14 22:21:29.714 [6233] dbg: async: starting: URI-DNSBL,
DNSBL:zen.spamhaus.org.:230.18.111.64 (timeout 15.0s, min 3.0s)
Aug 14 22:21:29.715 [6233] dbg: async: completed in 0.098 s: URI-A,
A:dns1.csfwg.org.
Aug 14 22:21:29.715 [6233] dbg: async: completed in 0.108 s: DNSBL-TXT,
dns:TXT:91.116.55.65.sa-accredit.habeas.com.
Aug 14 22:21:29.715 [6233] dbg: async: completed in 0.121 s: DNSBL-TXT,
dns:TXT:72.116.55.65.bl.spamcop.net.
Aug 14 22:21:29.715 [6233] dbg: async: completed in 0.121 s: DNSBL-TXT,
dns:TXT:179.202.71.75.bl.spamcop.net.
Aug 14 22:21:29.715 [6233] dbg: async: completed in 0.111 s: DNSBL-TXT,
dns:TXT:91.116.55.65.sa-trusted.bondedsender.org.
Aug 14 22:21:29.715 [6233] dbg: async: completed in 0.121 s: DNSBL-TXT,
dns:TXT:91.116.55.65.bl.spamcop.net.
Aug 14 22:21:29.715 [6233] dbg: async: queries completed: 7, started: 1
Aug 14 22:21:29.715 [6233] dbg: async: queries active: URI-DNSBL=2 at
Tue Aug 14 22:21:29 2012
Aug 14 22:21:29.715 [6233] dbg: dns: harvested completed queries
Aug 14 22:21:29.715 [6233] dbg: rules: running head_eval tests; score
so far=-0.0001
Aug 14 22:21:29.717 [6233] dbg: rules: run_eval_tests - compiling eval
code: 9, priority 0
Aug 14 22:21:29.723 [6233] dbg: FreeMail: RULE (FREEMAIL_FROM)
check_freemail_from
Aug 14 22:21:29.723 [6233] dbg: FreeMail: all from-addresses:
mel_k...@hotmail.com
Aug 14 22:21:29.723 [6233] dbg: FreeMail: HIT! mel_k...@hotmail.com is
freemail
Aug 14 22:21:29.724 [6233] dbg: rules: ran eval rule FREEMAIL_FROM
======> got hit (1)
Aug 14 22:21:29.745 [6233] dbg: dkim: using Mail::DKIM version 0.38
Aug 14 22:21:29.747 [6233] dbg: dkim: performing public key lookup and
signature verification
Aug 14 22:21:29.747 [6233] dbg: dkim: signature verification result:
none
Aug 14 22:21:29.747 [6233] dbg: dkim: adsp: performing lookup on
_adsp._domainkey.hotmail.com
Aug 14 22:21:29.751 [6233] dbg: dkim: adsp result: U/unknown (dns:
unknown), author domain 'hotmail.com'
Aug 14 22:21:29.751 [6233] dbg: spf: checking to see if the message has
a Received-SPF header that we can use
Aug 14 22:21:29.782 [6233] dbg: spf: using Mail::SPF for SPF checks
Aug 14 22:21:29.782 [6233] dbg: spf: checking HELO
(helo=blu0-omc3-s16.blu0.hotmail.com, ip=65.55.116.91)
Aug 14 22:21:29.783 [6233] dbg: dns: providing a callback for id:
31165/blu0-omc3-s16.blu0.hotmail.com/SPF/IN
Aug 14 22:21:29.784 [6233] dbg: dns: providing a callback for id:
33937/blu0-omc3-s16.blu0.hotmail.com/TXT/IN
Aug 14 22:21:29.785 [6233] dbg: spf: query for
/65.55.116.91/blu0-omc3-s16.blu0.hotmail.com: result: none, comment: ,
text: No applicable sender policy available
Aug 14 22:21:29.787 [6233] dbg: dkim: author mel_k...@hotmail.com, not
in any dkim whitelist
Aug 14 22:21:29.787 [6233] dbg: spf: already checked for Received-SPF
headers, proceeding with DNS based checks
Aug 14 22:21:29.788 [6233] dbg: spf: cannot get Envelope-From, cannot
use SPF
Aug 14 22:21:29.788 [6233] dbg: FreeMail: RULE (__freemail_reply)
check_freemail_replyto
Aug 14 22:21:29.788 [6233] dbg: FreeMail: From address:
mel_k...@hotmail.com
Aug 14 22:21:29.837 [6233] dbg: FreeMail: RULE
(FREEMAIL_REPLYTO_END_DIGIT) check_freemail_header regex:\d@
Aug 14 22:21:29.837 [6233] dbg: FreeMail: header Reply-To not found
from mail
Aug 14 22:21:29.837 [6233] dbg: FreeMail: RULE (__freemail_replyto)
check_freemail_replyto
Aug 14 22:21:29.838 [6233] dbg: FreeMail: From address:
mel_k...@hotmail.com
Aug 14 22:21:29.838 [6233] dbg: FreeMail: Reply-To is not freemail,
skipping check
Aug 14 22:21:29.838 [6233] dbg: FreeMail: RULE (__freemail_hdr_replyto)
check_freemail_header
Aug 14 22:21:29.838 [6233] dbg: FreeMail: header Reply-To not found
from mail
Aug 14 22:21:29.838 [6233] dbg: spf: def_spf_whitelist_from: already
checked spf and didn't get pass, skipping whitelist check
Aug 14 22:21:29.838 [6233] dbg: FreeMail: RULE
(FREEMAIL_ENVFROM_END_DIGIT) check_freemail_header regex:\d@
Aug 14 22:21:29.838 [6233] dbg: FreeMail: header EnvelopeFrom not found
from mail
Aug 14 22:21:29.839 [6233] dbg: spf: whitelist_from_spf: already
checked spf and didn't get pass, skipping whitelist check
Aug 14 22:21:29.839 [6233] dbg: async: select found no responses ready
(t.o.=0.0)
Aug 14 22:21:29.839 [6233] dbg: async: completed in 0.198 s: URI-DNSBL,
DNSBL:multi.uribl.com.:csfwg.org
Aug 14 22:21:29.840 [6233] dbg: async: completed in 0.069 s: URI-DNSBL,
DNSBL:zen.spamhaus.org.:230.18.111.64
Aug 14 22:21:29.840 [6233] dbg: dns: harvested completed queries
Aug 14 22:21:29.840 [6233] dbg: rules: running body tests; score so
far=0.0009
Aug 14 22:21:29.844 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60166 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_1
Aug 14 22:21:29.855 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60299 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_2
Aug 14 22:21:29.866 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60330 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_3
Aug 14 22:21:29.877 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60195 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_4
Aug 14 22:21:29.888 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60455 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_5
Aug 14 22:21:29.900 [6233] dbg: rules: flush_evalstr (add_evalstr)
compiling 60430 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_6
Aug 14 22:21:29.908 [6233] dbg: rules: flush_evalstr
(run_generic_tests) compiling 8457 chars of
Mail::SpamAssassin::Plugin::Check::_body_tests_0_7
Aug 14 22:21:29.910 [6233] dbg: rules: run_generic_tests - compiling
eval code: body, priority 0
Aug 14 22:21:29.910 [6233] dbg: rules: compiled body tests
Aug 14 22:21:30.078 [6233] dbg: rules: ran body rule __COMPENSATION
======> got hit: "Compensation"
Aug 14 22:21:30.292 [6233] dbg: rules: ran body rule __APPROVALFVGT
======> got hit: "approval"
Aug 14 22:21:30.434 [6233] dbg: rules: ran body rule __HAS_ANY_EMAIL
======> got hit: "y@csfwg.o"
Aug 14 22:21:30.504 [6233] dbg: rules: ran body rule __NONEMPTY_BODY
======> got hit: "R"
Aug 14 22:21:30.592 [6233] dbg: rules: ran body rule __LONGWORDS_A
======> got hit:
"ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
fffffffffffffffffdfffffffeffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
"
Aug 14 22:21:30.762 [6233] dbg: rules: ran body rule T_FRT_CONTACT
======> got hit: "cont ract"
Aug 14 23:59:21.418 [6233] info: check: exceeded time limit in
Mail::SpamAssassin::Plugin::Check::_body_tests_0, skipping further tests
Aug 14 23:59:21.418 [6233] dbg: dns: harvest_dnsbl_queries
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.007 .
dns:A:91.116.55.65.iadb.isipp.com.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.009 .
dns:A:72.116.55.65.zen.spamhaus.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.009 .
dns:A:179.202.71.75.zen.spamhaus.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.011 .
dns:A:91.116.55.65.bb.barracudacentral.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.011 .
dns:A:91.116.55.65.list.dnswl.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.012 .
dns:A:91.116.55.65.psbl.surriel.com.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.013 .
dns:A:179.202.71.75.dnsbl.sorbs.net.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.013 .
dns:A:91.116.55.65.bl.score.senderscore.com.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.014 .
dns:A:91.116.55.65.dnsbl.sorbs.net.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.014 .
dns:A:72.116.55.65.dnsbl.sorbs.net.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.014 .
dns:A:91.116.55.65.zen.spamhaus.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.018 .
dns:A:91.116.55.65.combined.njabl.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.018 .
dns:A:72.116.55.65.combined.njabl.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.019 .
dns:A:179.202.71.75.combined.njabl.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.020 . NS:csfwg.org
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.020 .
DNSBL:dbl.spamhaus.org.:csfwg.org
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.021 .
DNSBL:dob.sibl.support-intelligence.net:csfwg.org
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.022 .
DNSBL:multi.surbl.org.:csfwg.org
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.069 .
DNSBL:zen.spamhaus.org.:230.18.111.64
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.098 .
A:dns1.csfwg.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.098 .
A:dns2.csfwg.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.108 .
dns:TXT:91.116.55.65.sa-accredit.habeas.com.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.111 .
dns:TXT:91.116.55.65.sa-trusted.bondedsender.org.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.121 .
dns:TXT:91.116.55.65.bl.spamcop.net.
Aug 14 23:59:21.419 [6233] dbg: async: timing: 0.121 .
dns:TXT:72.116.55.65.bl.spamcop.net.
Aug 14 23:59:21.420 [6233] dbg: async: timing: 0.121 .
dns:TXT:179.202.71.75.bl.spamcop.net.
Aug 14 23:59:21.420 [6233] dbg: async: timing: 0.198 .
DNSBL:multi.uribl.com.:csfwg.org
Aug 14 23:59:21.420 [6233] dbg: check: is spam? score=0.012 required=5
Aug 14 23:59:21.421 [6233] dbg: check:
tests=FREEMAIL_FROM,RCVD_IN_DNSWL_NONE,TIME_LIMIT_EXCEEDED,T_FRT_CONTACT
Aug 14 23:59:21.421 [6233] dbg: check:
subtests=__APPROVALFVGT,__COMPENSATION,__CT,__CTYPE_HAS_BOUNDARY,__CTYPE_MULTIPART_ANY,__DOS_RCVD_TUE,__DOS_RELAYED_EXT,__FROM_FREEMAIL,__FROM_HOTMAIL_COM,__HAS_ANY_EMAIL,__HAS_DATE,__HAS_FROM,__HAS_IN_REPLY_TO,__HAS_MESSAGE_ID,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__HAS_TO,__HAS_X_REF,__HOST_HOTMAIL,__HS_SUBJ_RE_FW,__LAST_EXTERNAL_RELAY_NO_AUTH,__LAST_UNTRUSTED_RELAY_NO_AUTH,__LONGWORDS_A,__MIME_VERSION,__MSGID_OK_HOST,__NONEMPTY_BODY,__RCD_RDNS_MAIL_MESSY,__RCVD_IN_DNSWL,__RCVD_IN_SORBS,__RCVD_IN_ZEN,__SANE_MSGID,__SUBJ_RE,__TOCC_EXISTS
Aug 14 23:59:21.421 [6233] dbg: timing: total 5873022 ms - init: 1125
(0.0%), parse: 4 (0.0%), extract_message_metadata: 54 (0.0%),
poll_dns_idle: 0.52 (0.0%), get_uri_detail_list: 25 (0.0%),
tests_pri_-1000: 18 (0.0%), compile_gen: 80 (0.0%), compile_eval: 7
(0.0%), tests_pri_-950: 4 (0.0%), tests_pri_-900: 6 (0.0%),
tests_pri_-400: 4 (0.0%), tests_pri_0: 5871779 (100.0%),
dkim_load_modules: 21 (0.0%), check_dkim_signature: 1.97 (0.0%),
check_dkim_adsp: 4 (0.0%), check_spf: 34 (0.0%)
Aug 14 23:59:21.426 [6233] dbg: plugin:
Mail::SpamAssassin::Plugin::MIMEHeader=HASH(0x3c872b8) implements
'finish_tests', priority 0
Aug 14 23:59:21.426 [6233] dbg: plugin:
Mail::SpamAssassin::Plugin::Check=HASH(0x287cdd8) implements
'finish_tests', priority 0
