Mon Jul 30 12:02:24 2007 [9030] dbg: logger: successfully added file method Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: will perform setuids? 1 Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: creating INET socket: Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: Listen: 128 Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: LocalAddr: 192.168.101.2 Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: LocalPort: 783 Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: Proto: 6 Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: ReuseAddr: 1 Mon Jul 30 12:02:24 2007 [9030] dbg: spamd: Type: 1 Mon Jul 30 12:02:24 2007 [9030] dbg: logger: adding facilities: all Mon Jul 30 12:02:24 2007 [9030] dbg: logger: logging level is DBG Mon Jul 30 12:02:24 2007 [9030] dbg: generic: SpamAssassin version 3.2.3-r559432 Mon Jul 30 12:02:24 2007 [9030] dbg: config: score set 0 chosen. Mon Jul 30 12:02:25 2007 [9030] dbg: dns: is Net::DNS::Resolver available? yes Mon Jul 30 12:02:25 2007 [9030] dbg: dns: Net::DNS version: 0.60 Mon Jul 30 12:02:25 2007 [9030] dbg: learn: initializing learner Mon Jul 30 12:02:25 2007 [9030] dbg: config: using "/etc/mail/spamassassin" for site rules pre files Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /etc/mail/spamassassin/init.pre Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /etc/mail/spamassassin/v310.pre Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /etc/mail/spamassassin/v312.pre Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /etc/mail/spamassassin/v320.pre Mon Jul 30 12:02:25 2007 [9030] dbg: config: using "/usr/local/share/spamassassin" for sys rules pre files Mon Jul 30 12:02:25 2007 [9030] dbg: config: using "/usr/local/share/spamassassin" for default rules dir Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/10_default_prefs.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_advance_fee.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_body_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_compensate.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_dnsbl_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_drugs.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_dynrdns.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_fake_helo_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_head_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_html_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_imageinfo.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_meta_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_net_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_phrases.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_porn.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_ratware.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_uri_tests.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/20_vbounce.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/23_bayes.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_accessdb.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_antivirus.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_asn.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_dcc.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_dkim.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_domainkeys.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_hashcash.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_pyzor.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_razor2.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_replace.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_spf.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_textcat.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/25_uribl.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/30_text_de.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/30_text_fr.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/30_text_it.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/30_text_nl.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/30_text_pl.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/30_text_pt_br.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/50_scores.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_awl.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_shortcircuit.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_whitelist.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_whitelist_dk.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_whitelist_dkim.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_whitelist_spf.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/60_whitelist_subject.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /usr/local/share/spamassassin/72_active.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: using "/etc/mail/spamassassin" for site rules dir Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /etc/mail/spamassassin/local.cf Mon Jul 30 12:02:25 2007 [9030] dbg: config: using "/root/.spamassassin/user_prefs" for user prefs file Mon Jul 30 12:02:25 2007 [9030] dbg: config: read file /root/.spamassassin/user_prefs Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::RelayCountry from @INC Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDNSBL from @INC Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Hashcash from @INC Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::SPF from @INC Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::DCC from @INC Mon Jul 30 12:02:25 2007 [9030] dbg: dcc: network tests on, registering DCC Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Pyzor from @INC Mon Jul 30 12:02:25 2007 [9030] dbg: pyzor: network tests on, attempting Pyzor Mon Jul 30 12:02:25 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Razor2 from @INC Mon Jul 30 12:02:26 2007 [9030] dbg: razor2: razor2 is available, version 2.84 Mon Jul 30 12:02:26 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::SpamCop from @INC Mon Jul 30 12:02:26 2007 [9030] dbg: reporter: network tests on, attempting SpamCop Mon Jul 30 12:02:26 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::AntiVirus from @INC Mon Jul 30 12:02:26 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::AWL from @INC Mon Jul 30 12:02:26 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC Mon Jul 30 12:02:26 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::TextCat from @INC Mon Jul 30 12:02:26 2007 [9030] dbg: textcat: loading languages file... Mon Jul 30 12:02:26 2007 [9030] dbg: textcat: loaded 73 language models Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEHeader from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Pyzor from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: pyzor: network tests on, attempting Pyzor Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::Pyzor=HASH(0x8d69418), already registered Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Razor2 from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: razor2: razor2 is available, version 2.84 Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::Razor2=HASH(0x8d69460), already registered Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::SpamCop from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: reporter: network tests on, attempting SpamCop Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::SpamCop=HASH(0x8d6946c), already registered Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::AWL from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::AWL=HASH(0x94ce1cc), already registered Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x8d84258), already registered Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::WhiteListSubject from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEHeader from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::MIMEHeader=HASH(0x8d842c4), already registered Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::ReplaceTags from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::DKIM from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::ImageInfo from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Check from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTTPSMismatch from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDetail from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::Bayes from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::BodyEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::DNSEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTMLEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::HeaderEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::RelayEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::WLBLEval from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::VBounce from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: loading Mail::SpamAssassin::Plugin::ImageInfo from @INC Mon Jul 30 12:02:27 2007 [9030] dbg: plugin: did not register Mail::SpamAssassin::Plugin::ImageInfo=HASH(0x968ae2c), already registered Mon Jul 30 12:02:30 2007 [9030] dbg: conf: finish parsing Mon Jul 30 12:02:30 2007 [9030] dbg: plugin: Mail::SpamAssassin::Plugin::ReplaceTags=HASH(0x94dd474) implements 'finish_parsing_end', priority 0 Mon Jul 30 12:02:30 2007 [9030] dbg: replacetags: replacing tags Mon Jul 30 12:02:30 2007 [9030] dbg: replacetags: done replacing tags Mon Jul 30 12:02:31 2007 [9030] dbg: bayes: using username: root Mon Jul 30 12:02:31 2007 [9030] dbg: bayes: database connection established Mon Jul 30 12:02:31 2007 [9030] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:31 2007 [9030] dbg: bayes: Using userid: 32 Mon Jul 30 12:02:31 2007 [9030] dbg: bayes: not available for scanning, only 2 spam(s) in bayes DB < 200 Mon Jul 30 12:02:31 2007 [9030] dbg: config: score set 1 chosen. Mon Jul 30 12:02:31 2007 [9030] info: logger: removing stderr method Mon Jul 30 12:02:31 2007 [9033] dbg: spamd: successfully daemonized Mon Jul 30 12:02:31 2007 [9033] dbg: spamd: Preloading modules with HOME=/tmp/spamd-9033-init Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::HeaderEval=HASH(0x96890c0) implements 'compile_now_start', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: eval: failed to locate the triplets.txt file Mon Jul 30 12:02:31 2007 [9033] dbg: ignore: test message to precompile patterns and load modules Mon Jul 30 12:02:31 2007 [9033] dbg: dns: name server: 127.0.0.1, LocalAddr: 0.0.0.0 Mon Jul 30 12:02:31 2007 [9033] dbg: message: main message type: text/plain Mon Jul 30 12:02:31 2007 [9033] dbg: message: ---- MIME PARSER START ---- Mon Jul 30 12:02:31 2007 [9033] dbg: message: parsing normal part Mon Jul 30 12:02:31 2007 [9033] dbg: message: ---- MIME PARSER END ---- Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::DNSEval=HASH(0x964c478) implements 'check_start', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: bayes: database connection established Mon Jul 30 12:02:31 2007 [9033] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:31 2007 [9033] dbg: bayes: Using userid: 32 Mon Jul 30 12:02:31 2007 [9033] dbg: bayes: not available for scanning, only 2 spam(s) in bayes DB < 200 Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::Check=HASH(0x962460c) implements 'check_main', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: conf: trusted_networks are not configured; it is recommended that you configure trusted_networks manually Mon Jul 30 12:02:31 2007 [9033] dbg: metadata: X-Spam-Relays-Trusted: Mon Jul 30 12:02:31 2007 [9033] dbg: metadata: X-Spam-Relays-Untrusted: Mon Jul 30 12:02:31 2007 [9033] dbg: metadata: X-Spam-Relays-Internal: Mon Jul 30 12:02:31 2007 [9033] dbg: metadata: X-Spam-Relays-External: Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::RelayCountry=HASH(0x8c58464) implements 'extract_metadata', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::TextCat=HASH(0x924a624) implements 'extract_metadata', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: metadata: X-Relay-Countries: Mon Jul 30 12:02:31 2007 [9033] dbg: message: no encoding detected Mon Jul 30 12:02:31 2007 [9033] dbg: textcat: classifying, skipping: yi sco lv is bs sl la ga sa eu et rm cy eo fy gd lt Mon Jul 30 12:02:31 2007 [9033] dbg: textcat: language possibly: en Mon Jul 30 12:02:31 2007 [9033] dbg: textcat: X-Languages: "en", X-Languages-Length: 1342 Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::RelayCountry=HASH(0x8c58464) implements 'parsed_metadata', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH(0x8c540fc) implements 'parsed_metadata', priority 0 Mon Jul 30 12:02:31 2007 [9033] dbg: dns: is_dns_available() last checked 1185789751 seconds ago; re-checking Mon Jul 30 12:02:31 2007 [9033] dbg: dns: testing resolver nameservers: 127.0.0.1 Mon Jul 30 12:02:31 2007 [9033] dbg: dns: trying (3) intel.com... Mon Jul 30 12:02:31 2007 [9033] dbg: dns: looking up NS for 'intel.com' Mon Jul 30 12:02:31 2007 [9033] dbg: dns: NS lookup of intel.com using 127.0.0.1 succeeded => DNS available (set dns_available to override) Mon Jul 30 12:02:31 2007 [9033] dbg: dns: is DNS available? 1 Mon Jul 30 12:02:31 2007 [9033] dbg: uridnsbl: domains to query: Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL sa-accredit.habeas.com., set habeas-firsttrusted Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL sa-other.bondedsender.org., set bsp-untrusted Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL combined.njabl.org., set njabl Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL combined-HIB.dnsiplists.completewhois.com., set whois Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL list.dsbl.org., set dsbl-lastexternal Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL bl.spamcop.net., set spamcop Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL sa-trusted.bondedsender.org., set bsp-firsttrusted Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL combined-HIB.dnsiplists.completewhois.com., set whois-lastexternal Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL zen.spamhaus.org., set zen Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs-lastexternal Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs Mon Jul 30 12:02:31 2007 [9033] dbg: dns: checking RBL iadb.isipp.com., set iadb-firsttrusted Mon Jul 30 12:02:31 2007 [9033] dbg: check: running tests for priority: -1000 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:31 2007 [9033] dbg: eval: all '*From' addrs: ignore@compiling.spamassassin.taint.org Mon Jul 30 12:02:31 2007 [9033] dbg: eval: all '*To' addrs: Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:31 2007 [9033] dbg: check: running tests for priority: -950 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:31 2007 [9033] dbg: check: running tests for priority: -900 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:31 2007 [9033] dbg: check: running tests for priority: -400 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:31 2007 [9033] dbg: check: running tests for priority: 0 Mon Jul 30 12:02:31 2007 [9033] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:32 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran header rule __MSGID_OK_HOST ======> got hit: "@spamassassin_spamd_init>" Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran header rule __MSGID_OK_DIGITS ======> got hit: "1185789751" Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran header rule __HAS_MSGID ======> got hit: "<" Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran header rule __SANE_MSGID ======> got hit: "<1185789751.43294@spamassassin_spamd_init> Mon Jul 30 12:02:32 2007 [9033] dbg: rules: " Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran header rule MISSING_DATE ======> got hit: "UNSET" Mon Jul 30 12:02:32 2007 [9033] dbg: spf: checking to see if the message has a Received-SPF header that we can use Mon Jul 30 12:02:32 2007 [9033] dbg: spf: using Mail::SPF for SPF checks Mon Jul 30 12:02:32 2007 [9033] dbg: spf: no suitable relay for spf use found, skipping SPF-helo check Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: performing public key lookup and signature verification Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: originator address: ignore@compiling.spamassassin.taint.org Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: signature verification result: none Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: whitelist_from_dkim: could not find identity Mon Jul 30 12:02:32 2007 [9033] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks Mon Jul 30 12:02:32 2007 [9033] dbg: spf: no suitable relay for spf use found, skipping SPF check Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran eval rule NO_RELAYS ======> got hit (1) Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: def_whitelist_from_dkim: could not find identity Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: policy: performing lookup Mon Jul 30 12:02:32 2007 [9033] dbg: dkim: policy result neutral: o=~ Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran eval rule DKIM_POLICY_SIGNSOME ======> got hit (1) Mon Jul 30 12:02:32 2007 [9033] dbg: spf: def_spf_whitelist_from: already checked spf and didn't get pass, skipping whitelist check Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran eval rule __UNUSABLE_MSGID ======> got hit (1) Mon Jul 30 12:02:32 2007 [9033] dbg: rules: ran eval rule MISSING_HEADERS ======> got hit (1) Mon Jul 30 12:02:32 2007 [9033] dbg: spf: whitelist_from_spf: already checked spf and didn't get pass, skipping whitelist check Mon Jul 30 12:02:32 2007 [9033] dbg: rules: running body tests; score so far=1.581 Mon Jul 30 12:02:33 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:33 2007 [9033] dbg: rules: ran body rule __NONEMPTY_BODY ======> got hit: "I" Mon Jul 30 12:02:33 2007 [9033] dbg: rules: running uri tests; score so far=1.581 Mon Jul 30 12:02:33 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:33 2007 [9033] dbg: rules: running rawbody tests; score so far=1.581 Mon Jul 30 12:02:33 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:33 2007 [9033] dbg: rules: running full tests; score so far=1.581 Mon Jul 30 12:02:33 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:33 2007 [9033] dbg: info: entering helper-app run mode Mon Jul 30 12:02:35 2007 [9033] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:35 2007 [9033] dbg: razor2: part=0 engine=4 contested=0 confidence=0 Mon Jul 30 12:02:35 2007 [9033] dbg: razor2: results: spam? 0 Mon Jul 30 12:02:35 2007 [9033] dbg: razor2: results: engine 8, highest cf score: 0 Mon Jul 30 12:02:35 2007 [9033] dbg: razor2: results: engine 4, highest cf score: 0 Mon Jul 30 12:02:35 2007 [9033] dbg: util: current PATH is: /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin:/usr/local/bin Mon Jul 30 12:02:35 2007 [9033] dbg: util: executable for pyzor was found at /usr/bin/pyzor Mon Jul 30 12:02:35 2007 [9033] dbg: pyzor: pyzor is available: /usr/bin/pyzor Mon Jul 30 12:02:35 2007 [9033] dbg: info: entering helper-app run mode Mon Jul 30 12:02:35 2007 [9033] dbg: pyzor: opening pipe: /usr/bin/pyzor --homedir /etc/mail/spamassassin/.pyzor check < /tmp/.spamassassin9033YAQYEAtmp Mon Jul 30 12:02:35 2007 [9035] dbg: util: setuid: ruid=0 euid=0 Mon Jul 30 12:02:38 2007 [9033] dbg: pyzor: killed stale helper [9035] Mon Jul 30 12:02:38 2007 [9033] dbg: pyzor: [9035] terminated: exit=0x000f Mon Jul 30 12:02:38 2007 [9033] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:38 2007 [9033] dbg: pyzor: check timed out after 3.5 seconds Mon Jul 30 12:02:38 2007 [9033] dbg: dcc: dccifd is not available: no r/w dccifd socket found Mon Jul 30 12:02:38 2007 [9033] dbg: dcc: dccproc is available: /usr/local/bin/dccproc Mon Jul 30 12:02:38 2007 [9033] dbg: info: entering helper-app run mode Mon Jul 30 12:02:38 2007 [9033] dbg: dcc: opening pipe: /usr/local/bin/dccproc -H -x 0 < /tmp/.spamassassin9033YAQYEAtmp Mon Jul 30 12:02:38 2007 [9036] dbg: util: setuid: ruid=0 euid=0 Mon Jul 30 12:02:40 2007 [9033] dbg: dcc: got response: X-DCC-INFN-TO-Metrics: szpn0002 1233; Body=many Fuz1=many Fuz2=many Mon Jul 30 12:02:40 2007 [9033] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:40 2007 [9033] dbg: dcc: listed: BODY=999999/999999 FUZ1=999999/999999 FUZ2=999999/999999 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: ran eval rule DCC_CHECK ======> got hit (1) Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running meta tests; score so far=2.951 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:40 2007 [9033] dbg: check: running tests for priority: 500 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running head tests; score so far=2.951 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running body tests; score so far=2.951 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running uri tests; score so far=2.951 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running rawbody tests; score so far=2.951 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running full tests; score so far=2.951 Mon Jul 30 12:02:40 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:40 2007 [9033] dbg: rules: running meta tests; score so far=2.951 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:41 2007 [9033] dbg: check: running tests for priority: 1000 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: running head tests; score so far=4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled head tests Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: sql-based connected to DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: sql-based using username: root Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: sql-based get_addr_entry: no entry found for ignore@compiling.spamassassin.taint.org|ip=none Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: sql-based ignore@compiling.spamassassin.taint.org|ip=none scores 0/0 Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: AWL active, pre-score: 4.235, autolearn score: 4.235, mean: undef, IP: undef Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: sql-based finish: disconnected from DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:41 2007 [9033] dbg: auto-whitelist: post auto-whitelist score: 4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: running body tests; score so far=4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled body tests Mon Jul 30 12:02:41 2007 [9033] dbg: rules: running uri tests; score so far=4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled uri tests Mon Jul 30 12:02:41 2007 [9033] dbg: rules: running rawbody tests; score so far=4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled rawbody tests Mon Jul 30 12:02:41 2007 [9033] dbg: rules: running full tests; score so far=4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled full tests Mon Jul 30 12:02:41 2007 [9033] dbg: rules: running meta tests; score so far=4.235 Mon Jul 30 12:02:41 2007 [9033] dbg: rules: compiled meta tests Mon Jul 30 12:02:41 2007 [9033] dbg: check: is spam? score=4.235 required=5 Mon Jul 30 12:02:41 2007 [9033] dbg: check: tests=DCC_CHECK,DKIM_POLICY_SIGNSOME,MISSING_DATE,MISSING_HEADERS,MISSING_SUBJECT,NO_RECEIVED,NO_RELAYS Mon Jul 30 12:02:41 2007 [9033] dbg: check: subtests=__HAS_MSGID,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__NONEMPTY_BODY,__SANE_MSGID,__UNUSABLE_MSGID Mon Jul 30 12:02:41 2007 [9033] dbg: config: copying current conf to backup Mon Jul 30 12:02:41 2007 [9033] info: spamd: server started on port 783/tcp (running version 3.2.3-r559432) Mon Jul 30 12:02:41 2007 [9033] info: spamd: server pid: 9033 Mon Jul 30 12:02:41 2007 [9033] info: spamd: server successfully spawned child process, pid 9038 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9038: entering state 0 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: none Mon Jul 30 12:02:41 2007 [9038] dbg: prefork: sysread(8) not ready, wait max 300 secs Mon Jul 30 12:02:41 2007 [9033] info: spamd: server successfully spawned child process, pid 9039 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9039: entering state 0 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: none Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: no spare children to accept, waiting for one to complete Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9038: entering state 1 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: 9038 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child reports idle Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: overloaded, immediately telling kid to accept Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: ordered 9038 to accept Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9038: entering state 2 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: none Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: no longer overloaded Mon Jul 30 12:02:41 2007 [9033] info: prefork: child states: BS Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: adjust: increasing, not enough idle children (0 < 1) Mon Jul 30 12:02:41 2007 [9040] dbg: prefork: sysread(10) not ready, wait max 300 secs Mon Jul 30 12:02:41 2007 [9033] info: spamd: server successfully spawned child process, pid 9040 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9040: entering state 0 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: none Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9040: entering state 1 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: 9040 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child reports idle Mon Jul 30 12:02:41 2007 [9033] info: prefork: child states: BSI Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child 9039: entering state 1 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: new lowest idle kid: 9039 Mon Jul 30 12:02:41 2007 [9033] dbg: prefork: child reports idle Mon Jul 30 12:02:41 2007 [9033] info: prefork: child states: BII Mon Jul 30 12:02:41 2007 [9039] dbg: prefork: sysread(9) not ready, wait max 300 secs Mon Jul 30 12:02:42 2007 [9038] info: spamd: connection from 192.168.4.6 [192.168.4.6] at port 3177 Mon Jul 30 12:02:42 2007 [9038] warn: spamd: still running as root: user not specified with -u, not found, or set to root, falling back to nobody Mon Jul 30 12:02:42 2007 [9038] dbg: info: user has changed Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: using username: nobody Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: database connection established Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: Using userid: 35 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: not available for scanning, only 115 spam(s) in bayes DB < 200 Mon Jul 30 12:02:42 2007 [9038] dbg: config: score set 1 chosen. Mon Jul 30 12:02:42 2007 [9038] dbg: config: Conf::SQL: executing SQL: SELECT preference, value FROM userpref WHERE username = 'nobody' OR username = '$GLOBAL' OR username = CONCAT('%',NULL) ORDER BY username ASC Mon Jul 30 12:02:42 2007 [9038] dbg: config: retrieving prefs for nobody from SQL server Mon Jul 30 12:02:42 2007 [9038] dbg: info: user has changed Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: using username: nobody Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: database connection established Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: Using userid: 35 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: not available for scanning, only 115 spam(s) in bayes DB < 200 Mon Jul 30 12:02:42 2007 [9038] dbg: config: score set 1 chosen. Mon Jul 30 12:02:42 2007 [9038] dbg: spamd: running as uid 65534 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: name server: 127.0.0.1, LocalAddr: 0.0.0.0 Mon Jul 30 12:02:42 2007 [9038] dbg: message: main message type: text/plain Mon Jul 30 12:02:42 2007 [9038] info: spamd: processing message for (unknown):65534 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: database connection established Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: Using userid: 35 Mon Jul 30 12:02:42 2007 [9038] dbg: bayes: not available for scanning, only 115 spam(s) in bayes DB < 200 Mon Jul 30 12:02:42 2007 [9038] dbg: conf: trusted_networks are not configured; it is recommended that you configure trusted_networks manually Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: parsed as [ ip=199.172.62.20 rdns=europe.std.com helo=europe.std.com by=mail.netnoteinc.com ident= envfrom= intl=0 id=392E1114061 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: do not trust any hosts from here on Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: relay 199.172.62.20 trusted? no internal? no msa? no Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: parsed as [ ip=199.172.62.134 rdns=sgi04-e.std.com helo=sgi04-e.std.com by=europe.std.com ident= envfrom= intl=0 id=RAA08749 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: relay 199.172.62.134 trusted? no internal? no msa? no Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: parsed as [ ip=199.172.62.5 rdns=world-f.std.com helo=world.std.com by=sgi04-e.std.com ident= envfrom= intl=0 id=RAA8278330 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: relay 199.172.62.5 trusted? no internal? no msa? no Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: parsed as [ ip=199.172.62.134 rdns=sgi04-e.std.com helo=sgi04-e.std.com by=europe.std.com ident= envfrom= intl=0 id=RAA07541 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: relay 199.172.62.134 trusted? no internal? no msa? no Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: parsed as [ ip=199.172.62.5 rdns=world-f.std.com helo=world.std.com by=sgi04-e.std.com ident= envfrom= intl=0 id=RAA8416421 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: relay 199.172.62.5 trusted? no internal? no msa? no Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: parsed as [ ip=208.192.102.199 rdns=ppp0c199.std.com helo=!208.192.102.193! by=world.std.com ident= envfrom= intl=0 id=RAA14226 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: received-header: relay 208.192.102.199 trusted? no internal? no msa? no Mon Jul 30 12:02:42 2007 [9038] dbg: metadata: X-Spam-Relays-Trusted: Mon Jul 30 12:02:42 2007 [9038] dbg: metadata: X-Spam-Relays-Untrusted: [ ip=199.172.62.20 rdns=europe.std.com helo=europe.std.com by=mail.netnoteinc.com ident= envfrom= intl=0 id=392E1114061 auth= msa=0 ] [ ip=199.172.62.134 rdns=sgi04-e.std.com helo=sgi04-e.std.com by=europe.std.com ident= envfrom= intl=0 id=RAA08749 auth= msa=0 ] [ ip=199.172.62.5 rdns=world-f.std.com helo=world.std.com by=sgi04-e.std.com ident= envfrom= intl=0 id=RAA8278330 auth= msa=0 ] [ ip=199.172.62.134 rdns=sgi04-e.std.com helo=sgi04-e.std.com by=europe.std.com ident= envfrom= intl=0 id=RAA07541 auth= msa=0 ] [ ip=199.172.62.5 rdns=world-f.std.com helo=world.std.com by=sgi04-e.std.com ident= envfrom= intl=0 id=RAA8416421 auth= msa=0 ] [ ip=208.192.102.199 rdns=ppp0c199.std.com helo=!208.192.102.193! by=world.std.com ident= envfrom= intl=0 id=RAA14226 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: metadata: X-Spam-Relays-Internal: Mon Jul 30 12:02:42 2007 [9038] dbg: metadata: X-Spam-Relays-External: [ ip=199.172.62.20 rdns=europe.std.com helo=europe.std.com by=mail.netnoteinc.com ident= envfrom= intl=0 id=392E1114061 auth= msa=0 ] [ ip=199.172.62.134 rdns=sgi04-e.std.com helo=sgi04-e.std.com by=europe.std.com ident= envfrom= intl=0 id=RAA08749 auth= msa=0 ] [ ip=199.172.62.5 rdns=world-f.std.com helo=world.std.com by=sgi04-e.std.com ident= envfrom= intl=0 id=RAA8278330 auth= msa=0 ] [ ip=199.172.62.134 rdns=sgi04-e.std.com helo=sgi04-e.std.com by=europe.std.com ident= envfrom= intl=0 id=RAA07541 auth= msa=0 ] [ ip=199.172.62.5 rdns=world-f.std.com helo=world.std.com by=sgi04-e.std.com ident= envfrom= intl=0 id=RAA8416421 auth= msa=0 ] [ ip=208.192.102.199 rdns=ppp0c199.std.com helo=!208.192.102.193! by=world.std.com ident= envfrom= intl=0 id=RAA14226 auth= msa=0 ] Mon Jul 30 12:02:42 2007 [9038] dbg: metadata: X-Relay-Countries: US US US US US US Mon Jul 30 12:02:42 2007 [9038] dbg: message: ---- MIME PARSER START ---- Mon Jul 30 12:02:42 2007 [9038] dbg: message: parsing normal part Mon Jul 30 12:02:42 2007 [9038] dbg: message: ---- MIME PARSER END ---- Mon Jul 30 12:02:42 2007 [9038] dbg: message: no encoding detected Mon Jul 30 12:02:42 2007 [9038] dbg: textcat: classifying, skipping: yi sco lv is bs sl la ga sa eu et rm cy fy eo lt gd Mon Jul 30 12:02:42 2007 [9038] dbg: textcat: language possibly: en Mon Jul 30 12:02:42 2007 [9038] dbg: textcat: X-Languages: "en", X-Languages-Length: 4399 Mon Jul 30 12:02:42 2007 [9038] dbg: uridnsbl: domains to query: quicktopic.com sitescooper.org tbtf.com slashdot.org pgp.com userland.com Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_PH_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_BLACK lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_RED lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_GREY lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SC_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_AB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_JP_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_WS_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_OB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_PH_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_BLACK lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_RED lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_GREY lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SC_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_AB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_JP_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_WS_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_OB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_PH_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_BLACK lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_RED lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_GREY lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SC_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_AB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_JP_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_WS_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_OB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_PH_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_BLACK lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_RED lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_GREY lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SC_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_AB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_JP_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_WS_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_OB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_PH_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_BLACK lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_RED lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_GREY lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SC_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_AB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_JP_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_WS_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_OB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_PH_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_BLACK lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_RED lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_GREY lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SC_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_AB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_JP_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_WS_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_OB_SURBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: URIBL_SBL lookup start Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 20.62.172.199.zen.spamhaus.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL sa-accredit.habeas.com., set habeas-firsttrusted Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 20.62.172.199.sa-accredit.habeas.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL sa-other.bondedsender.org., set bsp-untrusted Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.134, 199.172.62.5, 208.192.102.199 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 134.62.172.199.sa-other.bondedsender.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 5.62.172.199.sa-other.bondedsender.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 199.102.192.208.sa-other.bondedsender.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL combined.njabl.org., set njabl Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 208.192.102.199, 199.172.62.5, 199.172.62.134, 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 199.102.192.208.combined.njabl.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 5.62.172.199.combined.njabl.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 134.62.172.199.combined.njabl.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 20.62.172.199.combined.njabl.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL combined-HIB.dnsiplists.completewhois.com., set whois Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 208.192.102.199, 199.172.62.5, 199.172.62.134, 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 199.102.192.208.combined-HIB.dnsiplists.completewhois.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 5.62.172.199.combined-HIB.dnsiplists.completewhois.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 134.62.172.199.combined-HIB.dnsiplists.completewhois.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 20.62.172.199.combined-HIB.dnsiplists.completewhois.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL list.dsbl.org., set dsbl-lastexternal Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 20.62.172.199.list.dsbl.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL bl.spamcop.net., set spamcop Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 208.192.102.199, 199.172.62.5, 199.172.62.134, 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 199.102.192.208.bl.spamcop.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 5.62.172.199.bl.spamcop.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 134.62.172.199.bl.spamcop.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 20.62.172.199.bl.spamcop.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: _check_rbl_addresses RBL blackhole.securitysage.com., set securitysage Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for world.std.com.blackhole.securitysage.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL sa-trusted.bondedsender.org., set bsp-firsttrusted Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS TXT query for 20.62.172.199.sa-trusted.bondedsender.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL combined-HIB.dnsiplists.completewhois.com., set whois-lastexternal Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL zen.spamhaus.org., set zen Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 208.192.102.199, 199.172.62.5, 199.172.62.134, 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 199.102.192.208.zen.spamhaus.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 5.62.172.199.zen.spamhaus.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 134.62.172.199.zen.spamhaus.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: _check_rbl_addresses RBL rhsbl.ahbl.org., set ahbl Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for world.std.com.rhsbl.ahbl.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking A and MX for host world.std.com Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for world.std.com in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS MX query for world.std.com in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: _check_rbl_addresses RBL fulldom.rfc-ignorant.org., set rfci_envfrom Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for world.std.com.fulldom.rfc-ignorant.org. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs-lastexternal Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 20.62.172.199.dnsbl.sorbs.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 208.192.102.199, 199.172.62.5, 199.172.62.134, 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 199.102.192.208.dnsbl.sorbs.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 5.62.172.199.dnsbl.sorbs.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 134.62.172.199.dnsbl.sorbs.net. in background Mon Jul 30 12:02:42 2007 [9038] dbg: dns: checking RBL iadb.isipp.com., set iadb-firsttrusted Mon Jul 30 12:02:42 2007 [9038] dbg: dns: IPs found: full-external: 199.172.62.20, 199.172.62.134, 199.172.62.5, 199.172.62.134, 199.172.62.5, 208.192.102.199 untrusted: 199.172.62.20, 199.172.62.134, 199.172.62.5, 208.192.102.199 originating: Mon Jul 30 12:02:42 2007 [9038] dbg: dns: only inspecting the following IPs: 199.172.62.20 Mon Jul 30 12:02:42 2007 [9038] dbg: dns: launching DNS A query for 20.62.172.199.iadb.isipp.com. in background Mon Jul 30 12:02:42 2007 [9038] dbg: check: running tests for priority: -1000 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: eval: all '*From' addrs: tbtf-approval@world.std.com dawson@world.std.com Mon Jul 30 12:02:42 2007 [9038] dbg: eval: all '*To' addrs: foo@foo.com tbtf@facteur.std.com tbtf@world.std.com Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: check: running tests for priority: -950 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: check: running tests for priority: -900 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:42 2007 [9038] dbg: check: running tests for priority: -400 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: check: running tests for priority: 0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __CT ======> got hit: "t" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __CT_TEXT_PLAIN ======> got hit: "text/plain" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __CTYPE_CHARSET_QUOTED ======> got hit: "charset="" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __MIME_VERSION ======> got hit: "1" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __HAS_RCVD ======> got hit: "f" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __TOCC_EXISTS ======> got hit: "t" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __HAS_MSGID ======> got hit: "<" Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __SANE_MSGID ======> got hit: " Mon Jul 30 12:02:43 2007 [9038] dbg: rules: " Mon Jul 30 12:02:43 2007 [9038] dbg: rules: ran header rule __HAS_SUBJECT ======> got hit: "T" Mon Jul 30 12:02:43 2007 [9038] dbg: spf: checking to see if the message has a Received-SPF header that we can use Mon Jul 30 12:02:43 2007 [9038] dbg: spf: checking HELO (helo=europe.std.com, ip=199.172.62.20) Mon Jul 30 12:02:43 2007 [9038] dbg: dns: hit 127.0.0.3 Mon Jul 30 12:02:43 2007 [9038] dbg: dns: hit 127.0.0.11 Mon Jul 30 12:02:43 2007 [9038] dbg: dns: hit 192.74.137.5 Mon Jul 30 12:02:43 2007 [9038] dbg: dns: hit 10 smtp.theworld.com. Mon Jul 30 12:02:43 2007 [9038] dbg: dns: hit 127.0.0.10 Mon Jul 30 12:02:43 2007 [9038] dbg: spf: query for /199.172.62.20/europe.std.com: result: permerror, comment: , text: Maximum DNS-interactive terms limit (10) exceeded Mon Jul 30 12:02:43 2007 [9038] dbg: dkim: performing public key lookup and signature verification Mon Jul 30 12:02:43 2007 [9038] dbg: dkim: originator address: dawson@world.std.com Mon Jul 30 12:02:43 2007 [9038] dbg: dkim: signature verification result: none Mon Jul 30 12:02:43 2007 [9038] dbg: dkim: whitelist_from_dkim: could not find identity Mon Jul 30 12:02:44 2007 [9038] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks Mon Jul 30 12:02:44 2007 [9038] dbg: spf: checking EnvelopeFrom (helo=europe.std.com, ip=199.172.62.20, envfrom=tbtf-approval@world.std.com) Mon Jul 30 12:02:44 2007 [9038] dbg: spf: query for tbtf-approval@world.std.com/199.172.62.20/europe.std.com: result: permerror, comment: , text: Maximum DNS-interactive terms limit (10) exceeded Mon Jul 30 12:02:44 2007 [9038] dbg: dkim: def_whitelist_from_dkim: could not find identity Mon Jul 30 12:02:44 2007 [9038] dbg: dkim: policy: performing lookup Mon Jul 30 12:02:44 2007 [9038] dbg: dkim: policy result neutral: o=~ Mon Jul 30 12:02:44 2007 [9038] dbg: rules: ran eval rule DKIM_POLICY_SIGNSOME ======> got hit (1) Mon Jul 30 12:02:44 2007 [9038] dbg: spf: def_spf_whitelist_from: already checked spf and didn't get pass, skipping whitelist check Mon Jul 30 12:02:44 2007 [9038] dbg: spf: whitelist_from_spf: already checked spf and didn't get pass, skipping whitelist check Mon Jul 30 12:02:44 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:44 2007 [9038] dbg: rules: ran body rule __NONEMPTY_BODY ======> got hit: "T" Mon Jul 30 12:02:44 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:44 2007 [9038] dbg: rules: relay europe.std.com doesn't match any whitelist Mon Jul 30 12:02:44 2007 [9038] dbg: rules: relay sgi04-e.std.com doesn't match any whitelist Mon Jul 30 12:02:44 2007 [9038] dbg: rules: relay world.std.com doesn't match any whitelist Mon Jul 30 12:02:44 2007 [9038] dbg: rules: relay sgi04-e.std.com doesn't match any whitelist Mon Jul 30 12:02:44 2007 [9038] dbg: rules: relay world.std.com doesn't match any whitelist Mon Jul 30 12:02:44 2007 [9038] dbg: rules: relay [208.192.102.193] doesn't match any whitelist Mon Jul 30 12:02:44 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:44 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:44 2007 [9038] dbg: info: entering helper-app run mode Mon Jul 30 12:02:46 2007 [9038] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:46 2007 [9038] dbg: razor2: part=0 engine=4 contested=0 confidence=0 Mon Jul 30 12:02:46 2007 [9038] dbg: razor2: part=0 engine=8 contested=0 confidence=0 Mon Jul 30 12:02:46 2007 [9038] dbg: razor2: results: spam? 0 Mon Jul 30 12:02:46 2007 [9038] dbg: razor2: results: engine 8, highest cf score: 0 Mon Jul 30 12:02:46 2007 [9038] dbg: razor2: results: engine 4, highest cf score: 0 Mon Jul 30 12:02:46 2007 [9038] dbg: pyzor: pyzor is available: /usr/bin/pyzor Mon Jul 30 12:02:46 2007 [9038] dbg: info: entering helper-app run mode Mon Jul 30 12:02:46 2007 [9038] dbg: pyzor: opening pipe: /usr/bin/pyzor --homedir /etc/mail/spamassassin/.pyzor check < /tmp/.spamassassin9038urQis1tmp Mon Jul 30 12:02:46 2007 [9045] dbg: util: changing real uid from 0 to match effective uid 65534 Mon Jul 30 12:02:46 2007 [9045] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:46 2007 [9045] warn: pyzor: check failed: util: setuid 0 to 65534 failed! at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/Util.pm line 1343. Mon Jul 30 12:02:46 2007 [9045] dbg: dcc: dccifd is not available: no r/w dccifd socket found Mon Jul 30 12:02:46 2007 [9045] dbg: dcc: dccproc is available: /usr/local/bin/dccproc Mon Jul 30 12:02:46 2007 [9045] dbg: info: entering helper-app run mode Mon Jul 30 12:02:46 2007 [9045] dbg: dcc: opening pipe: /usr/local/bin/dccproc -H -x 0 -a 199.172.62.20 < /tmp/.spamassassin9038urQis1tmp Mon Jul 30 12:02:46 2007 [9046] dbg: util: changing real uid from 0 to match effective uid 65534 Mon Jul 30 12:02:46 2007 [9046] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:46 2007 [9046] warn: dcc: check failed: util: setuid 0 to 65534 failed! at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/Util.pm line 1343. Mon Jul 30 12:02:46 2007 [9046] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:46 2007 [9046] dbg: check: running tests for priority: 500 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found no socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for tbtf.com took 5 seconds to look up (multi.uribl.com.:tbtf.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for quicktopic.com took 5 seconds to look up (multi.uribl.com.:quicktopic.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (multi.uribl.com.:slashdot.org) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (multi.surbl.org.:slashdot.org) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for userland.com took 5 seconds to look up (multi.surbl.org.:userland.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for tbtf.com took 5 seconds to look up (multi.surbl.org.:tbtf.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for quicktopic.com took 5 seconds to look up (multi.surbl.org.:quicktopic.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for sitescooper.org took 5 seconds to look up (multi.uribl.com.:sitescooper.org) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for sitescooper.org took 5 seconds to look up (multi.surbl.org.:sitescooper.org) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for pgp.com took 5 seconds to look up (multi.surbl.org.:pgp.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for userland.com took 5 seconds to look up (multi.uribl.com.:userland.com) Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for pgp.com took 5 seconds to look up (multi.uribl.com.:pgp.com) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 50 started: 18 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=17 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=16 URI-DNSBL=1 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=15 URI-DNSBL=2 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=14 URI-DNSBL=3 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=13 URI-DNSBL=4 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=12 URI-DNSBL=4 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=11 URI-DNSBL=5 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=10 URI-DNSBL=6 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=9 URI-DNSBL=7 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=8 URI-DNSBL=8 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=7 URI-DNSBL=9 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=6 URI-DNSBL=10 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=5 URI-DNSBL=11 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=4 URI-DNSBL=12 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=3 URI-DNSBL=13 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=2 URI-DNSBL=14 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-A=1 URI-DNSBL=15 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for tbtf.com took 5 seconds to look up (sbl.spamhaus.org.:134.6.96.208) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for tbtf.com took 5 seconds to look up (sbl.spamhaus.org.:3.219.158.64) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=15 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for tbtf.com took 5 seconds to look up (sbl.spamhaus.org.:56.56.76.208) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=14 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for tbtf.com took 5 seconds to look up (sbl.spamhaus.org.:150.184.152.204) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=13 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for sitescooper.org took 5 seconds to look up (sbl.spamhaus.org.:78.141.169.80) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=12 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for userland.com took 5 seconds to look up (sbl.spamhaus.org.:50.113.84.70) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=11 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for userland.com took 5 seconds to look up (sbl.spamhaus.org.:154.61.19.67) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=10 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for pgp.com took 5 seconds to look up (sbl.spamhaus.org.:43.226.237.209) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=9 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for pgp.com took 5 seconds to look up (sbl.spamhaus.org.:3.255.251.63) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=8 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for pgp.com took 5 seconds to look up (sbl.spamhaus.org.:4.255.251.63) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=7 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (sbl.spamhaus.org.:12.250.35.66) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=6 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (sbl.spamhaus.org.:10.250.35.66) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=5 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (sbl.spamhaus.org.:135.184.152.12) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=4 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (sbl.spamhaus.org.:11.250.35.66) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=3 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for slashdot.org took 5 seconds to look up (sbl.spamhaus.org.:136.184.152.12) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=2 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for quicktopic.com took 5 seconds to look up (sbl.spamhaus.org.:239.2.68.209) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: URI-DNSBL=1 at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: async: select found 1 socks ready Mon Jul 30 12:02:47 2007 [9046] dbg: uridnsbl: query for quicktopic.com took 5 seconds to look up (sbl.spamhaus.org.:2.61.92.216) Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: async: queries active: at Mon Jul 30 12:02:47 2007 Mon Jul 30 12:02:47 2007 [9046] dbg: dns: success for 49 of 50 queries Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: check: running tests for priority: 1000 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: sql-based connected to DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: sql-based using username: nobody Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: sql-based get_addr_entry: found existing entry for dawson@world.std.com|ip=208.192 Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: sql-based dawson@world.std.com|ip=208.192 scores 42/0 Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: AWL active, pre-score: 0, autolearn score: 0, mean: undef, IP: 208.192.102.199 Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: sql-based add_score: new count: 43, new totscore: 0 for dawson@world.std.com|ip=208.192 Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: sql-based finish: disconnected from DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:47 2007 [9046] dbg: auto-whitelist: post auto-whitelist score: 0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:47 2007 [9046] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:48 2007 [9046] dbg: plugin: Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x9230dc8) implements 'autolearn_discriminator', priority 0 Mon Jul 30 12:02:48 2007 [9046] dbg: learn: auto-learn: currently using scoreset 1 Mon Jul 30 12:02:48 2007 [9046] dbg: learn: auto-learn: message score: 0, computed score for autolearn: 0 Mon Jul 30 12:02:48 2007 [9046] dbg: learn: auto-learn? ham=0.1, spam=12, body-points=0, head-points=0, learned-points=0 Mon Jul 30 12:02:48 2007 [9046] dbg: learn: auto-learn? yes, ham (0 < 0.1) Mon Jul 30 12:02:48 2007 [9046] dbg: learn: initializing learner Mon Jul 30 12:02:48 2007 [9046] dbg: dns: name server: 127.0.0.1, LocalAddr: 0.0.0.0 Mon Jul 30 12:02:48 2007 [9046] dbg: learn: learning ham Mon Jul 30 12:02:48 2007 [9046] dbg: plugin: Mail::SpamAssassin::Plugin::WLBLEval=HASH(0x96c3f9c) implements 'check_wb_list', priority 0 Mon Jul 30 12:02:48 2007 [9046] dbg: eval: all '*From' addrs: tbtf-approval@world.std.com dawson@world.std.com Mon Jul 30 12:02:48 2007 [9046] dbg: eval: all '*To' addrs: foo@foo.com tbtf@facteur.std.com tbtf@world.std.com Mon Jul 30 12:02:48 2007 [9046] dbg: bayes: database connection established Mon Jul 30 12:02:48 2007 [9046] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:48 2007 [9046] dbg: bayes: Using userid: 35 Mon Jul 30 12:02:48 2007 [9046] dbg: bayes: a1381889b89a4970ed596e4c6b4f0ce310276bb0@sa_generated already learnt correctly, not learning twice Mon Jul 30 12:02:48 2007 [9046] dbg: learn: initializing learner Mon Jul 30 12:02:48 2007 [9046] dbg: check: is spam? score=0 required=5 Mon Jul 30 12:02:48 2007 [9046] dbg: check: tests=DKIM_POLICY_SIGNSOME Mon Jul 30 12:02:48 2007 [9046] dbg: check: subtests=__CT,__CTYPE_CHARSET_QUOTED,__CT_TEXT_PLAIN,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__MIME_VERSION,__NONEMPTY_BODY,__RCVD_IN_NJABL,__RCVD_IN_SORBS,__RCVD_IN_ZEN,__SANE_MSGID,__TOCC_EXISTS Mon Jul 30 12:02:48 2007 [9046] info: spamd: clean message (0.0/5.0) for (unknown):65534 in 6.3 seconds, 6494 bytes. Mon Jul 30 12:02:48 2007 [9046] info: spamd: result: . 0 - DKIM_POLICY_SIGNSOME scantime=6.3,size=6494,user=(unknown),uid=65534,required_score=5.0,rhost=192.168.4.6,raddr=192.168.4.6,rport=3177,mid=,autolearn=unavailable Mon Jul 30 12:02:48 2007 [9046] warn: spamd: accidental fork: 9046 != 9038 at /usr/local/bin/spamd line 1628. Mon Jul 30 12:02:48 2007 [9045] dbg: dcc: [9046] finished: exit=0x0100 Mon Jul 30 12:02:48 2007 [9045] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:48 2007 [9045] warn: dcc: check failed: failed to read header Mon Jul 30 12:02:48 2007 [9045] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:48 2007 [9045] dbg: check: running tests for priority: 500 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for tbtf.com took 7 seconds to look up (multi.uribl.com.:tbtf.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for quicktopic.com took 7 seconds to look up (multi.uribl.com.:quicktopic.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for slashdot.org took 7 seconds to look up (multi.uribl.com.:slashdot.org) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for slashdot.org took 7 seconds to look up (multi.surbl.org.:slashdot.org) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for userland.com took 7 seconds to look up (multi.surbl.org.:userland.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for tbtf.com took 7 seconds to look up (multi.surbl.org.:tbtf.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for quicktopic.com took 7 seconds to look up (multi.surbl.org.:quicktopic.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for sitescooper.org took 7 seconds to look up (multi.uribl.com.:sitescooper.org) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for sitescooper.org took 7 seconds to look up (multi.surbl.org.:sitescooper.org) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for pgp.com took 7 seconds to look up (multi.surbl.org.:pgp.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for userland.com took 7 seconds to look up (multi.uribl.com.:userland.com) Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for pgp.com took 7 seconds to look up (multi.uribl.com.:pgp.com) Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 50 started: 18 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=17 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=16 URI-DNSBL=1 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=15 URI-DNSBL=2 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=14 URI-DNSBL=3 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=13 URI-DNSBL=4 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=12 URI-DNSBL=4 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=11 URI-DNSBL=5 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=10 URI-DNSBL=6 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=9 URI-DNSBL=7 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=8 URI-DNSBL=8 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=7 URI-DNSBL=9 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=6 URI-DNSBL=10 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=5 URI-DNSBL=11 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=4 URI-DNSBL=12 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=3 URI-DNSBL=13 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=2 URI-DNSBL=14 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-A=1 URI-DNSBL=15 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9045] dbg: uridnsbl: query for tbtf.com took 7 seconds to look up (sbl.spamhaus.org.:134.6.96.208) Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:49 2007 [9045] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9045] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9038] dbg: pyzor: killed stale helper [9045] Mon Jul 30 12:02:49 2007 [9038] dbg: pyzor: [9045] terminated: exit=0x000f Mon Jul 30 12:02:49 2007 [9038] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:49 2007 [9038] dbg: pyzor: check timed out after 3.5 seconds Mon Jul 30 12:02:49 2007 [9038] dbg: dcc: dccifd is not available: no r/w dccifd socket found Mon Jul 30 12:02:49 2007 [9038] dbg: dcc: dccproc is available: /usr/local/bin/dccproc Mon Jul 30 12:02:49 2007 [9038] dbg: info: entering helper-app run mode Mon Jul 30 12:02:49 2007 [9038] dbg: dcc: opening pipe: /usr/local/bin/dccproc -H -x 0 -a 199.172.62.20 < /tmp/.spamassassin9038urQis1tmp Mon Jul 30 12:02:49 2007 [9049] dbg: util: changing real uid from 0 to match effective uid 65534 Mon Jul 30 12:02:49 2007 [9049] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:49 2007 [9049] warn: dcc: check failed: util: setuid 0 to 65534 failed! at /usr/local/share/perl/5.8.4/Mail/SpamAssassin/Util.pm line 1343. Mon Jul 30 12:02:49 2007 [9049] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:49 2007 [9049] dbg: check: running tests for priority: 500 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 52504/56.56.76.208.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 52504 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 56.56.76.208.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for tbtf.com took 7 seconds to look up (multi.uribl.com.:tbtf.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for quicktopic.com took 7 seconds to look up (multi.uribl.com.:quicktopic.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for slashdot.org took 7 seconds to look up (multi.uribl.com.:slashdot.org) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for slashdot.org took 7 seconds to look up (multi.surbl.org.:slashdot.org) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for userland.com took 7 seconds to look up (multi.surbl.org.:userland.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for tbtf.com took 7 seconds to look up (multi.surbl.org.:tbtf.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for quicktopic.com took 7 seconds to look up (multi.surbl.org.:quicktopic.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for sitescooper.org took 7 seconds to look up (multi.uribl.com.:sitescooper.org) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for sitescooper.org took 7 seconds to look up (multi.surbl.org.:sitescooper.org) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for pgp.com took 7 seconds to look up (multi.surbl.org.:pgp.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for userland.com took 7 seconds to look up (multi.uribl.com.:userland.com) Mon Jul 30 12:02:49 2007 [9049] dbg: uridnsbl: query for pgp.com took 7 seconds to look up (multi.uribl.com.:pgp.com) Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 50 started: 18 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 32529/150.184.152.204.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 32529 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 150.184.152.204.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 1451/78.141.169.80.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 1451 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 78.141.169.80.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 24439/50.113.84.70.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 24439 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 50.113.84.70.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 3691/154.61.19.67.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 3691 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 154.61.19.67.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 29361/43.226.237.209.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 29361 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 43.226.237.209.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 23552/3.255.251.63.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 23552 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 3.255.251.63.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 63774/4.255.251.63.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 63774 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 4.255.251.63.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 20117/12.250.35.66.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 20117 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 12.250.35.66.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 55479/10.250.35.66.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 55479 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 10.250.35.66.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 44740/135.184.152.12.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 44740 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 135.184.152.12.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 16779/11.250.35.66.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 16779 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 11.250.35.66.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 23093/136.184.152.12.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 23093 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 136.184.152.12.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 35112/239.2.68.209.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 35112 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 239.2.68.209.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: no callback for id: 38482/2.61.92.216.sbl.spamhaus.org/TXT/IN, ignored; packet: ;; HEADER SECTION Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; id = 38482 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ra = 1 ad = 0 cd = 0 rcode = NXDOMAIN Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; qdcount = 1 ancount = 0 nscount = 1 arcount = 0 Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; QUESTION SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; 2.61.92.216.sbl.spamhaus.org. IN TXT Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ANSWER SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; AUTHORITY SECTION (1 record) Mon Jul 30 12:02:49 2007 [9049] dbg: dns: sbl.spamhaus.org. 482 IN SOA need.to.know.only. hostmaster.spamhaus.org. ( Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 2007073039 ; Serial Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 3600 ; Refresh Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 600 ; Retry Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 432000 ; Expire Mon Jul 30 12:02:49 2007 [9049] dbg: dns: 900 ) ; Minimum TTL Mon Jul 30 12:02:49 2007 [9049] dbg: dns: Mon Jul 30 12:02:49 2007 [9049] dbg: dns: ;; ADDITIONAL SECTION (0 records) Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found no socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 0 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=18 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=17 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=16 URI-DNSBL=1 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=15 URI-DNSBL=2 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=14 URI-DNSBL=3 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=13 URI-DNSBL=4 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=12 URI-DNSBL=4 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=11 URI-DNSBL=5 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=10 URI-DNSBL=6 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=9 URI-DNSBL=7 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=8 URI-DNSBL=8 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=7 URI-DNSBL=9 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=6 URI-DNSBL=10 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=5 URI-DNSBL=11 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=4 URI-DNSBL=12 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=3 URI-DNSBL=13 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=2 URI-DNSBL=14 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-A=1 URI-DNSBL=15 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:49 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:49 2007 [9049] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:49 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for tbtf.com took 8 seconds to look up (sbl.spamhaus.org.:134.6.96.208) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for tbtf.com took 8 seconds to look up (sbl.spamhaus.org.:3.219.158.64) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=15 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for tbtf.com took 8 seconds to look up (sbl.spamhaus.org.:56.56.76.208) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=14 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for tbtf.com took 8 seconds to look up (sbl.spamhaus.org.:150.184.152.204) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=13 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for sitescooper.org took 8 seconds to look up (sbl.spamhaus.org.:78.141.169.80) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=12 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for userland.com took 8 seconds to look up (sbl.spamhaus.org.:50.113.84.70) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=11 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for userland.com took 8 seconds to look up (sbl.spamhaus.org.:154.61.19.67) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=10 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for pgp.com took 8 seconds to look up (sbl.spamhaus.org.:43.226.237.209) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=9 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for pgp.com took 8 seconds to look up (sbl.spamhaus.org.:3.255.251.63) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=8 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for pgp.com took 8 seconds to look up (sbl.spamhaus.org.:4.255.251.63) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=7 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for slashdot.org took 8 seconds to look up (sbl.spamhaus.org.:12.250.35.66) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=6 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for slashdot.org took 8 seconds to look up (sbl.spamhaus.org.:10.250.35.66) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=5 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for slashdot.org took 8 seconds to look up (sbl.spamhaus.org.:135.184.152.12) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=4 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for slashdot.org took 8 seconds to look up (sbl.spamhaus.org.:11.250.35.66) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=3 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for slashdot.org took 8 seconds to look up (sbl.spamhaus.org.:136.184.152.12) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=2 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for quicktopic.com took 8 seconds to look up (sbl.spamhaus.org.:239.2.68.209) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: URI-DNSBL=1 at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: async: select found 1 socks ready Mon Jul 30 12:02:50 2007 [9049] dbg: uridnsbl: query for quicktopic.com took 8 seconds to look up (sbl.spamhaus.org.:2.61.92.216) Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: async: queries active: at Mon Jul 30 12:02:50 2007 Mon Jul 30 12:02:50 2007 [9049] dbg: dns: success for 49 of 50 queries Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: check: running tests for priority: 1000 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: sql-based connected to DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: sql-based using username: nobody Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: sql-based get_addr_entry: found existing entry for dawson@world.std.com|ip=208.192 Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: sql-based dawson@world.std.com|ip=208.192 scores 43/0 Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: AWL active, pre-score: 0, autolearn score: 0, mean: undef, IP: 208.192.102.199 Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: sql-based add_score: new count: 44, new totscore: 0 for dawson@world.std.com|ip=208.192 Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: sql-based finish: disconnected from DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:50 2007 [9049] dbg: auto-whitelist: post auto-whitelist score: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:50 2007 [9049] dbg: plugin: Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x9230dc8) implements 'autolearn_discriminator', priority 0 Mon Jul 30 12:02:50 2007 [9049] dbg: learn: auto-learn: currently using scoreset 1 Mon Jul 30 12:02:50 2007 [9049] dbg: learn: auto-learn: message score: 0, computed score for autolearn: 0 Mon Jul 30 12:02:50 2007 [9049] dbg: learn: auto-learn? ham=0.1, spam=12, body-points=0, head-points=0, learned-points=0 Mon Jul 30 12:02:50 2007 [9049] dbg: learn: auto-learn? yes, ham (0 < 0.1) Mon Jul 30 12:02:50 2007 [9049] dbg: learn: initializing learner Mon Jul 30 12:02:50 2007 [9049] dbg: dns: name server: 127.0.0.1, LocalAddr: 0.0.0.0 Mon Jul 30 12:02:50 2007 [9049] dbg: learn: learning ham Mon Jul 30 12:02:50 2007 [9049] dbg: plugin: Mail::SpamAssassin::Plugin::WLBLEval=HASH(0x96c3f9c) implements 'check_wb_list', priority 0 Mon Jul 30 12:02:50 2007 [9049] dbg: eval: all '*From' addrs: tbtf-approval@world.std.com dawson@world.std.com Mon Jul 30 12:02:50 2007 [9049] dbg: eval: all '*To' addrs: foo@foo.com tbtf@facteur.std.com tbtf@world.std.com Mon Jul 30 12:02:50 2007 [9049] dbg: bayes: database connection established Mon Jul 30 12:02:50 2007 [9049] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:50 2007 [9049] dbg: bayes: Using userid: 35 Mon Jul 30 12:02:50 2007 [9049] dbg: bayes: a1381889b89a4970ed596e4c6b4f0ce310276bb0@sa_generated already learnt correctly, not learning twice Mon Jul 30 12:02:50 2007 [9049] dbg: learn: initializing learner Mon Jul 30 12:02:50 2007 [9049] dbg: check: is spam? score=0 required=5 Mon Jul 30 12:02:50 2007 [9049] dbg: check: tests=DKIM_POLICY_SIGNSOME Mon Jul 30 12:02:50 2007 [9049] dbg: check: subtests=__CT,__CTYPE_CHARSET_QUOTED,__CT_TEXT_PLAIN,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__MIME_VERSION,__NONEMPTY_BODY,__RCVD_IN_NJABL,__RCVD_IN_SORBS,__RCVD_IN_ZEN,__SANE_MSGID,__TOCC_EXISTS Mon Jul 30 12:02:50 2007 [9049] info: spamd: clean message (0.0/5.0) for (unknown):65534 in 8.4 seconds, 6494 bytes. Mon Jul 30 12:02:50 2007 [9049] info: spamd: result: . 0 - DKIM_POLICY_SIGNSOME scantime=8.4,size=6494,user=(unknown),uid=65534,required_score=5.0,rhost=192.168.4.6,raddr=192.168.4.6,rport=3177,mid=,autolearn=unavailable Mon Jul 30 12:02:50 2007 [9049] warn: spamd: accidental fork: 9049 != 9038 at /usr/local/bin/spamd line 1628. Mon Jul 30 12:02:50 2007 [9038] dbg: dcc: [9049] finished: exit=0x0100 Mon Jul 30 12:02:50 2007 [9038] dbg: info: leaving helper-app run mode Mon Jul 30 12:02:50 2007 [9038] warn: dcc: check failed: failed to read header Mon Jul 30 12:02:50 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:50 2007 [9038] dbg: check: running tests for priority: 500 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found no socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for tbtf.com took 9 seconds to look up (multi.uribl.com.:tbtf.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for quicktopic.com took 9 seconds to look up (multi.uribl.com.:quicktopic.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (multi.uribl.com.:slashdot.org) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (multi.surbl.org.:slashdot.org) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for userland.com took 9 seconds to look up (multi.surbl.org.:userland.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for tbtf.com took 9 seconds to look up (multi.surbl.org.:tbtf.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for quicktopic.com took 9 seconds to look up (multi.surbl.org.:quicktopic.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for sitescooper.org took 9 seconds to look up (multi.uribl.com.:sitescooper.org) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for sitescooper.org took 9 seconds to look up (multi.surbl.org.:sitescooper.org) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for pgp.com took 9 seconds to look up (multi.surbl.org.:pgp.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for userland.com took 9 seconds to look up (multi.uribl.com.:userland.com) Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for pgp.com took 9 seconds to look up (multi.uribl.com.:pgp.com) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 50 started: 18 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=17 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=16 URI-DNSBL=1 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=15 URI-DNSBL=2 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=14 URI-DNSBL=3 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=13 URI-DNSBL=4 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=12 URI-DNSBL=4 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=11 URI-DNSBL=5 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=10 URI-DNSBL=6 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=9 URI-DNSBL=7 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=8 URI-DNSBL=8 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=7 URI-DNSBL=9 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=6 URI-DNSBL=10 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=5 URI-DNSBL=11 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=4 URI-DNSBL=12 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=3 URI-DNSBL=13 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=2 URI-DNSBL=14 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-A=1 URI-DNSBL=15 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 1 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for tbtf.com took 9 seconds to look up (sbl.spamhaus.org.:134.6.96.208) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=16 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for tbtf.com took 9 seconds to look up (sbl.spamhaus.org.:3.219.158.64) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=15 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for tbtf.com took 9 seconds to look up (sbl.spamhaus.org.:56.56.76.208) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=14 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for tbtf.com took 9 seconds to look up (sbl.spamhaus.org.:150.184.152.204) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=13 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for sitescooper.org took 9 seconds to look up (sbl.spamhaus.org.:78.141.169.80) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=12 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for userland.com took 9 seconds to look up (sbl.spamhaus.org.:50.113.84.70) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=11 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for userland.com took 9 seconds to look up (sbl.spamhaus.org.:154.61.19.67) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=10 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for pgp.com took 9 seconds to look up (sbl.spamhaus.org.:43.226.237.209) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=9 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for pgp.com took 9 seconds to look up (sbl.spamhaus.org.:3.255.251.63) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=8 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for pgp.com took 9 seconds to look up (sbl.spamhaus.org.:4.255.251.63) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=7 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (sbl.spamhaus.org.:12.250.35.66) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=6 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (sbl.spamhaus.org.:10.250.35.66) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=5 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (sbl.spamhaus.org.:135.184.152.12) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=4 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (sbl.spamhaus.org.:11.250.35.66) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=3 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for slashdot.org took 9 seconds to look up (sbl.spamhaus.org.:136.184.152.12) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=2 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for quicktopic.com took 9 seconds to look up (sbl.spamhaus.org.:239.2.68.209) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: URI-DNSBL=1 at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: async: select found 1 socks ready Mon Jul 30 12:02:51 2007 [9038] dbg: uridnsbl: query for quicktopic.com took 9 seconds to look up (sbl.spamhaus.org.:2.61.92.216) Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries completed: 1 started: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: async: queries active: at Mon Jul 30 12:02:51 2007 Mon Jul 30 12:02:51 2007 [9038] dbg: dns: success for 49 of 50 queries Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: check: running tests for priority: 1000 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running head tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: sql-based connected to DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: sql-based using username: nobody Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: sql-based get_addr_entry: found existing entry for dawson@world.std.com|ip=208.192 Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: sql-based dawson@world.std.com|ip=208.192 scores 44/0 Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: AWL active, pre-score: 0, autolearn score: 0, mean: undef, IP: 208.192.102.199 Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: sql-based add_score: new count: 45, new totscore: 0 for dawson@world.std.com|ip=208.192 Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: sql-based finish: disconnected from DBI:mysql:SpamAssassin:localhost Mon Jul 30 12:02:51 2007 [9038] dbg: auto-whitelist: post auto-whitelist score: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running body tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running uri tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running rawbody tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running full tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: rules: running meta tests; score so far=0 Mon Jul 30 12:02:51 2007 [9038] dbg: plugin: Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x9230dc8) implements 'autolearn_discriminator', priority 0 Mon Jul 30 12:02:51 2007 [9038] dbg: learn: auto-learn: currently using scoreset 1 Mon Jul 30 12:02:51 2007 [9038] dbg: learn: auto-learn: message score: 0, computed score for autolearn: 0 Mon Jul 30 12:02:51 2007 [9038] dbg: learn: auto-learn? ham=0.1, spam=12, body-points=0, head-points=0, learned-points=0 Mon Jul 30 12:02:51 2007 [9038] dbg: learn: auto-learn? yes, ham (0 < 0.1) Mon Jul 30 12:02:51 2007 [9038] dbg: learn: initializing learner Mon Jul 30 12:02:51 2007 [9038] dbg: learn: learning ham Mon Jul 30 12:02:51 2007 [9038] dbg: plugin: Mail::SpamAssassin::Plugin::WLBLEval=HASH(0x96c3f9c) implements 'check_wb_list', priority 0 Mon Jul 30 12:02:51 2007 [9038] dbg: eval: all '*From' addrs: tbtf-approval@world.std.com dawson@world.std.com Mon Jul 30 12:02:51 2007 [9038] dbg: eval: all '*To' addrs: foo@foo.com tbtf@facteur.std.com tbtf@world.std.com Mon Jul 30 12:02:51 2007 [9038] dbg: bayes: database connection established Mon Jul 30 12:02:51 2007 [9038] dbg: bayes: found bayes db version 3 Mon Jul 30 12:02:51 2007 [9038] dbg: bayes: Using userid: 35 Mon Jul 30 12:02:51 2007 [9038] dbg: bayes: a1381889b89a4970ed596e4c6b4f0ce310276bb0@sa_generated already learnt correctly, not learning twice Mon Jul 30 12:02:51 2007 [9038] dbg: learn: initializing learner Mon Jul 30 12:02:51 2007 [9038] dbg: check: is spam? score=0 required=5 Mon Jul 30 12:02:51 2007 [9038] dbg: check: tests=DKIM_POLICY_SIGNSOME Mon Jul 30 12:02:51 2007 [9038] dbg: check: subtests=__CT,__CTYPE_CHARSET_QUOTED,__CT_TEXT_PLAIN,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__MIME_VERSION,__NONEMPTY_BODY,__RCVD_IN_NJABL,__RCVD_IN_SORBS,__RCVD_IN_ZEN,__SANE_MSGID,__TOCC_EXISTS Mon Jul 30 12:02:51 2007 [9038] info: spamd: clean message (0.0/5.0) for (unknown):65534 in 10.0 seconds, 6494 bytes. Mon Jul 30 12:02:51 2007 [9038] info: spamd: result: . 0 - DKIM_POLICY_SIGNSOME scantime=10.0,size=6494,user=(unknown),uid=65534,required_score=5.0,rhost=192.168.4.6,raddr=192.168.4.6,rport=3177,mid=,autolearn=unavailable Mon Jul 30 12:02:51 2007 [9038] dbg: config: copying current conf from backup Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: child 9038: entering state 1 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: new lowest idle kid: 9038 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: child reports idle Mon Jul 30 12:02:52 2007 [9033] info: prefork: child states: III Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: child 9040: entering state 3 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: new lowest idle kid: 9038 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: adjust: decreasing, too many idle children (3 > 2), killed 9040 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: child closed connection Mon Jul 30 12:02:52 2007 [9033] info: prefork: child states: IIK Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: child 9040: just exited Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: child 9040: entering state 4 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: new lowest idle kid: 9038 Mon Jul 30 12:02:52 2007 [9033] info: spamd: handled cleanup of child pid 9040 due to SIGCHLD Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: new lowest idle kid: 9038 Mon Jul 30 12:02:52 2007 [9033] dbg: prefork: select returned -1 due to child exiting, ignored () Mon Jul 30 12:02:52 2007 [9038] dbg: prefork: sysread(8) not ready, wait max 300 secs