I'm having a problem with spamassassin taking ages due to DNS lookups timing out. I could make the timeout shorter, but I'd rather try to find out what it's failing on and stop it trying to do those lookups. I've made a log of its debugging output (attached) but I don't understand it well enough to be able to identify the problem correctly. I hope someone here can help me. TIA.
-- TH * http://www.realh.co.uk
[14452] dbg: logger: adding facilities: all [14452] dbg: logger: logging level is DBG [14452] dbg: generic: SpamAssassin version 3.2.0 [14452] dbg: config: score set 0 chosen. [14452] dbg: util: running in taint mode? yes [14452] dbg: util: taint mode: deleting unsafe environment variables, resetting PATH [14452] dbg: util: PATH included '/usr/local/bin', keeping [14452] dbg: util: PATH included '/usr/bin', keeping [14452] dbg: util: PATH included '/bin', keeping [14452] dbg: util: PATH included '/usr/bin/X11', keeping [14452] dbg: util: PATH included '/usr/games', keeping [14452] dbg: util: PATH included '/home/tony/bin', keeping [14452] dbg: util: PATH included '/sbin', keeping [14452] dbg: util: PATH included '/usr/sbin', keeping [14452] dbg: util: PATH included '/usr/local/sbin', keeping [14452] dbg: util: PATH included '/usr/local/lib/jdk1.5.0_06/bin', keeping [14452] dbg: util: final PATH set to: /usr/local/bin:/usr/bin:/bin:/usr/bin/X11:/usr/games:/home/tony/bin:/sbin:/usr/sbin:/usr/local/sbin:/usr/local/lib/jdk1.5.0_06/bin [14452] dbg: dns: no ipv6 [14452] dbg: dns: is Net::DNS::Resolver available? yes [14452] dbg: dns: Net::DNS version: 0.59 [14452] dbg: config: using "/etc/spamassassin" for site rules pre files [14452] dbg: config: read file /etc/spamassassin/init.pre [14452] dbg: config: read file /etc/spamassassin/v310.pre [14452] dbg: config: read file /etc/spamassassin/v312.pre [14452] dbg: config: read file /etc/spamassassin/v320.pre [14452] dbg: config: using "/usr/share/spamassassin" for sys rules pre files [14452] dbg: config: using "/usr/share/spamassassin" for default rules dir [14452] dbg: config: read file /usr/share/spamassassin/10_default_prefs.cf [14452] dbg: config: read file /usr/share/spamassassin/20_advance_fee.cf [14452] dbg: config: read file /usr/share/spamassassin/20_body_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_compensate.cf [14452] dbg: config: read file /usr/share/spamassassin/20_dnsbl_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_drugs.cf [14452] dbg: config: read file /usr/share/spamassassin/20_dynrdns.cf [14452] dbg: config: read file /usr/share/spamassassin/20_fake_helo_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_head_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_html_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_imageinfo.cf [14452] dbg: config: read file /usr/share/spamassassin/20_meta_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_net_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_phrases.cf [14452] dbg: config: read file /usr/share/spamassassin/20_porn.cf [14452] dbg: config: read file /usr/share/spamassassin/20_ratware.cf [14452] dbg: config: read file /usr/share/spamassassin/20_uri_tests.cf [14452] dbg: config: read file /usr/share/spamassassin/20_vbounce.cf [14452] dbg: config: read file /usr/share/spamassassin/23_bayes.cf [14452] dbg: config: read file /usr/share/spamassassin/25_accessdb.cf [14452] dbg: config: read file /usr/share/spamassassin/25_antivirus.cf [14452] dbg: config: read file /usr/share/spamassassin/25_asn.cf [14452] dbg: config: read file /usr/share/spamassassin/25_dcc.cf [14452] dbg: config: read file /usr/share/spamassassin/25_dkim.cf [14452] dbg: config: read file /usr/share/spamassassin/25_domainkeys.cf [14452] dbg: config: read file /usr/share/spamassassin/25_hashcash.cf [14452] dbg: config: read file /usr/share/spamassassin/25_pyzor.cf [14452] dbg: config: read file /usr/share/spamassassin/25_razor2.cf [14452] dbg: config: read file /usr/share/spamassassin/25_replace.cf [14452] dbg: config: read file /usr/share/spamassassin/25_spf.cf [14452] dbg: config: read file /usr/share/spamassassin/25_textcat.cf [14452] dbg: config: read file /usr/share/spamassassin/25_uribl.cf [14452] dbg: config: read file /usr/share/spamassassin/30_text_de.cf [14452] dbg: config: read file /usr/share/spamassassin/30_text_fr.cf [14452] dbg: config: read file /usr/share/spamassassin/30_text_it.cf [14452] dbg: config: read file /usr/share/spamassassin/30_text_nl.cf [14452] dbg: config: read file /usr/share/spamassassin/30_text_pl.cf [14452] dbg: config: read file /usr/share/spamassassin/30_text_pt_br.cf [14452] dbg: config: read file /usr/share/spamassassin/50_scores.cf [14452] dbg: config: read file /usr/share/spamassassin/60_awl.cf [14452] dbg: config: read file /usr/share/spamassassin/60_shortcircuit.cf [14452] dbg: config: read file /usr/share/spamassassin/60_whitelist.cf [14452] dbg: config: read file /usr/share/spamassassin/60_whitelist_dk.cf [14452] dbg: config: read file /usr/share/spamassassin/60_whitelist_dkim.cf [14452] dbg: config: read file /usr/share/spamassassin/60_whitelist_spf.cf [14452] dbg: config: read file /usr/share/spamassassin/60_whitelist_subject.cf [14452] dbg: config: read file /usr/share/spamassassin/72_active.cf [14452] dbg: config: using "/etc/spamassassin" for site rules dir [14452] dbg: config: read file /etc/spamassassin/65_debian.cf [14452] dbg: config: read file /etc/spamassassin/local.cf [14452] dbg: config: using "/home/tony/.spamassassin" for user state dir [14452] dbg: config: using "/home/tony/.spamassassin/user_prefs" for user prefs file [14452] dbg: config: read file /home/tony/.spamassassin/user_prefs [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDNSBL from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::Hashcash from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::SPF from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::Pyzor from @INC [14452] dbg: pyzor: network tests on, attempting Pyzor [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::Razor2 from @INC [14452] dbg: razor2: razor2 is not available [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::SpamCop from @INC [14452] dbg: reporter: network tests on, attempting SpamCop [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::AWL from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::WhiteListSubject from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEHeader from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::ReplaceTags from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::Check from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTTPSMismatch from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDetail from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::Bayes from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::BodyEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::DNSEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTMLEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::HeaderEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::RelayEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::WLBLEval from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::VBounce from @INC [14452] dbg: plugin: loading Mail::SpamAssassin::Plugin::ImageInfo from @INC [14452] dbg: rules: __MO_OL_9B90B merged duplicates: __MO_OL_C65FA [14452] dbg: rules: __XM_OL_22B61 merged duplicates: __XM_OL_A842E [14452] dbg: rules: __MO_OL_07794 merged duplicates: __MO_OL_8627E __MO_OL_F3B05 [14452] dbg: rules: __XM_OL_07794 merged duplicates: __XM_OL_25340 __XM_OL_3857F __XM_OL_4F240 __XM_OL_58CB5 __XM_OL_6554A __XM_OL_812FF __XM_OL_C65FA __XM_OL_CF0C0 __XM_OL_F475E __XM_OL_F6D01 [14452] dbg: rules: FH_MSGID_01C67 merged duplicates: __MSGID_VGA [14452] dbg: rules: FS_NEW_SOFT_UPLOAD merged duplicates: HS_SUBJ_NEW_SOFTWARE [14452] dbg: rules: __FH_HAS_XMSMAIL merged duplicates: __HAS_MSMAIL_PRI [14452] dbg: rules: __MO_OL_015D5 merged duplicates: __MO_OL_6554A [14452] dbg: rules: __MO_OL_91287 merged duplicates: __MO_OL_B30D1 __MO_OL_CF0C0 [14452] dbg: rules: __XM_OL_015D5 merged duplicates: __XM_OL_4BF4C __XM_OL_4EEDB __XM_OL_5B79A __XM_OL_9B90B __XM_OL_ADFF7 __XM_OL_B30D1 __XM_OL_B4B40 __XM_OL_BC7E6 __XM_OL_F3B05 __XM_OL_FF5C8 [14452] dbg: rules: __XM_OL_5E7ED merged duplicates: __XM_OL_D03AB [14452] dbg: rules: __MO_OL_22B61 merged duplicates: __MO_OL_4F240 __MO_OL_ADFF7 [14452] dbg: rules: __MO_OL_812FF merged duplicates: __MO_OL_BC7E6 [14452] dbg: rules: __MO_OL_25340 merged duplicates: __MO_OL_4EEDB __MO_OL_7533E [14452] dbg: rules: __MO_OL_58CB5 merged duplicates: __MO_OL_B4B40 [14452] dbg: rules: __DOS_HAS_ANY_URI merged duplicates: __HAS_ANY_URI [14452] dbg: rules: __XM_OL_C7C33 merged duplicates: __XM_OL_C9068 __XM_OL_EF20B [14452] dbg: rules: __MO_OL_72641 merged duplicates: __MO_OL_A842E [14452] dbg: rules: __MO_OL_5E7ED merged duplicates: __MO_OL_C7C33 [14452] dbg: rules: __MO_OL_F475E merged duplicates: __MO_OL_FF5C8 [14452] dbg: rules: __MO_OL_4BF4C merged duplicates: __MO_OL_F6D01 [14452] dbg: conf: finish parsing [14452] dbg: plugin: Mail::SpamAssassin::Plugin::ReplaceTags=HASH(0x1e0dee0) implements 'finish_parsing_end', priority 0 [14452] dbg: replacetags: replacing tags [14452] dbg: replacetags: done replacing tags [14452] dbg: config: using "/home/tony/.spamassassin" for user state dir [14452] dbg: bayes: tie-ing to DB file R/O /home/tony/.spamassassin/bayes_toks [14452] dbg: bayes: tie-ing to DB file R/O /home/tony/.spamassassin/bayes_seen [14452] dbg: bayes: found bayes db version 3 [14452] dbg: bayes: DB journal sync: last sync: 1183743549 [14452] dbg: config: using "/home/tony/.spamassassin" for user state dir [14452] dbg: config: score set 3 chosen. [14452] dbg: message: main message type: multipart/mixed [14452] dbg: plugin: Mail::SpamAssassin::Plugin::DNSEval=HASH(0x1ef2a50) implements 'check_start', priority 0 [14452] dbg: plugin: Mail::SpamAssassin::Plugin::Check=HASH(0x1e8cc60) implements 'check_main', priority 0 [14452] dbg: conf: trusted_networks are not configured; it is recommended that you configure trusted_networks manually [14452] dbg: received-header: parsed as [ ip=80.168.53.75 rdns=mailman.ukfsn.org helo=localhost by=mail.ukfsn.org ident= envfrom= intl=0 id=B6011E6FFA auth= msa=0 ] [14452] dbg: received-header: do not trust any hosts from here on [14452] dbg: received-header: relay 80.168.53.75 trusted? no internal? no msa? no [14452] dbg: received-header: parsed as [ ip=80.168.53.20 rdns= helo=mail.ukfsn.org by=localhost ident= envfrom= intl=0 id=W5LB30ajT8tB auth= msa=0 ] [14452] dbg: received-header: relay 80.168.53.20 trusted? no internal? no msa? no [14452] dbg: received-header: parsed as [ ip=213.171.216.36 rdns=freeservices-out-36.livemail.co.uk helo=freeservices-out-36.livemail.co.uk by=mail.ukfsn.org ident= envfrom= intl=0 id=D5280E6EF7 auth= msa=0 ] [14452] dbg: received-header: relay 213.171.216.36 trusted? no internal? no msa? no [14452] dbg: received-header: parsed as [ ip=66.35.250.225 rdns=lists-outbound.sourceforge.net helo=lists-outbound.sourceforge.net by=freeservices-out-36.livemail.co.uk ident= envfrom= intl=0 id=F301B3CE182 auth= msa=0 ] [14452] dbg: received-header: relay 66.35.250.225 trusted? no internal? no msa? no [14452] dbg: received-header: parsed as [ ip=10.3.1.94 rdns=sc8-sf-list2-new-b.sourceforge.net helo=sc8-sf-list2-new.sourceforge.net by=sc8-sf-spam2.sourceforge.net ident= envfrom= intl=0 id=BC24A133B4 auth= msa=0 ] [14452] dbg: received-header: relay 10.3.1.94 trusted? no internal? no msa? no [14452] dbg: metadata: X-Spam-Relays-Trusted: [14452] dbg: metadata: X-Spam-Relays-Untrusted: [ ip=80.168.53.75 rdns=mailman.ukfsn.org helo=localhost by=mail.ukfsn.org ident= envfrom= intl=0 id=B6011E6FFA auth= msa=0 ] [ ip=80.168.53.20 rdns= helo=mail.ukfsn.org by=localhost ident= envfrom= intl=0 id=W5LB30ajT8tB auth= msa=0 ] [ ip=213.171.216.36 rdns=freeservices-out-36.livemail.co.uk helo=freeservices-out-36.livemail.co.uk by=mail.ukfsn.org ident= envfrom= intl=0 id=D5280E6EF7 auth= msa=0 ] [ ip=66.35.250.225 rdns=lists-outbound.sourceforge.net helo=lists-outbound.sourceforge.net by=freeservices-out-36.livemail.co.uk ident= envfrom= intl=0 id=F301B3CE182 auth= msa=0 ] [ ip=10.3.1.94 rdns=sc8-sf-list2-new-b.sourceforge.net helo=sc8-sf-list2-new.sourceforge.net by=sc8-sf-spam2.sourceforge.net ident= envfrom= intl=0 id=BC24A133B4 auth= msa=0 ] [14452] dbg: metadata: X-Spam-Relays-Internal: [14452] dbg: metadata: X-Spam-Relays-External: [ ip=80.168.53.75 rdns=mailman.ukfsn.org helo=localhost by=mail.ukfsn.org ident= envfrom= intl=0 id=B6011E6FFA auth= msa=0 ] [ ip=80.168.53.20 rdns= helo=mail.ukfsn.org by=localhost ident= envfrom= intl=0 id=W5LB30ajT8tB auth= msa=0 ] [ ip=213.171.216.36 rdns=freeservices-out-36.livemail.co.uk helo=freeservices-out-36.livemail.co.uk by=mail.ukfsn.org ident= envfrom= intl=0 id=D5280E6EF7 auth= msa=0 ] [ ip=66.35.250.225 rdns=lists-outbound.sourceforge.net helo=lists-outbound.sourceforge.net by=freeservices-out-36.livemail.co.uk ident= envfrom= intl=0 id=F301B3CE182 auth= msa=0 ] [ ip=10.3.1.94 rdns=sc8-sf-list2-new-b.sourceforge.net helo=sc8-sf-list2-new.sourceforge.net by=sc8-sf-spam2.sourceforge.net ident= envfrom= intl=0 id=BC24A133B4 auth= msa=0 ] [14452] dbg: message: ---- MIME PARSER START ---- [14452] dbg: message: parsing multipart, got boundary: ===============1078031641== [14452] dbg: message: found part of type text/plain, boundary: ===============1078031641== [14452] dbg: message: added part, type: text/plain [14452] dbg: message: found part of type message/rfc822, boundary: ===============1078031641== [14452] dbg: message: added part, type: message/rfc822 [14452] dbg: message: parsing normal part [14452] dbg: message: parsing normal part [14452] dbg: message: no encoding detected [14452] dbg: message: main message type: text/plain [14452] dbg: message: added part, type: text/plain [14452] dbg: message: parsing normal part [14452] dbg: message: ---- MIME PARSER END ---- [14452] dbg: message: decoding other encoding type (7bit), ignoring [14452] dbg: message: no encoding detected [14452] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH(0x1846650) implements 'parsed_metadata', priority 0 [14452] dbg: dns: is_dns_available() last checked 1183744677 seconds ago; re-checking [14452] dbg: dns: name server: 10.0.0.2, LocalAddr: 0.0.0.0 [14452] dbg: dns: testing resolver nameservers: 10.0.0.2 [14452] dbg: dns: trying (3) motorola.com... [14452] dbg: dns: looking up NS for 'motorola.com' [14452] dbg: dns: NS lookup of motorola.com using 10.0.0.2 succeeded => DNS available (set dns_available to override) [14452] dbg: dns: is DNS available? 1 [14452] dbg: uridnsbl: domains to query: [14452] dbg: dns: checking RBL sa-other.bondedsender.org., set bsp-untrusted [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.20, 213.171.216.36, 66.35.250.225 [14452] dbg: dns: launching DNS TXT query for 20.53.168.80.sa-other.bondedsender.org. in background [14452] dbg: dns: launching DNS TXT query for 36.216.171.213.sa-other.bondedsender.org. in background [14452] dbg: dns: launching DNS TXT query for 225.250.35.66.sa-other.bondedsender.org. in background [14452] dbg: dns: checking RBL combined.njabl.org., set njabl [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 66.35.250.225, 213.171.216.36, 80.168.53.20, 80.168.53.75 [14452] dbg: dns: launching DNS A query for 225.250.35.66.combined.njabl.org. in background [14452] dbg: dns: launching DNS A query for 36.216.171.213.combined.njabl.org. in background [14452] dbg: dns: launching DNS A query for 20.53.168.80.combined.njabl.org. in background [14452] dbg: dns: launching DNS A query for 75.53.168.80.combined.njabl.org. in background [14452] dbg: dns: checking RBL bl.spamcop.net., set spamcop [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 66.35.250.225, 213.171.216.36, 80.168.53.20, 80.168.53.75 [14452] dbg: dns: launching DNS TXT query for 225.250.35.66.bl.spamcop.net. in background [14452] dbg: dns: launching DNS TXT query for 36.216.171.213.bl.spamcop.net. in background [14452] dbg: dns: launching DNS TXT query for 20.53.168.80.bl.spamcop.net. in background [14452] dbg: dns: launching DNS TXT query for 75.53.168.80.bl.spamcop.net. in background [14452] dbg: dns: _check_rbl_addresses RBL blackhole.securitysage.com., set securitysage [14452] dbg: dns: launching DNS A query for lists.sourceforge.net.blackhole.securitysage.com. in background [14452] dbg: dns: _check_rbl_addresses RBL rhsbl.ahbl.org., set ahbl [14452] dbg: dns: launching DNS A query for lists.sourceforge.net.rhsbl.ahbl.org. in background [14452] dbg: dns: checking RBL dob.sibl.support-intelligence.net., set dob [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 66.35.250.225, 213.171.216.36, 80.168.53.20, 80.168.53.75 [14452] dbg: dns: launching DNS A query for 225.250.35.66.dob.sibl.support-intelligence.net. in background [14452] dbg: dns: launching DNS A query for 36.216.171.213.dob.sibl.support-intelligence.net. in background [14452] dbg: dns: launching DNS A query for 20.53.168.80.dob.sibl.support-intelligence.net. in background [14452] dbg: dns: launching DNS A query for 75.53.168.80.dob.sibl.support-intelligence.net. in background [14452] dbg: dns: checking A and MX for host lists.sourceforge.net [14452] dbg: dns: launching DNS A query for lists.sourceforge.net in background [14452] dbg: dns: launching DNS MX query for lists.sourceforge.net in background [14452] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: launching DNS A query for 75.53.168.80.zen.spamhaus.org. in background [14452] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs-lastexternal [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: launching DNS A query for 75.53.168.80.dnsbl.sorbs.net. in background [14452] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 66.35.250.225, 213.171.216.36, 80.168.53.20, 80.168.53.75 [14452] dbg: dns: launching DNS A query for 225.250.35.66.dnsbl.sorbs.net. in background [14452] dbg: dns: launching DNS A query for 36.216.171.213.dnsbl.sorbs.net. in background [14452] dbg: dns: launching DNS A query for 20.53.168.80.dnsbl.sorbs.net. in background [14452] dbg: dns: _check_rbl_addresses RBL dob.sibl.support-intelligence.net., set dob [14452] dbg: dns: launching DNS A query for lists.sourceforge.net.dob.sibl.support-intelligence.net. in background [14452] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: checking RBL sa-accredit.habeas.com., set habeas-firsttrusted [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: launching DNS A query for 75.53.168.80.sa-accredit.habeas.com. in background [14452] dbg: dns: checking RBL combined-HIB.dnsiplists.completewhois.com., set whois [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 66.35.250.225, 213.171.216.36, 80.168.53.20, 80.168.53.75 [14452] dbg: dns: launching DNS A query for 225.250.35.66.combined-HIB.dnsiplists.completewhois.com. in background [14452] dbg: dns: launching DNS A query for 36.216.171.213.combined-HIB.dnsiplists.completewhois.com. in background [14452] dbg: dns: launching DNS A query for 20.53.168.80.combined-HIB.dnsiplists.completewhois.com. in background [14452] dbg: dns: launching DNS A query for 75.53.168.80.combined-HIB.dnsiplists.completewhois.com. in background [14452] dbg: dns: checking RBL list.dsbl.org., set dsbl-lastexternal [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: launching DNS TXT query for 75.53.168.80.list.dsbl.org. in background [14452] dbg: dns: checking RBL sa-trusted.bondedsender.org., set bsp-firsttrusted [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: launching DNS TXT query for 75.53.168.80.sa-trusted.bondedsender.org. in background [14452] dbg: dns: checking RBL combined-HIB.dnsiplists.completewhois.com., set whois-lastexternal [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: checking RBL zen.spamhaus.org., set zen [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 66.35.250.225, 213.171.216.36, 80.168.53.20, 80.168.53.75 [14452] dbg: dns: launching DNS A query for 225.250.35.66.zen.spamhaus.org. in background [14452] dbg: dns: launching DNS A query for 36.216.171.213.zen.spamhaus.org. in background [14452] dbg: dns: launching DNS A query for 20.53.168.80.zen.spamhaus.org. in background [14452] dbg: dns: _check_rbl_addresses RBL bl.open-whois.org., set openwhois [14452] dbg: dns: launching DNS A query for lists.sourceforge.net.bl.open-whois.org. in background [14452] dbg: dns: _check_rbl_addresses RBL fulldom.rfc-ignorant.org., set rfci_envfrom [14452] dbg: dns: launching DNS A query for lists.sourceforge.net.fulldom.rfc-ignorant.org. in background [14452] dbg: dns: checking RBL iadb.isipp.com., set iadb-firsttrusted [14452] dbg: dns: IPs found: full-external: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225, 10.3.1.94 untrusted: 80.168.53.75, 80.168.53.20, 213.171.216.36, 66.35.250.225 originating: [14452] dbg: dns: only inspecting the following IPs: 80.168.53.75 [14452] dbg: dns: launching DNS A query for 75.53.168.80.iadb.isipp.com. in background [14452] dbg: check: running tests for priority: -1000 [14452] dbg: rules: running head tests; score so far=0 [14452] dbg: rules: compiled head tests [14452] dbg: eval: all '*From' addrs: [EMAIL PROTECTED] [14452] dbg: eval: all '*To' addrs: [EMAIL PROTECTED] [EMAIL PROTECTED] [14452] dbg: rules: running body tests; score so far=0 [14452] dbg: rules: compiled body tests [14452] dbg: rules: running uri tests; score so far=0 [14452] dbg: rules: compiled uri tests [14452] dbg: rules: running rawbody tests; score so far=0 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=0 [14452] dbg: rules: compiled full tests [14452] dbg: rules: running meta tests; score so far=0 [14452] dbg: rules: compiled meta tests [14452] dbg: check: running tests for priority: -950 [14452] dbg: rules: running head tests; score so far=0 [14452] dbg: rules: compiled head tests [14452] dbg: rules: running body tests; score so far=0 [14452] dbg: rules: compiled body tests [14452] dbg: rules: running uri tests; score so far=0 [14452] dbg: rules: compiled uri tests [14452] dbg: rules: running rawbody tests; score so far=0 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=0 [14452] dbg: rules: compiled full tests [14452] dbg: rules: running meta tests; score so far=0 [14452] dbg: rules: compiled meta tests [14452] dbg: check: running tests for priority: -900 [14452] dbg: rules: running head tests; score so far=0 [14452] dbg: rules: compiled head tests [14452] dbg: rules: running body tests; score so far=0 [14452] dbg: rules: compiled body tests [14452] dbg: rules: running uri tests; score so far=0 [14452] dbg: rules: compiled uri tests [14452] dbg: rules: running rawbody tests; score so far=0 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=0 [14452] dbg: rules: compiled full tests [14452] dbg: rules: running meta tests; score so far=0 [14452] dbg: rules: compiled meta tests [14452] dbg: check: running tests for priority: -400 [14452] dbg: rules: running head tests; score so far=0 [14452] dbg: rules: compiled head tests [14452] dbg: rules: running body tests; score so far=0 [14452] dbg: rules: compiled body tests [14452] dbg: rules: running uri tests; score so far=0 [14452] dbg: rules: compiled uri tests [14452] dbg: plugin: Mail::SpamAssassin::Plugin::WLBLEval=HASH(0x2065910) implements 'check_wb_list', priority 0 [14452] dbg: bayes: DB journal sync: last sync: 1183743549 [14452] dbg: bayes: corpus size: nspam = 2330, nham = 8436 [14452] dbg: bayes: score = 0 [14452] dbg: bayes: DB journal sync: last sync: 1183743549 [14452] dbg: bayes: untie-ing [14452] dbg: rules: running rawbody tests; score so far=0 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=0 [14452] dbg: rules: compiled full tests [14452] dbg: rules: running meta tests; score so far=0 [14452] dbg: rules: compiled meta tests [14452] dbg: check: running tests for priority: 0 [14452] dbg: rules: running head tests; score so far=0 [14452] dbg: rules: compiled head tests [14452] dbg: rules: ran header rule __CTYPE_HAS_BOUNDARY ======> got hit: "boundary" [14452] dbg: rules: ran header rule __CT ======> got hit: "m" [14452] dbg: rules: ran header rule HELO_LOCALHOST ======> got hit: "[ ip=80.168.53.75 rdns=mailman.ukfsn.org helo=localhost " [14452] dbg: rules: ran header rule __HELO_NO_DOMAIN ======> got hit: "[ ip=80.168.53.75 rdns=mailman.ukfsn.org helo=localhost " [14452] dbg: rules: ran header rule __MISSING_REF ======> got hit: "UNSET" [14452] dbg: rules: ran header rule __DATE_700 ======> got hit: "-0700" [14452] dbg: rules: ran header rule __NAKED_TO ======> got hit: "[EMAIL PROTECTED]" [14452] dbg: rules: ran header rule __MIME_VERSION ======> got hit: "1" [14452] dbg: rules: ran header rule __HAS_RCVD ======> got hit: "f" [14452] dbg: rules: ran header rule __DOS_RCVD_FRI ======> got hit: " Fri, " [14452] dbg: rules: ran header rule __TOCC_EXISTS ======> got hit: "h" [14452] dbg: rules: ran header rule __MSGID_OK_HOST ======> got hit: "@lists.sourceforge.net>" [14452] dbg: rules: ran header rule __MSGID_OK_DIGITS ======> got hit: "1183738438" [14452] dbg: rules: ran header rule __HAS_MSGID ======> got hit: "<" [14452] dbg: rules: ran header rule __SANE_MSGID ======> got hit: "<[EMAIL PROTECTED]> [14452] dbg: rules: " [14452] dbg: rules: ran header rule __HAS_SUBJECT ======> got hit: "T" [14452] dbg: rules: ran header rule __MAILMAN_21 ======> got hit: "2" [14452] dbg: spf: checking to see if the message has a Received-SPF header that we can use [14452] dbg: spf: cannot load Mail::SPF module or create Mail::SPF::Server object: Can't locate Mail/SPF.pm in @INC (@INC contains: /usr/share/perl5 /etc/perl /usr/local/lib/perl/5.8.8 /usr/local/share/perl/5.8.8 /usr/lib/perl5 /usr/lib/perl/5.8 /usr/share/perl/5.8 /usr/local/lib/site_perl) at /usr/share/perl5/Mail/SpamAssassin/Plugin/SPF.pm line 390. [14452] dbg: spf: attempting to use legacy Mail::SPF::Query module instead [14452] dbg: spf: cannot load Mail::SPF::Query module: Can't locate Mail/SPF/Query.pm in @INC (@INC contains: /usr/share/perl5 /etc/perl /usr/local/lib/perl/5.8.8 /usr/local/share/perl/5.8.8 /usr/lib/perl5 /usr/lib/perl/5.8 /usr/share/perl/5.8 /usr/local/lib/site_perl) at /usr/share/perl5/Mail/SpamAssassin/Plugin/SPF.pm line 414. [14452] dbg: spf: one of Mail::SPF or Mail::SPF::Query is required for SPF checks, SPF checks disabled [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: rules: ran eval rule __ENV_AND_HDR_FROM_MATCH ======> got hit (1) [14452] dbg: spf: def_whitelist_from_spf: [EMAIL PROTECTED] is not in DEF_WHITELIST_FROM_SPF [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [14452] dbg: spf: whitelist_from_spf: [EMAIL PROTECTED] is not in user's WHITELIST_FROM_SPF [14452] dbg: rules: running body tests; score so far=3.941 [14452] dbg: rules: compiled body tests [14452] dbg: rules: ran body rule __NONEMPTY_BODY ======> got hit: "T" [14452] dbg: rules: running uri tests; score so far=3.941 [14452] dbg: rules: compiled uri tests [14452] dbg: https_http_mismatch: anchors 0 [14452] dbg: eval: stock info total: 0 [14452] dbg: rules: ran eval rule BAYES_00 ======> got hit (1) [14452] dbg: rules: relay (mailman.ukfsn.org doesn't match any whitelist [14452] dbg: rules: relay mail.ukfsn.org doesn't match any whitelist [14452] dbg: rules: relay freeservices-out-36.livemail.co.uk doesn't match any whitelist [14452] dbg: rules: relay lists-outbound.sourceforge.net doesn't match any whitelist [14452] dbg: rules: relay sc8-sf-list2-new.sourceforge.net doesn't match any whitelist [14452] dbg: rules: relay sc8-sf-mx1-b.sourceforge.net doesn't match any whitelist [14452] dbg: rules: relay s2.ukfsn.org doesn't match any whitelist [14452] dbg: rules: relay (mailman.ukfsn.org doesn't match any whitelist [14452] dbg: rules: relay mail.ukfsn.org doesn't match any whitelist [14452] dbg: rules: relay tiber.realh.co.uk doesn't match any whitelist [14452] dbg: rules: relay tiber.realh.co.uk doesn't match any whitelist [14452] dbg: rules: running rawbody tests; score so far=1.342 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=1.342 [14452] dbg: rules: compiled full tests [14452] dbg: util: current PATH is: /usr/local/bin:/usr/bin:/bin:/usr/bin/X11:/usr/games:/home/tony/bin:/sbin:/usr/sbin:/usr/local/sbin:/usr/local/lib/jdk1.5.0_06/bin [14452] dbg: pyzor: pyzor is not available: no pyzor executable found [14452] dbg: pyzor: no pyzor found, disabling Pyzor [14452] dbg: rules: running meta tests; score so far=1.342 [14452] dbg: rules: compiled meta tests [14452] dbg: check: running tests for priority: 500 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=27 DNSBL-MX=1 DNSBL-TXT=9 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=26 DNSBL-MX=1 DNSBL-TXT=9 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=25 DNSBL-MX=1 DNSBL-TXT=9 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=24 DNSBL-MX=1 DNSBL-TXT=9 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=24 DNSBL-MX=1 DNSBL-TXT=8 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=23 DNSBL-MX=1 DNSBL-TXT=8 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=23 DNSBL-MX=1 DNSBL-TXT=7 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=22 DNSBL-MX=1 DNSBL-TXT=7 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=22 DNSBL-MX=1 DNSBL-TXT=6 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=21 DNSBL-MX=1 DNSBL-TXT=6 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=21 DNSBL-MX=1 DNSBL-TXT=5 at Fri Jul 6 18:57:57 2007 [14452] dbg: dns: hit <dns:lists.sourceforge.net?type=MX> 10 mail.sourceforge.net. [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=21 DNSBL-TXT=5 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=20 DNSBL-TXT=5 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=19 DNSBL-TXT=5 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=19 DNSBL-TXT=4 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=19 DNSBL-TXT=3 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=19 DNSBL-TXT=2 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=18 DNSBL-TXT=2 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found 1 socks ready [14452] dbg: async: queries completed: 1 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:57:57 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:57:58 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:57:59 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:00 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:01 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:02 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:03 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:04 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:05 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:06 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:07 2007 [14452] dbg: async: select found no socks ready [14452] dbg: async: queries completed: 0 started: 0 [14452] dbg: async: queries active: DNSBL-A=17 DNSBL-TXT=2 at Fri Jul 6 18:58:08 2007 [14452] dbg: dns: success for 19 of 38 queries [14452] dbg: dns: timeout for bsp-firsttrusted after 11 seconds [14452] dbg: dns: timeout for zen-lastexternal,zen-lastexternal,zen after 11 seconds [14452] dbg: dns: timeout for whois after 11 seconds [14452] dbg: dns: timeout for openwhois after 11 seconds [14452] dbg: dns: timeout for dsbl-lastexternal after 11 seconds [14452] dbg: dns: timeout for rfci_envfrom after 11 seconds [14452] dbg: dns: timeout for sorbs after 11 seconds [14452] dbg: dns: timeout for whois after 11 seconds [14452] dbg: dns: timeout for zen after 11 seconds [14452] dbg: dns: timeout for dob after 11 seconds [14452] dbg: dns: timeout for NO_DNS_FOR_FROM after 11 seconds [14452] dbg: dns: timeout for zen after 11 seconds [14452] dbg: dns: timeout for zen after 11 seconds [14452] dbg: dns: timeout for dob after 11 seconds [14452] dbg: dns: timeout for ahbl after 11 seconds [14452] dbg: dns: timeout for sorbs after 11 seconds [14452] dbg: dns: timeout for whois,whois-lastexternal after 11 seconds [14452] dbg: dns: timeout for whois after 11 seconds [14452] dbg: dns: timeout for iadb-firsttrusted after 11 seconds [14452] dbg: async: aborting remaining lookups [14452] dbg: rules: running head tests; score so far=1.342 [14452] dbg: rules: compiled head tests [14452] dbg: rules: running body tests; score so far=1.342 [14452] dbg: rules: compiled body tests [14452] dbg: rules: running uri tests; score so far=1.342 [14452] dbg: rules: compiled uri tests [14452] dbg: rules: running rawbody tests; score so far=1.342 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=1.342 [14452] dbg: rules: compiled full tests [14452] dbg: rules: running meta tests; score so far=1.342 [14452] dbg: rules: meta test DIGEST_MULTIPLE has undefined dependency 'DCC_CHECK' [14452] dbg: rules: compiled meta tests [14452] dbg: check: running tests for priority: 1000 [14452] dbg: rules: running head tests; score so far=1.342 [14452] dbg: rules: compiled head tests [14452] dbg: config: using "/home/tony/.spamassassin" for user state dir [14452] dbg: locker: safe_lock: created /home/tony/.spamassassin/auto-whitelist.lock.tiber.realh.co.uk.14452 [14452] dbg: locker: safe_lock: trying to get lock on /home/tony/.spamassassin/auto-whitelist with 0 retries [14452] dbg: locker: safe_lock: link to /home/tony/.spamassassin/auto-whitelist.lock: link ok [14452] dbg: auto-whitelist: tie-ing to DB file of type DB_File R/W in /home/tony/.spamassassin/auto-whitelist [14452] dbg: auto-whitelist: db-based [EMAIL PROTECTED]|ip=66.35 scores 44/-7.656 [14452] dbg: auto-whitelist: AWL active, pre-score: 1.342, autolearn score: 1.342, mean: -0.174, IP: 66.35.250.225 [14452] dbg: auto-whitelist: add_score: new count: 45, new totscore: -6.314 [14452] dbg: auto-whitelist: DB addr list: untie-ing and unlocking [14452] dbg: auto-whitelist: DB addr list: file locked, breaking lock [14452] dbg: locker: safe_unlock: unlink /home/tony/.spamassassin/auto-whitelist.lock [14452] dbg: auto-whitelist: post auto-whitelist score: 0.584 [14452] dbg: rules: running body tests; score so far=0.584 [14452] dbg: rules: compiled body tests [14452] dbg: rules: running uri tests; score so far=0.584 [14452] dbg: rules: compiled uri tests [14452] dbg: rules: running rawbody tests; score so far=0.584 [14452] dbg: rules: compiled rawbody tests [14452] dbg: rules: running full tests; score so far=0.584 [14452] dbg: rules: compiled full tests [14452] dbg: rules: running meta tests; score so far=0.584 [14452] dbg: rules: compiled meta tests [14452] dbg: plugin: Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x199ec60) implements 'autolearn_discriminator', priority 0 [14452] dbg: learn: auto-learn: currently using scoreset 3, recomputing score based on scoreset 1 [14452] dbg: learn: auto-learn: message score: 0.584, computed score for autolearn: 4.499 [14452] dbg: learn: auto-learn? ham=-1, spam=12, body-points=4.499, head-points=4.499, learned-points=-2.599 [14452] dbg: learn: auto-learn? no: inside auto-learn thresholds, not considered ham or spam [14452] dbg: check: is spam? score=0.584 required=5 [14452] dbg: check: tests=AWL,BAYES_00,HELO_LOCALHOST [14452] dbg: check: subtests=__CT,__CTYPE_HAS_BOUNDARY,__DATE_700,__DOS_RCVD_FRI,__ENV_AND_HDR_FROM_MATCH,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__HELO_NO_DOMAIN,__MAILMAN_21,__MIME_VERSION,__MISSING_REF,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__NAKED_TO,__NONEMPTY_BODY,__SANE_MSGID,__TOCC_EXISTS