Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: logging initialized, log level 5, syslog: amavis.mail Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: starting. /usr/sbin/amavisd at strike.wu-wien.ac.at amavisd-new-2.5.2 (20070627), Unicode aware, LANG="en_US" Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: user=, EUID: 0 (0); group=, EGID: 0 0 1 2 3 4 6 10 (0 0 1 2 3 4 6 10) Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Perl version 5.010000 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: INFO: no optional modules: Mail/DomainKeys/Header.pm Mail/DomainKeys/Key.pm Mail/DomainKeys/Key/Public.pm Mail/DomainKeys/Message.pm Mail/DomainKeys/Policy.pm Mail/DomainKeys/Signature.pm Mail/SpamAssassin/Plugin/DomainKeys.pm Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: INFO: SA version: 3.2.5, 3.002005, no optional modules: Sys::Hostname::Long Mail::SpamAssassin::BayesStore::PgSQL IP::Country::Fast Mail::SPF::Query Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SpamControl: init_pre_chroot done Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: LEO: setrlimit: 1 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: 2009/06/01-18:31:21 Amavis (type Net::Server::PreFork) starting! pid(30954) Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Binding to UNIX socket file /var/spool/amavisd/amavisd.sock using SOCK_STREAM Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Binding to TCP port 10024 on host * Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Binding to TCP port 10026 on host * Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Setting gid to "486 486" Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Setting uid to "491" Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Setting up serialization via flock Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: after_chroot_init: EUID: 491 (491); EGID: 486 486 486 (486 486 486) Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: config files read: /etc/amavisd/amavisd.conf Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Amavis::Conf 2.091 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Archive::Zip 1.23 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Compress::Zlib 2.008 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Convert::TNEF 0.17 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Convert::UUlib 1.11 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module DBD::mysql 4.005 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module DBI 1.607 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module DB_File 1.816_1 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Digest::MD5 2.36_01 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Digest::SHA 5.45 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Digest::SHA1 2.11 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module IO::Socket::INET6 2.54 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module MIME::Entity 5.427 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module MIME::Parser 5.427 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module MIME::Tools 5.427 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Mail::DKIM 0.32 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Mail::Header 2.04 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Mail::Internet 2.04 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Mail::SPF v2.005 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Mail::SpamAssassin 3.002005 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Net::DNS 0.63 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Net::Server 0.97 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module NetAddr::IP 4.007 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Razor2::Client::Version 2.84 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Time::HiRes 1.9711 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module URI 1.35 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Module Unix::Syslog 1.1 Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Amavis::DB code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Amavis::Cache code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SQL base code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SQL::Log code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SQL::Quarantine NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Lookup::SQL code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Lookup::LDAP code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: AM.PDP-in proto code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SMTP-in proto code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Courier proto code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SMTP-out proto code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Pipe-out proto code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: BSMTP-out proto code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Local-out proto code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: OS_Fingerprint code NOT loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: ANTI-VIRUS code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: ANTI-SPAM code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: ANTI-SPAM-SA code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Unpackers code loaded Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found $file at /usr/bin/file Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: No $dspam, not using it Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found $altermime at /usr/bin/altermime Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .mail Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .asc Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .uue Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .hqx Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .ync Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .F at /usr/bin/unfreeze Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .Z at /usr/bin/gzip -d Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .gz at /usr/bin/gzip -d Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .gz (backup, not used) Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .bz2 at /usr/bin/bzip2 -d Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .lzo at /usr/bin/lzop -d Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .rpm at /usr/bin/rpm2cpio Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .cpio at /usr/bin/pax Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .tar at /usr/bin/pax Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .deb at /usr/bin/ar Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .zip Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .7z at /usr/bin/7za Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .rar at /usr/bin/rar Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .arj at /usr/bin/arj Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .arc at /usr/bin/nomarch Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: No decoder for .zoo tried: zoo, unzoo Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .lha at /usr/bin/lha Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .cab at /usr/bin/cabextract Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: No decoder for .tnef tried: tnef Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Internal decoder for .tnef Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Found decoder for .exe at /usr/bin/rar; /usr/bin/lha; /usr/bin/arj Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Using primary internal av scanner code for AVG Anti-Virus Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Using secondary internal av scanner code for always-clean Jun 1 18:31:21 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SpamControl: initializing Mail::SpamAssassin [30954] dbg: logger: adding facilities: all [30954] dbg: logger: logging level is DBG [30954] dbg: generic: SpamAssassin version 3.2.5 [30954] dbg: config: score set 0 chosen. [30954] dbg: util: running in taint mode? yes [30954] dbg: util: taint mode: deleting unsafe environment variables, resetting PATH [30954] dbg: util: PATH included '/usr/local/sbin', keeping [30954] dbg: util: PATH included '/usr/local/bin', keeping [30954] dbg: util: PATH included '/usr/sbin', keeping [30954] dbg: util: PATH included '/sbin', keeping [30954] dbg: util: PATH included '/usr/bin', keeping [30954] dbg: util: PATH included '/bin', keeping [30954] dbg: util: final PATH set to: /usr/local/sbin:/usr/local/bin:/usr/sbin:/sbin:/usr/bin:/bin [30954] dbg: dns: is Net::DNS::Resolver available? yes [30954] dbg: dns: Net::DNS version: 0.63 [30954] dbg: ignore: test message to precompile patterns and load modules [30954] dbg: config: using "/etc/mail/spamassassin" for site rules pre files [30954] dbg: config: read file /etc/mail/spamassassin/init.pre [30954] dbg: config: read file /etc/mail/spamassassin/v310.pre [30954] dbg: config: read file /etc/mail/spamassassin/v312.pre [30954] dbg: config: read file /etc/mail/spamassassin/v320.pre [30954] dbg: config: using "/var/lib/spamassassin/3.002005" for sys rules pre files [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com.pre [30954] dbg: config: using "/var/lib/spamassassin/3.002005" for default rules dir [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com.cf [30954] dbg: config: read file /var/lib/spamassassin/3.002005/sought_rules_yerp_org.cf [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org.cf [30954] dbg: config: using "/etc/mail/spamassassin" for site rules dir [30954] dbg: config: read file /etc/mail/spamassassin/local.cf [30954] dbg: config: using "/var/spool/amavisd/.spamassassin/user_prefs" for user prefs file [30954] dbg: config: read file /var/spool/amavisd/.spamassassin/user_prefs [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDNSBL from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::Hashcash from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::SPF from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::DCC from @INC [30954] dbg: dcc: network tests on, registering DCC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::Pyzor from @INC [30954] dbg: pyzor: network tests on, attempting Pyzor [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::Razor2 from @INC [30954] dbg: razor2: razor2 is available, version 2.84 [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::SpamCop from @INC [30954] dbg: reporter: network tests on, attempting SpamCop [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::AWL from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::WhiteListSubject from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEHeader from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::ReplaceTags from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::DKIM from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::Check from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTTPSMismatch from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDetail from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::Bayes from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::BodyEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::DNSEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTMLEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::HeaderEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::RelayEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::WLBLEval from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::VBounce from @INC [30954] dbg: plugin: loading Mail::SpamAssassin::Plugin::ImageInfo from @INC [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/loadplugins.pre [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/loadplugins.pre" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/loadplugins.pre [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_adult.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_adult.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_adult.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_bayes_poison_nxm.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_bayes_poison_nxm.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_bayes_poison_nxm.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_evilnum0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_evilnum0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_evilnum0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_evilnum1.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_evilnum1.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_evilnum1.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj1.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj1.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj1.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj2.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj2.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj2.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj_eng.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj_eng.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_genlsubj_eng.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_header0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_header0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_header0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_header1.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_header1.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_header1.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_highrisk.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_highrisk.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_highrisk.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_html0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_html0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_html0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_html1.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_html1.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_html1.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_obfu0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_obfu0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_obfu0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_obfu1.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_obfu1.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_obfu1.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_oem.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_oem.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_oem.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_random.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_random.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_random.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_specific.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_specific.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_specific.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_spoof.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_spoof.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_spoof.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_stocks.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_stocks.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_stocks.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_unsub.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_unsub.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_unsub.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri1.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri1.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri1.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri_eng.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri_eng.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_uri_eng.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist_rcvd.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist_rcvd.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist_rcvd.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist_spf.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist_spf.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sare_whitelist_spf.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sc_top200.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sc_top200.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/70_sc_top200.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/72_sare_bml_post25x.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/72_sare_bml_post25x.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/72_sare_bml_post25x.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/72_sare_redirect_post3.0.0.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/72_sare_redirect_post3.0.0.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/72_sare_redirect_post3.0.0.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/saupdates_openprotect_com/99_sare_fraud_post25x.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/saupdates_openprotect_com/99_sare_fraud_post25x.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/saupdates_openprotect_com/99_sare_fraud_post25x.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/sought_rules_yerp_org/20_sought.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/sought_rules_yerp_org/20_sought.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/sought_rules_yerp_org/20_sought.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/sought_rules_yerp_org/20_sought_fraud.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/sought_rules_yerp_org/20_sought_fraud.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/sought_rules_yerp_org/20_sought_fraud.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/10_default_prefs.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/10_default_prefs.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/10_default_prefs.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_advance_fee.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_advance_fee.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_advance_fee.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_body_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_body_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_body_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_compensate.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_compensate.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_compensate.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_dnsbl_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_dnsbl_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_dnsbl_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_drugs.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_drugs.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_drugs.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_dynrdns.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_dynrdns.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_dynrdns.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_fake_helo_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_fake_helo_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_fake_helo_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_head_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_head_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_head_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_html_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_html_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_html_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_imageinfo.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_imageinfo.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_imageinfo.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_meta_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_meta_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_meta_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_net_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_net_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_net_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_phrases.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_phrases.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_phrases.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_porn.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_porn.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_porn.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_ratware.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_ratware.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_ratware.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_uri_tests.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_uri_tests.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_uri_tests.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_vbounce.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/20_vbounce.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/20_vbounce.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/23_bayes.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/23_bayes.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/23_bayes.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_accessdb.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_accessdb.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_accessdb.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_antivirus.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_antivirus.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_antivirus.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_asn.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_asn.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_asn.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_dcc.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_dcc.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_dcc.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_dkim.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_dkim.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_dkim.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_domainkeys.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_domainkeys.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_domainkeys.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_hashcash.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_hashcash.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_hashcash.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_pyzor.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_pyzor.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_pyzor.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_razor2.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_razor2.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_razor2.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_replace.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_replace.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_replace.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_spf.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_spf.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_spf.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_textcat.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_textcat.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_textcat.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_uribl.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/25_uribl.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/25_uribl.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_de.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_de.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_de.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_fr.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_fr.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_fr.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_it.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_it.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_it.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_nl.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_nl.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_nl.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_pl.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_pl.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_pl.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_pt_br.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_pt_br.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/30_text_pt_br.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/50_scores.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/50_scores.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/50_scores.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_awl.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_awl.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_awl.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_shortcircuit.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_shortcircuit.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_shortcircuit.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_dk.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_dk.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_dk.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_dkim.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_dkim.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_dkim.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_spf.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_spf.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_spf.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_subject.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_subject.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/60_whitelist_subject.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/72_active.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/72_active.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/72_active.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/72_removed.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/72_removed.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/72_removed.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/72_scores.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/72_scores.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/72_scores.cf [30954] dbg: config: fixed relative path: /var/lib/spamassassin/3.002005/updates_spamassassin_org/80_additional.cf [30954] dbg: config: using "/var/lib/spamassassin/3.002005/updates_spamassassin_org/80_additional.cf" for included file [30954] dbg: config: read file /var/lib/spamassassin/3.002005/updates_spamassassin_org/80_additional.cf netset: cannot include 127.0.0.0/8 as it has already been included [30954] dbg: rules: __XM_OL_22B61 merged duplicates: __XM_OL_A842E [30954] dbg: rules: PREVENT_NONDELIVERY merged duplicates: SARE_HEAD_HDR_PREVNDR [30954] dbg: rules: __SARE_HEAD_HDR_IDKEY merged duplicates: SARE_HEAD_HDR_XIDKEY [30954] dbg: rules: __JM_REACTOR_DATE merged duplicates: __RATWARE_0_TZ_DATE [30954] dbg: rules: __SARE_BODY_BLANKS_5_100 merged duplicates: __SARE_BODY_BLNK_5_100 [30954] dbg: rules: __XM_OL_07794 merged duplicates: __XM_OL_25340 __XM_OL_3857F __XM_OL_4F240 __XM_OL_58CB5 __XM_OL_6554A __XM_OL_812FF __XM_OL_C65FA __XM_OL_CF0C0 __XM_OL_F475E __XM_OL_F6D01 [30954] dbg: rules: __HTML_IMG_ONLY merged duplicates: __IMG_ONLY [30954] dbg: rules: FU_UKGEOCITIES merged duplicates: __SARE_SPEC_XX2GEOCIT [30954] dbg: rules: FB_FAKE_NUMBERS merged duplicates: SARE_OBFU_NUMBERS [30954] dbg: rules: FH_MSGID_01C67 merged duplicates: __MSGID_VGA [30954] dbg: rules: FS_NEW_SOFT_UPLOAD merged duplicates: HS_SUBJ_NEW_SOFTWARE [30954] dbg: rules: __MO_OL_22B61 merged duplicates: __MO_OL_4F240 __MO_OL_ADFF7 [30954] dbg: rules: SARE_SUB_2UNDERSCORES merged duplicates: SARE_SUB_6_FIG_INC SARE_SUB_ACCENT_CHAR SARE_SUB_ACCT_UPD SARE_SUB_ACTION_OB SARE_SUB_ADV_DB SARE_SUB_ADV_SEARCH SARE_SUB_AGING SARE_SUB_ALL_LEAD SARE_SUB_AM_MED_DICT SARE_SUB_ASSIST SARE_SUB_AS_LOW_AS SARE_SUB_BETTER_DEAL SARE_SUB_BETTER_OB2 SARE_SUB_BIGGER SARE_SUB_BIGGER_OB SARE_SUB_BOOST SARE_SUB_BOOST_OB SARE_SUB_BREAKTHRU SARE_SUB_BREAKTHRU_OB SARE_SUB_BULK_EMAIL SARE_SUB_BUY_CHEAP SARE_SUB_BUY_OB SARE_SUB_BUY_OB1 SARE_SUB_CALL_NOW SARE_SUB_CARD_BILLED SARE_SUB_CARTRIDGE_OB SARE_SUB_CAR_INSURANCE SARE_SUB_CASINO_OB SARE_SUB_CHANGE_LIFE SARE_SUB_CHARGE_OB SARE_SUB_CHEAP_OB SARE_SUB_COMM_MAILERS SARE_SUB_CONFIDENTIAL SARE_SUB_CONFID_OB SARE_SUB_CONSULTATION SARE_SUB_CONSULTN_OB SARE_SUB_CURRENT_NEWS SARE_SUB_DBL_MEDICTN SARE_SUB_DBL_PHARM SARE_SUB_DEBT SARE_SUB_DEBTS_COURT SARE_SUB_DOLLARS SARE_SUB_DOWNLOAD_OB SARE_SUB_EBAY_OB SARE_SUB_EXCL_OB SARE_SUB_EXPIRED SARE_SUB_FORECLOSURE SARE_SUB_FOREVER SARE_SUB_FOR_WOMEN SARE_SUB_FREE_SAMPLE SARE_SUB_GAPPY_3 SARE_SUB_GAPPY_4 SARE_SUB_GAPPY_5 SARE_SUB_GAPPY_6 SARE_SUB_GAPPY_7 SARE_SUB_GAPPY_8 SARE_SUB_GROW_BUSINESS SARE_SUB_HARD_OB SARE_SUB_HOMEOWNER_OB SARE_SUB_INCHES SARE_SUB_INC_ONLINE SARE_SUB_INEXPEN SARE_SUB_INKJET SARE_SUB_INKJET_OB SARE_SUB_INVESTMENTS SARE_SUB_INVESTORS SARE_SUB_JOB SARE_SUB_LEAD_PUNCT SARE_SUB_LINES_CREDIT SARE_SUB_LONG_SUBJ_140 SARE_SUB_LONG_SUBJ_170 SARE_SUB_LOSE_OB SARE_SUB_LOTS_PUNC_21 SARE_SUB_LOTS_PUNC_26 SARE_SUB_MED_USE SARE_SUB_MENS_HEALTH SARE_SUB_MINUTES SARE_SUB_MISC_1 SARE_SUB_MORTGAGE SARE_SUB_MORTGAGE_OB SARE_SUB_MOVE_OB SARE_SUB_MSGSUB SARE_SUB_NEXT_DOOR SARE_SUB_NOW_TIME SARE_SUB_OBFU_V SARE_SUB_ODDWORD_G SARE_SUB_ODDWORD_I SARE_SUB_ODDWORD_P SARE_SUB_ODDWORD_Q SARE_SUB_ODDWORD_U SARE_SUB_ONLINE_OB SARE_SUB_ORIG_SOFT_OB SARE_SUB_PAREN_NUM2 SARE_SUB_PASSION_OB SARE_SUB_PENIS_OB SARE_SUB_PERFECTLY SARE_SUB_PHOTOS_OB SARE_SUB_PHYSICIAN SARE_SUB_PHYSICIAN_OB SARE_SUB_PLEASE_OB SARE_SUB_PORN_WORD10 SARE_SUB_PRINTER_OB SARE_SUB_PROVEN_OB SARE_SUB_RAND_LETTRS5 SARE_SUB_RAND_UC SARE_SUB_REAL_OB SARE_SUB_SEXY SARE_SUB_SION_OB SARE_SUB_STRETCH_MARK SARE_SUB_STRONG SARE_SUB_STRONG_OB SARE_SUB_TAXES SARE_SUB_TION_OB SARE_SUB_TONER SARE_SUB_TONER_OB SARE_SUB_VIDEO_OB SARE_SUB_VIRUSQ SARE_SUB_WEBMASTER2 SARE_SUB_WINNER SARE_SUB_YOUNGER SARE_SUB_YOUNGER_OB [30954] dbg: rules: __MO_OL_812FF merged duplicates: __MO_OL_BC7E6 [30954] dbg: rules: __SARE_HEAD_FALSE merged duplicates: __SARE_SUB_FALSE [30954] dbg: rules: SARE_SUBJ_SLUT merged duplicates: __FPS_SLUT [30954] dbg: rules: __SEEK_2PBFIF merged duplicates: __SEEK_FRAUD_2PBFIF [30954] dbg: rules: __FVGT_RAPE merged duplicates: __WORD_RAPED [30954] dbg: rules: SARE_USERAG_BAT merged duplicates: __SARE_HEAD_MAIL_BAT2 [30954] dbg: rules: __XM_OL_C9068 merged duplicates: __XM_OL_EF20B [30954] dbg: rules: __FH_RCV_53 merged duplicates: __RCVD_53 [30954] dbg: rules: __MO_OL_72641 merged duplicates: __MO_OL_A842E [30954] dbg: rules: SARE_OBFU_AFFORD merged duplicates: SARE_OBFU_AMP SARE_OBFU_BETTER_SUB SARE_OBFU_CARTRDGE_SUB SARE_OBFU_CIALIS SARE_OBFU_OBLIGATION SARE_OBFU_SEX_SPL SARE_OBFU_TBL_05 SARE_URI_AFF_DIG SARE_URI_CAMPAIGNID SARE_URI_CASINO SARE_URI_DIET SARE_URI_DIG_LET_PIC SARE_URI_DOM_ENDU SARE_URI_H0 SARE_URI_HARRYDAV SARE_URI_HOUSE SARE_URI_IPPORT3333 SARE_URI_MIXED_CASE SARE_URI_MRTG SARE_URI_OC SARE_URI_OPTOUT SARE_URI_P8 SARE_URI_PORTD4 SARE_URI_REFID2 SARE_URI_REFID3 SARE_URI_SHARE_DIG SARE_URI_SIXCAPS SARE_URI_SQUARE SARE_URI_SUCCEZZ [30954] dbg: rules: __MO_OL_4BF4C merged duplicates: __MO_OL_F6D01 [30954] dbg: rules: __MO_OL_07794 merged duplicates: __MO_OL_8627E __MO_OL_F3B05 [30954] dbg: rules: SARE_SPOOF_COM2OTH merged duplicates: SPOOF_COM2COM [30954] dbg: rules: __MO_OL_9B90B merged duplicates: __MO_OL_C65FA [30954] dbg: rules: SARE_HEAD_HDR_XRMDTXT merged duplicates: __SARE_HEAD_HDR_RMDB [30954] dbg: rules: __FH_FRM_53 merged duplicates: __FROM_53 [30954] dbg: rules: __SEEK_FRAUD_SKC_ZR merged duplicates: __SEEK_SKC_ZR [30954] dbg: rules: FH_HELO_GMAILSMTP merged duplicates: SARE_HELO_GMAILSMTP [30954] dbg: rules: __FH_HAS_XMSMAIL merged duplicates: __HAS_MSMAIL_PRI [30954] dbg: rules: KAM_STOCKOTC merged duplicates: KAM_STOCKTIP15 KAM_STOCKTIP20 KAM_STOCKTIP21 KAM_STOCKTIP4 KAM_STOCKTIP6 [30954] dbg: rules: __XM_OL_015D5 merged duplicates: __XM_OL_4BF4C __XM_OL_4EEDB __XM_OL_5B79A __XM_OL_9B90B __XM_OL_ADFF7 __XM_OL_B30D1 __XM_OL_B4B40 __XM_OL_BC7E6 __XM_OL_F3B05 __XM_OL_FF5C8 [30954] dbg: rules: __MO_OL_91287 merged duplicates: __MO_OL_B30D1 __MO_OL_CF0C0 [30954] dbg: rules: __MO_OL_015D5 merged duplicates: __MO_OL_6554A [30954] dbg: rules: __MO_OL_25340 merged duplicates: __MO_OL_4EEDB __MO_OL_7533E [30954] dbg: rules: __MO_OL_58CB5 merged duplicates: __MO_OL_B4B40 [30954] dbg: rules: __DOS_HAS_ANY_URI merged duplicates: __HAS_ANY_URI __SARE_URI_ANY [30954] dbg: rules: SARE_BOUNDARY_02 merged duplicates: SARE_BOUNDARY_ANYDIG SARE_BOUNDARY_D11 SARE_BOUNDARY_D8 SARE_BOUNDARY_MULTB SARE_CONTENT_BITBITNUM SARE_FREE_WEBM_CZSEZNA SARE_FREE_WEBM_USACOPS SARE_FROM_AMERICA SARE_FROM_DEBT SARE_FROM_DVDCOPY SARE_FROM_MULTI_DASH SARE_FROM_NUM_9DIG SARE_FROM_PRINTER SARE_FROM_QUOTE SARE_FROM_SPACE2 SARE_FROM_SPAM_CHAR0 SARE_FROM_SPAM_DOMN0 SARE_FROM_SPAM_NAME2 SARE_FROM_SPAM_WORD0 SARE_FROM_SUPPORT_DIG SARE_FROM_UK2NET2 SARE_FROM_VIRUS1 SARE_FROM_WSJ SARE_HEAD_8BIT_NOSPM SARE_HEAD_8BIT_SPAM SARE_HEAD_BDY_BOUNCES SARE_HEAD_DATE18 SARE_HEAD_DATE_5L SARE_HEAD_DATE_RNDDATE SARE_HEAD_HDR_ALTREC SARE_HEAD_HDR_AUTSUBD SARE_HEAD_HDR_CONVER SARE_HEAD_HDR_JLH SARE_HEAD_HDR_MSGTYPE SARE_HEAD_HDR_NLETRID SARE_HEAD_HDR_PID SARE_HEAD_HDR_RTNPATH SARE_HEAD_HDR_X400RCV SARE_HEAD_HDR_XACWGHT SARE_HEAD_HDR_XAR SARE_HEAD_HDR_XAUTOGN SARE_HEAD_HDR_XBBOUNC SARE_HEAD_HDR_XBNCETR SARE_HEAD_HDR_XCCDIAG SARE_HEAD_HDR_XCNDINF SARE_HEAD_HDR_XCONTAC SARE_HEAD_HDR_XEMGBMS SARE_HEAD_HDR_XENVID SARE_HEAD_HDR_XGMAILA SARE_HEAD_HDR_XIDSRVR SARE_HEAD_HDR_XLEGAL2 SARE_HEAD_HDR_XLEGAL4 SARE_HEAD_HDR_XLISTAD SARE_HEAD_HDR_XMAILTH SARE_HEAD_HDR_XMCAVTP SARE_HEAD_HDR_XMEBDOM SARE_HEAD_HDR_XMLFILT SARE_HEAD_HDR_XNOSPAM SARE_HEAD_HDR_XRIPE SARE_HEAD_HDR_XSAFMMI SARE_HEAD_HDR_XSMTPSV SARE_HEAD_HDR_XUMAIL SARE_HEAD_HDR_XUNOLOOK SARE_HEAD_HDR_XWTID SARE_HEAD_HDR_XWTVERS SARE_HEAD_MSMPR_RNDSTR SARE_HEAD_ORIG_RECIP SARE_HEAD_THRD_ALNUM SARE_HEAD_XCANIT1 SARE_HEAD_XCANIT2 SARE_HEAD_XCOM_RFCMIN SARE_HEAD_XM4 SARE_HEAD_XMF_AUTHSNDR SARE_HEAD_XWORD SARE_HELO_MAIL SARE_HELO_MAILUSER SARE_HELO_SERVER SARE_HTML_ALT_WAIT1 SARE_HTML_ALT_WAIT2 SARE_HTML_A_NULL SARE_HTML_BADOPEN SARE_HTML_BAD_FG_CLR SARE_HTML_BR_MANY SARE_HTML_COLOR_B SARE_HTML_COLOR_NWHT3 SARE_HTML_EHTML_OBFU SARE_HTML_FONT_INVIS2 SARE_HTML_FSIZE_1ALL SARE_HTML_GIF_DIM SARE_HTML_H2_CLK SARE_HTML_HEAD_AFFIL SARE_HTML_HTML_AFTER SARE_HTML_HTML_DBL SARE_HTML_INV_TAGA SARE_HTML_JSCRIPT_ENC SARE_HTML_JVS_HREF SARE_HTML_LEAKTHRU1 SARE_HTML_LEAKTHRU2 SARE_HTML_MANY_BR10 SARE_HTML_NO_BODY SARE_HTML_NO_HTML1 SARE_HTML_ONE_LINE2 SARE_HTML_ONE_LINE3 SARE_HTML_POB1200 SARE_HTML_P_JUSTIFY SARE_HTML_TITLE_MNY SARE_HTML_URI_2SLASH SARE_HTML_URI_AXEL SARE_HTML_URI_BADQRY SARE_HTML_URI_BUG SARE_HTML_URI_DEFASP SARE_HTML_URI_FORMPHP SARE_HTML_URI_HIDADD SARE_HTML_URI_HREF SARE_HTML_URI_LOGOGEN SARE_HTML_URI_MANYP2 SARE_HTML_URI_MANYP3 SARE_HTML_URI_NUMPHP3 SARE_HTML_URI_OBFU4 SARE_HTML_URI_OBFU4a SARE_HTML_URI_OC SARE_HTML_URI_OFF SARE_HTML_URI_REFID SARE_HTML_URI_RID SARE_HTML_URI_RM SARE_HTML_USL_B7 SARE_HTML_USL_B9 SARE_HTML_USL_MULT SARE_MSGID_06D6 SARE_MSGID_2KDD SARE_MSGID_DBL_AT SARE_MSGID_EMPTY SARE_MSGID_HEX30 SARE_MSGID_LONG SARE_MSGID_LONG35 SARE_MSGID_LONG40 SARE_MSGID_LONG55 SARE_MSGID_LONG65 SARE_MSGID_LONG75 SARE_MSGID_SPAM_DOMN0 SARE_MSGID_SUSP2 SARE_MULT_RATW_02 SARE_MULT_RATW_03 SARE_MULT_SEXCLUB SARE_MULT_SUBJ SARE_MULT_VIA_FWCATS SARE_PHISH_HTML_01 SARE_RECV_CHAR_CARAT SARE_RECV_FREESERVE SARE_RECV_IP_004078 SARE_RECV_IP_038112147 SARE_RECV_IP_062023 SARE_RECV_IP_063106130 SARE_RECV_IP_064034 SARE_RECV_IP_064069032 SARE_RECV_IP_064080 SARE_RECV_IP_064192082 SARE_RECV_IP_064192191 SARE_RECV_IP_065205157 SARE_RECV_IP_066063 SARE_RECV_IP_066111 SARE_RECV_IP_066114a SARE_RECV_IP_066114b SARE_RECV_IP_066159017 SARE_RECV_IP_066248154 SARE_RECV_IP_069060122 SARE_RECV_IP_070096177 SARE_RECV_IP_071004246 SARE_RECV_IP_080178 SARE_RECV_IP_081019 SARE_RECV_IP_195229 SARE_RECV_IP_206248152 SARE_RECV_IP_207182 SARE_RECV_IP_208048182 SARE_RECV_IP_209190 SARE_RECV_IP_211049 SARE_RECV_IP_212164 SARE_RECV_IP_216055133 SARE_RECV_IP_222126 SARE_RECV_ISWEST SARE_RECV_LOCALHOST SARE_RECV_RANDOM SARE_RECV_RND_DATE SARE_RECV_RND_NUMBER SARE_RECV_SPAM_DOMN3 SARE_RECV_SPAM_DOMN81 SARE_RECV_SPAM_NAME0 SARE_RECV_SUSP_2 SARE_RECV_SUSP_3 SARE_RECV_TRADVALUES SARE_RECV_VIPLIST SARE_RECV_XACTRIX SARE_REPLY_SPAMWORD0 SARE_REPLY_XACTRIX SARE_TOCC_BCC_MANY SARE_TOCC_COMBO1 SARE_USERAG_Dig SARE_XMAIL_DIRUNIV SARE_XMAIL_GDI SARE_XMAIL_GOMAIL SARE_XMAIL_INTERMED SARE_XMAIL_LEO SARE_XMAIL_PHPBulkEmai SARE_XMAIL_SUSP3 SARE_XMAIL_TOLMAIL SARE_XMAIL_XMAIL [30954] dbg: rules: AXB_RCVD_ZOOBSEND merged duplicates: BROKEN_RATWARE_BOM CTYPE_001C_A DEAR_HOMEOWNER DIV_CENTER_A_HREF DRUG_RA_PRICE FM_DDDD_TIMES_2 FM_SEX_HOSTDDDD HG_HORMONE HS_PHARMA_1 HS_UPLOADED_SOFTWARE OEBOUND RCVD_IN_DSBL STOX_RCVD_N_NN_N URIBL_RHS_ABUSE URIBL_RHS_BOGUSMX URIBL_RHS_DSN URIBL_RHS_POST URIBL_RHS_TLD_WHOIS URIBL_RHS_WHOIS URIBL_XS_SURBL URI_L_PHP XMAILER_MIMEOLE_OL_5E7ED XMAILER_MIMEOLE_OL_C7C33 XMAILER_MIMEOLE_OL_D03AB X_LIBRARY YOUR_CRD_RATING [30954] dbg: rules: __MO_OL_F475E merged duplicates: __MO_OL_FF5C8 [30954] dbg: rules: __SEEK_FRAUD_ZMTQZC merged duplicates: __SEEK_ZMTQZC [30954] dbg: conf: finish parsing [30954] dbg: plugin: Mail::SpamAssassin::Plugin::ReplaceTags=HASH(0xb8a7454) implements 'finish_parsing_end', priority 0 [30954] dbg: replacetags: replacing tags [30954] dbg: replacetags: done replacing tags [30954] dbg: bayes: using username: amavis [30954] dbg: bayes: database connection established [30954] dbg: bayes: found bayes db version 3 [30954] dbg: bayes: Using userid: 1 [30954] dbg: config: score set 3 chosen. [30954] dbg: message: main message type: text/plain [30954] dbg: message: ---- MIME PARSER START ---- [30954] dbg: message: parsing normal part [30954] dbg: message: ---- MIME PARSER END ---- [30954] dbg: plugin: Mail::SpamAssassin::Plugin::DNSEval=HASH(0xb87e67c) implements 'check_start', priority 0 [30954] dbg: plugin: Mail::SpamAssassin::Plugin::Check=HASH(0xb8958dc) implements 'check_main', priority 0 [30954] dbg: conf: internal_networks not configured, using trusted_networks configuration for internal_networks; if you really want internal_networks to only contain the required 127/8 add 'internal_networks !0/0' to your configuration [30954] dbg: metadata: X-Spam-Relays-Trusted: [30954] dbg: metadata: X-Spam-Relays-Untrusted: [30954] dbg: metadata: X-Spam-Relays-Internal: [30954] dbg: metadata: X-Spam-Relays-External: [30954] dbg: message: no encoding detected [30954] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH(0xb84aa44) implements 'parsed_metadata', priority 0 [30954] dbg: dns: is Net::DNS::Resolver available? yes [30954] dbg: dns: Net::DNS version: 0.63 [30954] dbg: dns: name server: 137.208.3.3, LocalAddr: 0.0.0.0 [30954] dbg: dns: resolver socket rx buffer size is 111616 bytes [30954] dbg: dns: dns_available set to yes in config file, skipping test [30954] dbg: uridnsbl: domains to query: [30954] dbg: dns: checking RBL sa-other.bondedsender.org., set bsp-untrusted [30954] dbg: dns: checking RBL plus.bondedsender.org., set ssc-firsttrusted [30954] dbg: dns: checking RBL combined.njabl.org., set njabl [30954] dbg: dns: checking RBL bl.spamcop.net., set spamcop [30954] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [30954] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs-lastexternal [30954] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs [30954] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [30954] dbg: dns: checking RBL list.dnswl.org., set dnswl-firsttrusted [30954] dbg: dns: checking RBL sa-accredit.habeas.com., set habeas-firsttrusted [30954] dbg: dns: checking RBL sa-trusted.bondedsender.org., set bsp-firsttrusted [30954] dbg: dns: checking RBL zen.spamhaus.org., set zen [30954] dbg: dns: checking RBL iadb.isipp.com., set iadb-firsttrusted [30954] dbg: check: running tests for priority: -1000 [30954] dbg: rules: running head tests; score so far=0 [30954] dbg: rules: compiled head tests [30954] dbg: eval: all '*From' addrs: ignore@compiling.spamassassin.taint.org [30954] dbg: eval: all '*To' addrs: [30954] dbg: rules: running body tests; score so far=0 [30954] dbg: rules: compiled body tests [30954] dbg: rules: running uri tests; score so far=0 [30954] dbg: rules: compiled uri tests [30954] dbg: rules: running rawbody tests; score so far=0 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: running full tests; score so far=0 [30954] dbg: rules: compiled full tests [30954] dbg: rules: running meta tests; score so far=0 [30954] dbg: rules: compiled meta tests [30954] dbg: check: running tests for priority: -950 [30954] dbg: rules: running head tests; score so far=0 [30954] dbg: rules: compiled head tests [30954] dbg: rules: running body tests; score so far=0 [30954] dbg: rules: compiled body tests [30954] dbg: rules: running uri tests; score so far=0 [30954] dbg: rules: compiled uri tests [30954] dbg: rules: running rawbody tests; score so far=0 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: running full tests; score so far=0 [30954] dbg: rules: compiled full tests [30954] dbg: rules: running meta tests; score so far=0 [30954] dbg: rules: compiled meta tests [30954] dbg: check: running tests for priority: -900 [30954] dbg: rules: running head tests; score so far=0 [30954] dbg: rules: compiled head tests [30954] dbg: rules: running body tests; score so far=0 [30954] dbg: rules: compiled body tests [30954] dbg: rules: running uri tests; score so far=0 [30954] dbg: rules: compiled uri tests [30954] dbg: rules: running rawbody tests; score so far=0 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: running full tests; score so far=0 [30954] dbg: rules: compiled full tests [30954] dbg: rules: running meta tests; score so far=0 [30954] dbg: rules: compiled meta tests [30954] dbg: check: running tests for priority: -400 [30954] dbg: rules: running head tests; score so far=0 [30954] dbg: rules: compiled head tests [30954] dbg: rules: running body tests; score so far=0 [30954] dbg: rules: compiled body tests [30954] dbg: rules: running uri tests; score so far=0 [30954] dbg: rules: compiled uri tests [30954] dbg: rules: running rawbody tests; score so far=0 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: running full tests; score so far=0 [30954] dbg: rules: compiled full tests [30954] dbg: rules: running meta tests; score so far=0 [30954] dbg: rules: compiled meta tests [30954] dbg: check: running tests for priority: 0 [30954] dbg: rules: running head tests; score so far=0 [30954] dbg: rules: compiled head tests [30954] dbg: rules: ran header rule __MISSING_REF ======> got hit: "UNSET" [30954] dbg: rules: ran header rule __MSOE_MID_WRONG_CASE ======> got hit: " [30954] dbg: rules: Message-Id: " [30954] dbg: rules: ran header rule MISSING_DATE ======> got hit: "UNSET" [30954] dbg: rules: ran header rule __SARE_WHITELIST_FLAG ======> got hit: "i" [30954] dbg: rules: ran header rule __MSGID_OK_HOST ======> got hit: "@spamassassin_spamd_init>" [30954] dbg: rules: ran header rule __MSGID_OK_DIGITS ======> got hit: "1243873881" [30954] dbg: rules: ran header rule __HAS_MSGID ======> got hit: "<" [30954] dbg: rules: ran header rule __SANE_MSGID ======> got hit: "<1243873881.90385@spamassassin_spamd_init> [30954] dbg: rules: " [30954] dbg: spf: checking to see if the message has a Received-SPF header that we can use [30954] dbg: spf: using Mail::SPF for SPF checks [30954] dbg: spf: no suitable relay for spf use found, skipping SPF-helo check [30954] dbg: dkim: performing public key lookup and signature verification [30954] dbg: dkim: signature verification result: none [30954] dbg: dkim: author ignore@compiling.spamassassin.taint.org, not in any dkim whitelist [30954] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [30954] dbg: spf: no suitable relay for spf use found, skipping SPF check [30954] dbg: rules: ran eval rule NO_RELAYS ======> got hit (1) [30954] dbg: dkim: policy: performing lookup [30954] dbg: dkim: policy result neutral: o=~ [30954] dbg: spf: def_spf_whitelist_from: already checked spf and didn't get pass, skipping whitelist check [30954] dbg: rules: ran eval rule __UNUSABLE_MSGID ======> got hit (1) [30954] dbg: rules: ran eval rule MISSING_HEADERS ======> got hit (1) [30954] dbg: spf: whitelist_from_spf: already checked spf and didn't get pass, skipping whitelist check [30954] dbg: rules: running body tests; score so far=1.292 [30954] dbg: rules: compiled body tests [30954] dbg: rules: ran body rule __NONEMPTY_BODY ======> got hit: "I" [30954] dbg: rules: running uri tests; score so far=1.292 [30954] dbg: rules: compiled uri tests [30954] dbg: eval: stock info total: 0 [30954] dbg: rules: running rawbody tests; score so far=1.292 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: ran rawbody rule __TVD_BODY ======> got hit: "need" [30954] dbg: rules: running full tests; score so far=1.292 [30954] dbg: rules: compiled full tests [30954] dbg: info: entering helper-app run mode [30954] dbg: info: leaving helper-app run mode [30954] dbg: razor2: part=0 engine=4 contested=0 confidence=0 [30954] dbg: razor2: results: spam? 0 [30954] dbg: razor2: results: engine 8, highest cf score: 0 [30954] dbg: razor2: results: engine 4, highest cf score: 0 [30954] dbg: util: current PATH is: /usr/local/sbin:/usr/local/bin:/usr/sbin:/sbin:/usr/bin:/bin [30954] dbg: pyzor: pyzor is not available: no pyzor executable found [30954] dbg: pyzor: no pyzor found, disabling Pyzor [30954] dbg: dcc: dccifd is not available: no r/w dccifd socket found [30954] dbg: dcc: dccproc is not available: no dccproc executable found [30954] dbg: dcc: dccifd and dccproc are not available, disabling DCC [30954] dbg: rules: running meta tests; score so far=1.292 [30954] dbg: rules: compiled meta tests [30954] dbg: check: running tests for priority: 500 [30954] dbg: dns: harvest_dnsbl_queries [30954] dbg: rules: running head tests; score so far=1.292 [30954] dbg: rules: compiled head tests [30954] dbg: rules: running body tests; score so far=1.292 [30954] dbg: rules: compiled body tests [30954] dbg: rules: running uri tests; score so far=1.292 [30954] dbg: rules: compiled uri tests [30954] dbg: rules: running rawbody tests; score so far=1.292 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: running full tests; score so far=1.292 [30954] dbg: rules: compiled full tests [30954] dbg: rules: running meta tests; score so far=1.292 [30954] dbg: rules: meta test SARE_HEAD_SUBJ_RAND has undefined dependency 'SARE_XMAIL_SUSP2' [30954] dbg: rules: meta test SARE_HEAD_SUBJ_RAND has undefined dependency 'SARE_HEAD_XAUTH_WARN' [30954] dbg: rules: meta test SARE_HEAD_SUBJ_RAND has undefined dependency 'X_AUTH_WARN_FAKED' [30954] dbg: rules: meta test SARE_RD_SAFE has undefined dependency 'SARE_RD_SAFE_MKSHRT' [30954] dbg: rules: meta test SARE_RD_SAFE has undefined dependency 'SARE_RD_SAFE_GT' [30954] dbg: rules: meta test SARE_RD_SAFE has undefined dependency 'SARE_RD_SAFE_TINY' [30954] dbg: rules: meta test MSGID_DOLLARS has undefined dependency '__HAS_OUTLOOK_IN_MAILER' [30954] dbg: rules: compiled meta tests [30954] dbg: check: running tests for priority: 1000 [30954] dbg: rules: running head tests; score so far=3.053 [30954] dbg: rules: compiled head tests [30954] dbg: auto-whitelist: sql-based connected to DBI:mysql:spamassassin:127.0.0.1 [30954] dbg: auto-whitelist: sql-based using username: amavis [30954] dbg: auto-whitelist: sql-based get_addr_entry: no entry found for ignore@compiling.spamassassin.taint.org|ip=none [30954] dbg: auto-whitelist: sql-based ignore@compiling.spamassassin.taint.org|ip=none scores 0/0 [30954] dbg: auto-whitelist: AWL active, pre-score: 3.053, autolearn score: 3.053, mean: undef, IP: undef [30954] dbg: auto-whitelist: sql-based finish: disconnected from DBI:mysql:spamassassin:127.0.0.1 [30954] dbg: auto-whitelist: post auto-whitelist score: 3.053 [30954] dbg: rules: running body tests; score so far=3.053 [30954] dbg: rules: compiled body tests [30954] dbg: rules: running uri tests; score so far=3.053 [30954] dbg: rules: compiled uri tests [30954] dbg: rules: running rawbody tests; score so far=3.053 [30954] dbg: rules: compiled rawbody tests [30954] dbg: rules: running full tests; score so far=3.053 [30954] dbg: rules: compiled full tests [30954] dbg: rules: running meta tests; score so far=3.053 [30954] dbg: rules: compiled meta tests [30954] dbg: check: is spam? score=3.053 required=7 [30954] dbg: check: tests=MISSING_DATE,MISSING_HEADERS,MISSING_SUBJECT,NO_RECEIVED,NO_RELAYS [30954] dbg: check: subtests=__HAS_MSGID,__MISSING_REF,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__MSOE_MID_WRONG_CASE,__NONEMPTY_BODY,__SANE_MSGID,__SARE_WHITELIST_FLAG,__TVD_BODY,__UNUSABLE_MSGID Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: SpamControl: init_pre_fork done Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Beginning prefork (6 processes) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Starting "6" children Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: Net::Server: Child Preforked (30956) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: Net::Server: Child Preforked (30957) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: storage and lookups will use the same connection to SQL Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: storage and lookups will use the same connection to SQL Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30958]: Net::Server: Child Preforked (30958) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30959]: Net::Server: Child Preforked (30959) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30958]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30958]: storage and lookups will use the same connection to SQL Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30959]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30959]: storage and lookups will use the same connection to SQL Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30960]: Net::Server: Child Preforked (30960) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30961]: Net::Server: Child Preforked (30961) Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30960]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30960]: storage and lookups will use the same connection to SQL Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30961]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30961]: storage and lookups will use the same connection to SQL Jun 1 18:31:25 strike.wu-wien.ac.at /usr/sbin/amavisd[30954]: Net::Server: Parent ready for children. Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: Net::Server: 2009/06/01-18:31:27 CONNECT TCP Peer: "127.0.0.1:51536" Local: "127.0.0.1:10024" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: loaded base policy bank Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: loaded policy bank "STRIKE" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.0/8", result=1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: process_request: fileno sock=13, STDIN=0, STDOUT=1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: switch_to_my_time 90 s, new request Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: process_request: suggested_protocol="" on TCP Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 4: was busy, 4.0 ms, total idle 0.000 s, busy 0.004 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.000 s, busy 0.004 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) SMTP< EHLO strike.wu.ac.at\r\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, SMTP EHLO received Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-[127.0.0.1] Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-VRFY Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-PIPELINING Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-SIZE Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-ENHANCEDSTATUSCODES Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-8BITMIME Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250-DSN Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.000 s, busy 0.005 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.000 s, busy 0.005 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP< XFORWARD NAME=monty.wu-wien.ac.at ADDR=137.208.16.200 HELO=monty.wu-wien.ac.at PROTO=ESMTP\r\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, SMTP XFORWARD received Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250 2.5.0 Ok XFORWARD Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 6: was busy, 0.6 ms, total idle 0.000 s, busy 0.006 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.000 s, busy 0.006 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP< MAIL FROM: SIZE=2671\r\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, SMTP MAIL received Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) check_mail_begin_task: task_count=1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) TempDir::prepare: creating directory /var/spool/amavisd/tmp/amavis-20090601T183127-30956 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) TempDir::prepare_file: creating file /var/spool/amavisd/tmp/amavis-20090601T183127-30956/email.txt Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) TempDir::prepare_file: layers: unix,perlio Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_ip_acl (mynetworks): key="137.208.16.200" matches "137.208.0.0/16", result=1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) loaded policy bank "MYNETS" over "STRIKE" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (debug_sender) => undef, "trinas@zdnetasia.com" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250 2.1.0 Sender OK Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 6: was busy, 2.8 ms, total idle 0.000 s, busy 0.009 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.009 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP< RCPT TO: ORCPT=rfc822;e.mohn@nowhere.at\r\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, SMTP RCPT received Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_acl(e.mohn@nowhere.at) matches key ".nowhere.at", result=1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (local_domains) => true, "e.mohn@nowhere.at" matches, result="1", matching_key=".nowhere.at" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn, @nowhere.at, @.nowhere.at, @.at, @. Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql "e.mohn@nowhere.at", query args: "e.mohn@nowhere.at", "e.mohn", "@nowhere.at", "@.nowhere.at", "@.at", "@." Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql select: SELECT *, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin, nontransaction Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Connecting to SQL database server Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) connect_to_sql: trying 'DBI:mysql:database=amavis;host=127.0.0.1' Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) connect_to_sql: 'DBI:mysql:database=amavis;host=127.0.0.1' succeeded Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: preparing and executing: SELECT *, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql, "e.mohn@nowhere.at" no match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(message_size_limit), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (message_size_limit) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250 2.1.5 Recipient OK Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 6: was busy, 4.6 ms, total idle 0.001 s, busy 0.013 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.013 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP< DATA\r\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, SMTP DATA received Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP:[127.0.0.1]:10024 /var/spool/amavisd/tmp/amavis-20090601T183127-30956: -> SIZE=2671 Received: from strike.wu.ac.at ([127.0.0.1]) by localhost (strike.wu-wien.ac.at [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for ; Mon, 1 Jun 2009 18:31:27 +0200 (CEST) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 354 End data with . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, receiving data Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, data-end received Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP< . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Actual message size 2854 B greater than the declared 2671 B Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(local), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_acl(e.mohn@nowhere.at) matches key ".nowhere.at", result=1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (local_domains) => true, "e.mohn@nowhere.at" matches, result="1", matching_key=".nowhere.at" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) body type: unlabeled, good (h=0, b=0) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) body hash: 985bfa1a12e31d837c517d5723396ee1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Original mail size: 2854; quota set to: 1427000 bytes Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin, nontransaction Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: preparing and executing: SELECT id FROM maddr WHERE email=? Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin, nontransaction Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: preparing and executing: INSERT INTO maddr (email, domain) VALUES (?,?) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin, nontransaction Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: executing clause: SELECT id FROM maddr WHERE email=? Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) find_or_save_addr: record inserted, id=1191500, trinas@zdnetasia.com Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) save_info_preliminary: 1191500, trinas@zdnetasia.com, new Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin, nontransaction Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: executing clause: SELECT id FROM maddr WHERE email=? Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) save_info_preliminary TDQdyV5IK8QS, recip id: 425, e.mohn@nowhere.at, exists Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin transaction Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: preparing and executing: INSERT INTO msgs (mail_id, secret_id, am_id, time_num, time_iso, sid, policy, client_addr, size, host) VALUES (?,?,?,?,?,?,?,?,?,?) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql commit Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Checking: TDQdyV5IK8QS STRIKE/MYNETS [137.208.16.200] -> Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) 2822.From: Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_virus_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_virus_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Extracting mime components Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Issued a new file name: p001 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Issued a new file name: p002 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) mime_decode_preamble: 2 lines Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Issued a new pseudo part: p003 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) p003 1 Content-Type: multipart/alternative Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) mime_decode_epilogue: 1 lines Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Charging 390 bytes to remaining quota 1427000 (out of 1427000, (0%)) - by mime_decode Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) p001 1/1 Content-Type: text/plain, size: 390 B, name: Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) reparenting p001 from p000 to p003 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Charging 1093 bytes to remaining quota 1426610 (out of 1427000, (0%)) - by mime_decode Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) p002 1/2 Content-Type: text/html, size: 1093 B, name: Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) reparenting p002 from p000 to p003 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer mime_decode: remaining time = 90 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer mime_decode-1: remaining time = 90 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) decode_parts: level=1, #parts=3 : p001, p002, p003 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) run_command: [30962] /usr/bin/file p001 p002 &1 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) result line from file(1): p001: ASCII English text\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_re("ASCII English text") matches key "(?i-xsm:^(ASCII|text)\b)", result="asc" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (map_full_type_to_short_type) => true, "ASCII English text" matches, result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) File-type of p001: ASCII English text; (asc) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) result line from file(1): p002: HTML document text\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_re("HTML document text") matches key "(?-xism:^HTML document text\b)", result="html" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (map_full_type_to_short_type) => true, "HTML document text" matches, result="html", matching_key="(?-xism:^HTML document text\\b)" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) File-type of p002: HTML document text; (html) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) do_ascii: Decoding part p001 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) do_ascii: Setting sigaction handler, was 0 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) timer set to 60 s (was 90 s) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) do_ascii: Decoding part p001 (0 items), uulib V0.5pl20 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer do_ascii: timer set to 90 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) decompose_part: p001 - atomic Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) decompose_part: p002 - atomic Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer parts_decode: remaining time = 90 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_header_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_header_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) check_header: 0, OK Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_header_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_header_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Checking for banned types and filenames Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_banned_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_banned_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(banned_rulenames), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="DEFAULT" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (banned_filename), 1 matches for "e.mohn@nowhere.at", results: "(constant:DEFAULT)"=>"DEFAULT" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) collect banned table[0]: e.mohn@nowhere.at, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x9f599bc) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) starting banned checks - traversing message structure tree Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) check_for_banned (p003,p001) multipart/alternative | text/plain,.asc Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) doing banned check for e.mohn@nowhere.at on multipart/alternative | text/plain,.asc Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_re(["multipart/alternative","text/plain",".asc"]), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (check_bann:e.mohn@nowhere.at) => undef, ["multipart/alternative","text/plain",".asc"] does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) p.path e.mohn@nowhere.at: "P=p003,L=1,M=multipart/alternative | P=p001,L=1/1,M=text/plain,T=asc" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) check_for_banned (p003,p002) multipart/alternative | text/html,.html Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) doing banned check for e.mohn@nowhere.at on multipart/alternative | text/html,.html Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_re(["multipart/alternative","text/html",".html"]), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (check_bann:e.mohn@nowhere.at) => undef, ["multipart/alternative","text/html",".html"] does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) p.path e.mohn@nowhere.at: "P=p003,L=1,M=multipart/alternative | P=p002,L=1/2,M=text/html,T=html" Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) banned check: any=0, all=N (1) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_re("MAIL"), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (keep_decoded_original) => undef, "MAIL" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Using AVG Anti-Virus: (built-in interface) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) timer set to 60 s (was 90 s) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ask_av (AVG Anti-Virus): query template1: SCAN {}\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Using (AVG Anti-Virus) on dir: SCAN /var/spool/amavisd/tmp/amavis-20090601T183127-30956/parts\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) timer set to 10 s (was 60 s) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) AVG Anti-Virus: Connecting to socket 127.0.0.1:55555 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) AVG Anti-Virus: Sending SCAN /var/spool/amavisd/tmp/amavis-20090601T183127-30956/parts\n to INET socket 127.0.0.1:55555 Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer ask_daemon_internal: timer set to 48 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ask_av (AVG Anti-Virus) result: 220-AVG7 Anti-Virus daemon mode scanner\r\n220-Program version 7.5.51, engine 442\r\n220-Virus Database: Version 270.12.36/2126 2009-05-21\r\n220 Ready\r\n200 OK\r\n Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ask_av (AVG Anti-Virus): /var/spool/amavisd/tmp/amavis-20090601T183127-30956/parts CLEAN Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) AVG Anti-Virus result: clean Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer run_av: timer set to 90 s Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_virus_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_virus_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_spam_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_spam_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) wbl: checking sender Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(id), "e.mohn@nowhere.at" no matching records Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) wbl: (SQL) recip , 0 matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (blacklist_recip) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: trinas@zdnetasia.com, trinas@, zdnetasia.com, .zdnetasia.com, .com, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(trinas@zdnetasia.com), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (blacklist_sender) => undef, "trinas@zdnetasia.com" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (whitelist_recip) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: trinas@zdnetasia.com, trinas@, zdnetasia.com, .zdnetasia.com, .com, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(trinas@zdnetasia.com), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (whitelist_sender) => undef, "trinas@zdnetasia.com" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at) matches keys: "."=>ARRAY(0x9f59f8c) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (score_sender), 1 matches for "e.mohn@nowhere.at", results: "."=>[Amavis::Lookup::RE=ARRAY(0x9f59ccc),HASH(0x9f59d5c)] Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_re("trinas@zdnetasia.com"), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: trinas@zdnetasia.com, trinas@, zdnetasia.com, .zdnetasia.com, .com, . Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(trinas@zdnetasia.com), no matches Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (score_sender) => undef, "trinas@zdnetasia.com" does not match Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) SpamControl: calling spam scanner Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) spam_scan: DSPAM not available, skipping it Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) timer set to 60 s for SA (was 90 s) Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) calling SA parse, SA version 3.2.5, 3.002005, data as GLOB [30956] dbg: dns: name server: 137.208.3.3, LocalAddr: 0.0.0.0 [30956] dbg: dns: resolver socket rx buffer size is 111616 bytes [30956] dbg: message: main message type: multipart/alternative Jun 1 18:31:27 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) CALLING SA check [30956] dbg: conf: internal_networks not configured, using trusted_networks configuration for internal_networks; if you really want internal_networks to only contain the required 127/8 add 'internal_networks !0/0' to your configuration [30956] dbg: received-header: parsed as [ ip=137.208.16.200 rdns=monty.wu-wien.ac.at helo=monty.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=0 id= auth= msa=0 ] [30956] dbg: received-header: relay 137.208.16.200 trusted? yes internal? yes msa? no [30956] dbg: received-header: parsed as [ ip=88.228.174.25 rdns= helo=dsl.dynamic8599137161.ttnet.net.tr by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=09AAAE000D4 auth= msa=0 ] [30956] dbg: received-header: relay 88.228.174.25 trusted? no internal? no msa? no [30956] dbg: metadata: X-Spam-Relays-Trusted: [ ip=137.208.16.200 rdns=monty.wu-wien.ac.at helo=monty.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=1 id= auth= msa=0 ] [30956] dbg: metadata: X-Spam-Relays-Untrusted: [ ip=88.228.174.25 rdns= helo=dsl.dynamic8599137161.ttnet.net.tr by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=09AAAE000D4 auth= msa=0 ] [30956] dbg: metadata: X-Spam-Relays-Internal: [ ip=137.208.16.200 rdns=monty.wu-wien.ac.at helo=monty.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=1 id= auth= msa=0 ] [30956] dbg: metadata: X-Spam-Relays-External: [ ip=88.228.174.25 rdns= helo=dsl.dynamic8599137161.ttnet.net.tr by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=09AAAE000D4 auth= msa=0 ] [30956] dbg: message: ---- MIME PARSER START ---- [30956] dbg: message: parsing multipart, got boundary: ----=_NextPart_000_0023_A0_01C9E2F2.1A7E225D [30956] dbg: message: found part of type text/plain, boundary: ----=_NextPart_000_0023_A0_01C9E2F2.1A7E225D [30956] dbg: message: added part, type: text/plain [30956] dbg: message: found part of type text/html, boundary: ----=_NextPart_000_0023_A0_01C9E2F2.1A7E225D [30956] dbg: message: added part, type: text/html [30956] dbg: message: parsing normal part [30956] dbg: message: parsing normal part [30956] dbg: message: ---- MIME PARSER END ---- [30956] dbg: message: decoding quoted-printable [30956] dbg: message: decoding quoted-printable [30956] dbg: uridnsbl: domains to query: okayback.com [30956] dbg: async: starting: URI-DNSBL, DNSBL:multi.surbl.org.:okayback.com (timeout 15.0s, min 3.0s) [30956] dbg: dns: URIBL_PH_SURBL lookup start [30956] dbg: async: starting: URI-DNSBL, DNSBL:multi.uribl.com.:okayback.com (timeout 15.0s, min 3.0s) [30956] dbg: dns: URIBL_BLACK lookup start [30956] dbg: dns: URIBL_RED lookup start [30956] dbg: dns: URIBL_GREY lookup start [30956] dbg: async: starting: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:okayback.com (timeout 15.0s, min 3.0s) [30956] dbg: dns: URIBL_RHS_DOB lookup start [30956] dbg: dns: URIBL_SC_SURBL lookup start [30956] dbg: dns: URIBL_AB_SURBL lookup start [30956] dbg: dns: URIBL_JP_SURBL lookup start [30956] dbg: dns: URIBL_WS_SURBL lookup start [30956] dbg: dns: URIBL_OB_SURBL lookup start [30956] dbg: async: starting: URI-NS, NS:okayback.com (timeout 15.0s, min 3.0s) [30956] dbg: dns: URIBL_SBL lookup start [30956] dbg: dns: checking RBL sa-other.bondedsender.org., set bsp-untrusted [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: [30956] dbg: dns: checking RBL plus.bondedsender.org., set ssc-firsttrusted [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.plus.bondedsender.org. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.plus.bondedsender.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL combined.njabl.org., set njabl [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.combined.njabl.org. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.combined.njabl.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL bl.spamcop.net., set spamcop [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS TXT query for 25.174.228.88.bl.spamcop.net. in background [30956] dbg: async: starting: DNSBL-TXT, dns:TXT:25.174.228.88.bl.spamcop.net. (timeout 15.0s, min 3.0s) [30956] dbg: dns: _check_rbl_addresses RBL rhsbl.ahbl.org., set ahbl [30956] dbg: dns: launching DNS A query for zdnetasia.com.rhsbl.ahbl.org. in background [30956] dbg: async: starting: DNSBL-A, dns:A:zdnetasia.com.rhsbl.ahbl.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking A and MX for host zdnetasia.com [30956] dbg: dns: launching DNS A query for zdnetasia.com in background [30956] dbg: async: starting: NO_DNS_FOR_FROM, DNSBL-A, dns:A:zdnetasia.com (timeout 15.0s, min 3.0s) [30956] dbg: dns: launching DNS MX query for zdnetasia.com in background [30956] dbg: async: starting: NO_DNS_FOR_FROM, DNSBL-MX, dns:MX:zdnetasia.com (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.zen.spamhaus.org. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.zen.spamhaus.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs-lastexternal [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.dnsbl.sorbs.net. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.dnsbl.sorbs.net. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: checking RBL list.dnswl.org., set dnswl-firsttrusted [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.list.dnswl.org. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.list.dnswl.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL sa-accredit.habeas.com., set habeas-firsttrusted [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.sa-accredit.habeas.com. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.sa-accredit.habeas.com. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL sa-trusted.bondedsender.org., set bsp-firsttrusted [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS TXT query for 25.174.228.88.sa-trusted.bondedsender.org. in background [30956] dbg: async: starting: DNSBL-TXT, dns:TXT:25.174.228.88.sa-trusted.bondedsender.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL zen.spamhaus.org., set zen [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: _check_rbl_addresses RBL fulldom.rfc-ignorant.org., set rfci_envfrom [30956] dbg: dns: launching DNS A query for zdnetasia.com.fulldom.rfc-ignorant.org. in background [30956] dbg: async: starting: DNSBL-A, dns:A:zdnetasia.com.fulldom.rfc-ignorant.org. (timeout 15.0s, min 3.0s) [30956] dbg: dns: checking RBL iadb.isipp.com., set iadb-firsttrusted [30956] dbg: dns: IPs found: full-external: 88.228.174.25 untrusted: 88.228.174.25 originating: [30956] dbg: dns: only inspecting the following IPs: 88.228.174.25 [30956] dbg: dns: launching DNS A query for 25.174.228.88.iadb.isipp.com. in background [30956] dbg: async: starting: DNSBL-A, dns:A:25.174.228.88.iadb.isipp.com. (timeout 15.0s, min 3.0s) [30956] dbg: check: running tests for priority: -1000 [30956] dbg: dns: hit 202.176.217.12 [30956] dbg: async: select found 3 responses ready (t.o.=0.0) [30956] dbg: async: completed in 0.002 s: DNSBL-A, dns:A:zdnetasia.com.fulldom.rfc-ignorant.org. [30956] dbg: async: completed in 0.006 s: DNSBL-A, dns:A:zdnetasia.com.rhsbl.ahbl.org. [30956] dbg: async: completed in 0.006 s: NO_DNS_FOR_FROM, DNSBL-A, dns:A:zdnetasia.com [30956] dbg: async: queries completed: 3, started: 0 [30956] dbg: async: queries active: DNSBL-A=7 DNSBL-MX=1 DNSBL-TXT=2 URI-DNSBL=3 URI-NS=1 at Mon Jun 1 18:31:27 2009 [30956] dbg: dns: harvested completed queries [30956] dbg: rules: running head tests; score so far=0 [30956] dbg: eval: all '*From' addrs: trinas@zdnetasia.com [30956] dbg: eval: all '*To' addrs: e.mohn@nowhere.at [30956] dbg: rules: running body tests; score so far=0 [30956] dbg: rules: running uri tests; score so far=0 [30956] dbg: rules: running rawbody tests; score so far=0 [30956] dbg: rules: running full tests; score so far=0 [30956] dbg: rules: running meta tests; score so far=0 [30956] dbg: check: running tests for priority: -950 [30956] dbg: rules: running head tests; score so far=0 [30956] dbg: rules: running body tests; score so far=0 [30956] dbg: rules: running uri tests; score so far=0 [30956] dbg: rules: running rawbody tests; score so far=0 [30956] dbg: rules: running full tests; score so far=0 [30956] dbg: rules: running meta tests; score so far=0 [30956] dbg: check: running tests for priority: -900 [30956] dbg: rules: running head tests; score so far=0 [30956] dbg: rules: running body tests; score so far=0 [30956] dbg: rules: running uri tests; score so far=0 [30956] dbg: rules: running rawbody tests; score so far=0 [30956] dbg: rules: running full tests; score so far=0 [30956] dbg: rules: running meta tests; score so far=0 [30956] dbg: check: running tests for priority: -400 [30956] dbg: rules: running head tests; score so far=0 [30956] dbg: rules: running body tests; score so far=0 [30956] dbg: rules: running uri tests; score so far=0 [30956] dbg: plugin: Mail::SpamAssassin::Plugin::WLBLEval=HASH(0xb882a64) implements 'check_wb_list', priority 0 [30956] dbg: bayes: database connection established [30956] dbg: bayes: found bayes db version 3 [30956] dbg: bayes: Using userid: 1 [30956] dbg: bayes: corpus size: nspam = 1462386, nham = 369935 [30956] dbg: bayes: tok_get_all: token count: 160 [30956] dbg: bayes: score = 1 [30956] dbg: rules: ran eval rule BAYES_99 ======> got hit (1) [30956] dbg: rules: running rawbody tests; score so far=4 [30956] dbg: rules: running full tests; score so far=4 [30956] dbg: rules: running meta tests; score so far=4 [30956] dbg: check: running tests for priority: 0 [30956] dbg: rules: running head tests; score so far=4 [30956] dbg: rules: ran header rule __CT ======> got hit: "m" [30956] dbg: rules: ran header rule __CTYPE_MULTIPART_ALT ======> got hit: "multipart/alternative" [30956] dbg: rules: ran header rule __CTYPE_HAS_BOUNDARY ======> got hit: "boundary" [30956] dbg: rules: ran header rule __RDNS_NONE ======> got hit: "[ ip=88.228.174.25 rdns= " [30956] dbg: rules: ran header rule __LAST_UNTRUSTED_RELAY_NO_AUTH ======> got hit: "[ ip=88.228.174.25 rdns= helo=dsl.dynamic8599137161.ttnet.net.tr by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=09AAAE000D4 auth= " [30956] dbg: rules: ran header rule __MISSING_REF ======> got hit: "UNSET" [30956] dbg: rules: ran header rule __MIME_VERSION ======> got hit: "1" [30956] dbg: rules: ran header rule __TOCC_EXISTS ======> got hit: "<" [30956] dbg: rules: ran header rule __HDR_ORDER_FTSDMCXXXX ======> got hit: " [30956] dbg: rules: From: "Adan Caldwell" [30956] dbg: rules: To: [30956] dbg: rules: Subject: Swiss Branded Watches [30956] dbg: rules: Date: Mon, 01 Jun 2009 19:31:33 +0300 [30956] dbg: rules: MIME-Version: 1.0 [30956] dbg: rules: Content-Type: multipart/alternative; boundary="----=_NextPart_000_0023_A0_01C9E2F2.1A7E225D" [30956] dbg: rules: X-Priority: 3 [30956] dbg: rules: X-MSMail-Priority: Normal [30956] dbg: rules: X-Mailer: Microsoft Outlook Express 6.00.2900.2180 [30956] dbg: rules: X-MimeOLE:" [30956] dbg: rules: ran header rule __SARE_WHITELIST_FLAG ======> got hit: """ [30956] dbg: rules: ran header rule __FH_HAS_XMSMAIL ======> got hit: "N" [30956] dbg: rules: ran header rule __XM_MS_IN_GENERAL ======> got hit: "Microsoft Outlook" [30956] dbg: rules: ran header rule __ANY_OUTLOOK_MUA ======> got hit: "Microsoft Outlook" [30956] dbg: rules: ran header rule __OE_MUA ======> got hit: "Outlook Express 6." [30956] dbg: rules: ran header rule __XM_MSOE6 ======> got hit: "Microsoft Outlook Express 6" [30956] dbg: rules: ran header rule __XM_OUTLOOK_EXPRESS ======> got hit: "Microsoft Outlook Express 6" [30956] dbg: rules: ran header rule __HAS_X_MAILER ======> got hit: "M" [30956] dbg: rules: ran header rule __SARE_HEAD_MIME_VALID ======> got hit: "1.0" [30956] dbg: rules: ran header rule __DOS_SINGLE_EXT_RELAY ======> got hit: "[ ip=88.228.174.25 rdns= helo=dsl.dynamic8599137161.ttnet.net.tr by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=09AAAE000D4 auth= msa=0 ]" [30956] dbg: rules: ran header rule __FH_HAS_XPRIORITY ======> got hit: "3" [30956] dbg: rules: ran header rule __HAS_RCVD ======> got hit: "f" [30956] dbg: rules: ran header rule __DOS_RCVD_MON ======> got hit: " Mon, " [30956] dbg: rules: ran header rule __MSGID_OK_HOST ======> got hit: "@zdnetasia.com>" [30956] dbg: rules: ran header rule __MSGID_OK_HEX ======> got hit: "66fe9bc0" [30956] dbg: rules: ran header rule __MSGID_RANDY ======> got hit: "<6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com>" [30956] dbg: rules: ran header rule __MIMEOLE_MS ======> got hit: "Produced By Microsoft MimeOLE" [30956] dbg: rules: ran header rule __HAS_MSGID ======> got hit: "<" [30956] dbg: rules: ran header rule __SANE_MSGID ======> got hit: "<6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com> [30956] dbg: rules: " [30956] dbg: rules: ran header rule __MSGID_DOLLARS_MAYBE ======> got hit: "<6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com>" [30956] dbg: rules: ran header rule __MSGID_DOLLARS_OK ======> got hit: "<6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com>" [30956] dbg: rules: ran header rule __OE_MSGID_2 ======> got hit: "<6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com>" [30956] dbg: rules: ran header rule __HAS_SUBJECT ======> got hit: "S" [30956] dbg: rules: ran header rule __SARE_SPEC_WATCH_SUBJ ======> got hit: "Watch" [30956] dbg: rules: ran header rule __SARE_SPEC_SUBJ_LEO ======> got hit: "Swiss Branded Watches [30956] dbg: rules: " [30956] dbg: rules: ran header rule __HAS_MIMEOLE ======> got hit: "P" [30956] dbg: spf: checking to see if the message has a Received-SPF header that we can use [30956] dbg: spf: checking HELO (helo=dsl.dynamic8599137161.ttnet.net.tr, ip=88.228.174.25) [30956] dbg: spf: query for /88.228.174.25/dsl.dynamic8599137161.ttnet.net.tr: result: none, comment: , text: No applicable sender policy available [30956] dbg: dkim: performing public key lookup and signature verification [30956] dbg: dkim: signature verification result: none [30956] dbg: dkim: author trinas@zdnetasia.com, not in any dkim whitelist [30956] dbg: spf: already checked for Received-SPF headers, proceeding with DNS based checks [30956] dbg: spf: relayed through one or more trusted relays, cannot use header-based Envelope-From, skipping [30956] dbg: dkim: policy: performing lookup [30956] dbg: dkim: policy result neutral: o=~ [30956] dbg: rules: ran eval rule __ENV_AND_HDR_FROM_MATCH ======> got hit (1) [30956] dbg: spf: def_spf_whitelist_from: already checked spf and didn't get pass, skipping whitelist check [30956] dbg: spf: whitelist_from_spf: already checked spf and didn't get pass, skipping whitelist check [30956] dbg: dns: hit 127.0.0.10 [30956] dbg: dns: hit 100 c12-mail.cnet.com. [30956] dbg: dns: hit 500 c18-mail.cnet.com. [30956] dbg: async: select found 9 responses ready (t.o.=0.0) [30956] dbg: async: completed in 0.782 s: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:okayback.com [30956] dbg: async: completed in 0.773 s: DNSBL-A, dns:A:25.174.228.88.sa-accredit.habeas.com. [30956] dbg: async: completed in 0.779 s: DNSBL-TXT, dns:TXT:25.174.228.88.bl.spamcop.net. [30956] dbg: async: completed in 0.773 s: DNSBL-A, dns:A:25.174.228.88.iadb.isipp.com. [30956] dbg: async: completed in 0.773 s: DNSBL-A, dns:A:25.174.228.88.zen.spamhaus.org. [30956] dbg: async: completed in 0.574 s: URI-DNSBL, DNSBL:multi.uribl.com.:okayback.com [30956] dbg: uridnsbl: domain "okayback.com" listed (URIBL_BLACK): 127.0.0.2 [30956] dbg: dns: URIBL_BLACK lookup finished [30956] dbg: async: completed in 0.777 s: DNSBL-A, dns:A:25.174.228.88.combined.njabl.org. [30956] dbg: async: completed in 0.778 s: DNSBL-A, dns:A:25.174.228.88.plus.bondedsender.org. [30956] dbg: async: completed in 0.573 s: URI-DNSBL, DNSBL:multi.surbl.org.:okayback.com [30956] dbg: uridnsbl: domain "okayback.com" listed (URIBL_AB_SURBL): 127.0.0.112 [30956] dbg: dns: URIBL_AB_SURBL lookup finished [30956] dbg: uridnsbl: domain "okayback.com" listed (URIBL_JP_SURBL): 127.0.0.112 [30956] dbg: dns: URIBL_JP_SURBL lookup finished [30956] dbg: uridnsbl: domain "okayback.com" listed (URIBL_OB_SURBL): 127.0.0.112 [30956] dbg: dns: URIBL_OB_SURBL lookup finished [30956] dbg: async: completed in 0.571 s: DNSBL-A, dns:A:25.174.228.88.list.dnswl.org. [30956] dbg: async: completed in 0.772 s: DNSBL-TXT, dns:TXT:25.174.228.88.sa-trusted.bondedsender.org. [30956] dbg: async: completed in 0.776 s: NO_DNS_FOR_FROM, DNSBL-MX, dns:MX:zdnetasia.com [30956] dbg: async: completed in 0.570 s: DNSBL-A, dns:A:25.174.228.88.dnsbl.sorbs.net. [30956] dbg: async: queries completed: 13, started: 0 [30956] dbg: async: queries active: URI-NS=1 at Mon Jun 1 18:31:28 2009 [30956] dbg: dns: harvested completed queries [30956] dbg: rules: running body tests; score so far=11.721 [30956] dbg: rules: ran body rule SARE_SPEC_REPLICA_OBFU ======> got hit: "replica" [30956] dbg: rules: ran body rule __FB_WALLETS ======> got hit: "Wallets" [30956] dbg: rules: ran body rule __SEEK_RUB3_U ======> got hit: "Courier delivery right to your doorstep - don't wait, purchase before they are all sold out! Browse our shop" [30956] dbg: rules: ran body rule __SARE_SPEC_WATCH_BODY ======> got hit: "Watch" [30956] dbg: rules: ran body rule __SEEK_WUDYUX ======> got hit: "We carry the entire range of models, including brands:" [30956] dbg: rules: ran body rule __SARE_SPEC_ROLEX_REP1 ======> got hit: "Rolex replica" [30956] dbg: rules: ran body rule __SARE_SPEC_ROLEX_BODY ======> got hit: "Rolex" [30956] dbg: rules: ran body rule __NONEMPTY_BODY ======> got hit: "S" [30956] dbg: rules: ran body rule __SEEK_5DZDOH ======> got hit: " Louis Vuitton Bags & Wallets" [30956] dbg: rules: ran body rule __SEEK_GPRBUZ ======> got hit: "Chanel Rolex Sports Models Bell& Ross Tiffany& Co Jewelry Louis Vuitton Bags& Wallets and all starting from unbelievably low prices." [30956] dbg: rules: ran body rule __SEEK_IK5UYS ======> got hit: "Limited release of 2009 Rolex replica models - Swiss quality, blow-out sale prices!" [30956] dbg: rules: ran body rule __FB_S_PRICE ======> got hit: "price" [30956] dbg: rules: running uri tests; score so far=13.533 [30956] dbg: rules: ran uri rule __DOS_HAS_ANY_URI ======> got hit: "h" [30956] dbg: rules: ran uri rule __LOCAL_PP_NONPPURL ======> got hit: "http://okayback.com" [30956] dbg: rules: ran eval rule __HTML_LENGTH_1024_1536 ======> got hit (1) [30956] dbg: rules: ran eval rule __MIME_HTML ======> got hit (1) [30956] dbg: rules: ran eval rule HTML_MESSAGE ======> got hit (1) [30956] dbg: eval: stock info total: 0 [30956] dbg: rules: ran eval rule __TAG_EXISTS_HTML ======> got hit (1) [30956] dbg: rules: ran eval rule __SARE_BODY_BLANKS_5_100 ======> got hit (1) [30956] dbg: rules: ran eval rule __TAG_EXISTS_BODY ======> got hit (1) [30956] dbg: eval: text words: 56, html words: 56 [30956] dbg: eval: madiff: left: 3, orig: 56, max-difference: 5.36% [30956] dbg: rules: ran eval rule __TVD_MIME_ATT_TP ======> got hit (1) [30956] dbg: rules: ran eval rule __TAG_EXISTS_HEAD ======> got hit (1) [30956] dbg: rules: ran eval rule __TAG_EXISTS_META ======> got hit (1) [30956] dbg: rules: running rawbody tests; score so far=13.534 [30956] dbg: rules: ran rawbody rule __MY_CLOSING ======> got hit: "" [30956] dbg: rules: ran rawbody rule __SARE_WHITE_BG_COLOR ======> got hit: "bgColor=#ffffff" [30956] dbg: rules: ran rawbody rule __SARE_HAS_BG_COLOR ======> got hit: "bgColor=" [30956] dbg: rules: ran rawbody rule __TVD_BODY ======> got hit: "Limi" [30956] dbg: rules: ran rawbody rule __MY_STYLE ======> got hit: "" [30956] dbg: rules: ran rawbody rule __SARE_HAS_FG_COLOR ======> got hit: " color=" [30956] dbg: rules: ran rawbody rule __MY_ARIAL2 ======> got hit: "face=Arial size=2>" [30956] dbg: rules: ran eval rule __SARE_HTML_HAS_BR ======> got hit (1) [30956] dbg: rules: ran eval rule __SARE_HTML_HAS_A ======> got hit (1) [30956] dbg: rules: ran eval rule __SARE_HTML_HAS_FONT ======> got hit (1) [30956] dbg: rules: ran eval rule __SARE_HTML_HAS_DIV ======> got hit (1) [30956] dbg: rules: ran eval rule __MIME_QP ======> got hit (2) [30956] dbg: rules: running full tests; score so far=13.534 [30956] dbg: info: entering helper-app run mode [30956] dbg: info: leaving helper-app run mode [30956] dbg: razor2: part=0 engine=4 contested=0 confidence=100 [30956] dbg: razor2: part=1 engine=4 contested=0 confidence=0 [30956] dbg: razor2: part=1 engine=8 contested=0 confidence=100 [30956] dbg: razor2: results: spam? 1 [30956] dbg: razor2: results: engine 8, highest cf score: 100 [30956] dbg: razor2: results: engine 4, highest cf score: 100 [30956] dbg: rules: ran eval rule RAZOR2_CF_RANGE_E8_51_100 ======> got hit (1) [30956] dbg: rules: ran eval rule RAZOR2_CHECK ======> got hit (1) [30956] dbg: rules: ran eval rule RAZOR2_CF_RANGE_E4_51_100 ======> got hit (1) [30956] dbg: rules: ran eval rule RAZOR2_CF_RANGE_51_100 ======> got hit (1) [30956] dbg: pyzor: pyzor is not available: no pyzor executable found [30956] dbg: pyzor: no pyzor found, disabling Pyzor [30956] dbg: dcc: dccifd is not available: no r/w dccifd socket found [30956] dbg: dcc: dccproc is not available: no dccproc executable found [30956] dbg: dcc: dccifd and dccproc are not available, disabling DCC [30956] dbg: async: select found 1 responses ready (t.o.=0.0) [30956] dbg: async: completed in 1.335 s: URI-NS, NS:okayback.com [30956] dbg: async: starting: URI-A, A:ns1.okayback.com. (timeout 15.0s, min 3.0s) [30956] dbg: async: starting: URI-A, A:ns2.okayback.com. (timeout 15.0s, min 3.0s) [30956] dbg: async: queries completed: 1, started: 2 [30956] dbg: async: queries active: URI-A=2 at Mon Jun 1 18:31:29 2009 [30956] dbg: dns: harvested completed queries [30956] dbg: rules: running meta tests; score so far=17.534 [30956] dbg: check: running tests for priority: 500 [30956] dbg: dns: harvest_dnsbl_queries [30956] dbg: async: select found 2 responses ready (t.o.=0.0) [30956] dbg: async: completed in 0.001 s: URI-A, A:ns1.okayback.com. [30956] dbg: async: starting: URI-DNSBL, DNSBL:sbl.spamhaus.org.:170.72.67.119 (timeout 15.0s, min 3.0s) [30956] dbg: async: completed in 0.001 s: URI-A, A:ns2.okayback.com. [30956] dbg: async: queries completed: 2, started: 1 [30956] dbg: async: queries active: URI-DNSBL=1 at Mon Jun 1 18:31:29 2009 [30956] dbg: dns: harvest_dnsbl_queries - check_tick [30956] dbg: async: select found 1 responses ready (t.o.=1.0) [30956] dbg: async: completed in 0.001 s: URI-DNSBL, DNSBL:sbl.spamhaus.org.:170.72.67.119 [30956] dbg: uridnsbl: domain "okayback.com" listed (URIBL_SBL): "http://www.spamhaus.org/SBL/sbl.lasso?query=SBL76156" [30956] dbg: dns: URIBL_SBL lookup finished [30956] dbg: async: timing: 0.001 . DNSBL:sbl.spamhaus.org.:170.72.67.119 [30956] dbg: async: timing: 0.001 . A:ns2.okayback.com. [30956] dbg: async: timing: 0.001 . A:ns1.okayback.com. [30956] dbg: async: timing: 0.002 . dns:A:zdnetasia.com.fulldom.rfc-ignorant.org. [30956] dbg: async: timing: 0.006 . dns:A:zdnetasia.com.rhsbl.ahbl.org. [30956] dbg: async: timing: 0.006 . dns:A:zdnetasia.com [30956] dbg: async: timing: 0.570 . dns:A:25.174.228.88.dnsbl.sorbs.net. [30956] dbg: async: timing: 0.571 . dns:A:25.174.228.88.list.dnswl.org. [30956] dbg: async: timing: 0.573 . DNSBL:multi.surbl.org.:okayback.com [30956] dbg: async: timing: 0.574 . DNSBL:multi.uribl.com.:okayback.com [30956] dbg: async: timing: 0.772 . dns:TXT:25.174.228.88.sa-trusted.bondedsender.org. [30956] dbg: async: timing: 0.773 . dns:A:25.174.228.88.zen.spamhaus.org. [30956] dbg: async: timing: 0.773 . dns:A:25.174.228.88.sa-accredit.habeas.com. [30956] dbg: async: timing: 0.773 . dns:A:25.174.228.88.iadb.isipp.com. [30956] dbg: async: timing: 0.776 . dns:MX:zdnetasia.com [30956] dbg: async: timing: 0.777 . dns:A:25.174.228.88.combined.njabl.org. [30956] dbg: async: timing: 0.778 . dns:A:25.174.228.88.plus.bondedsender.org. [30956] dbg: async: timing: 0.779 . dns:TXT:25.174.228.88.bl.spamcop.net. [30956] dbg: async: timing: 0.782 . DNSBL:dob.sibl.support-intelligence.net:okayback.com [30956] dbg: async: timing: 1.335 . NS:okayback.com [30956] dbg: rules: running head tests; score so far=19.033 [30956] dbg: rules: running body tests; score so far=19.033 [30956] dbg: rules: running uri tests; score so far=19.033 [30956] dbg: rules: running rawbody tests; score so far=19.033 [30956] dbg: rules: running full tests; score so far=19.033 [30956] dbg: rules: running meta tests; score so far=19.033 [30956] dbg: check: running tests for priority: 1000 [30956] dbg: rules: running head tests; score so far=30.215 [30956] dbg: auto-whitelist: sql-based connected to DBI:mysql:spamassassin:127.0.0.1 [30956] dbg: auto-whitelist: sql-based using username: amavis [30956] dbg: auto-whitelist: sql-based get_addr_entry: no entry found for trinas@zdnetasia.com|ip=88.228 [30956] dbg: auto-whitelist: sql-based trinas@zdnetasia.com|ip=88.228 scores 0/0 [30956] dbg: auto-whitelist: sql-based get_addr_entry: no entry found for trinas@zdnetasia.com|ip=none [30956] dbg: auto-whitelist: sql-based trinas@zdnetasia.com|ip=none scores 0/0 [30956] dbg: auto-whitelist: AWL active, pre-score: 30.215, autolearn score: 30.215, mean: undef, IP: 88.228.174.25 [30956] dbg: auto-whitelist: sql-based add_score: created new entry for trinas@zdnetasia.com|ip=88.228 with totscore: 30.215 [30956] dbg: auto-whitelist: sql-based finish: disconnected from DBI:mysql:spamassassin:127.0.0.1 [30956] dbg: auto-whitelist: post auto-whitelist score: 30.215 [30956] dbg: rules: running body tests; score so far=30.215 [30956] dbg: rules: running uri tests; score so far=30.215 [30956] dbg: rules: running rawbody tests; score so far=30.215 [30956] dbg: rules: running full tests; score so far=30.215 [30956] dbg: rules: running meta tests; score so far=30.215 [30956] dbg: plugin: Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0xb894c2c) implements 'autolearn_discriminator', priority 0 [30956] dbg: learn: auto-learn: currently using scoreset 3, recomputing score based on scoreset 1 [30956] dbg: learn: auto-learn: message score: 30.215, computed score for autolearn: 28.535 [30956] dbg: learn: auto-learn? ham=0.1, spam=9, body-points=28.535, head-points=28.535, learned-points=4 [30956] dbg: learn: auto-learn? yes, spam (28.535 > 9) [30956] dbg: learn: initializing learner [30956] dbg: learn: learning spam [30956] dbg: eval: all '*From' addrs: trinas@zdnetasia.com [30956] dbg: eval: all '*To' addrs: e.mohn@nowhere.at [30956] dbg: bayes: database connection established [30956] dbg: bayes: found bayes db version 3 [30956] dbg: bayes: Using userid: 1 [30956] dbg: bayes: seen (c6c10588e0da867aac60df34e57c687349255e29@sa_generated) put [30956] dbg: bayes: learned 'c6c10588e0da867aac60df34e57c687349255e29@sa_generated', atime: 1243873887 [30956] dbg: learn: initializing learner [30956] dbg: check: is spam? score=30.215 required=7 [30956] dbg: check: tests=BAYES_99,DOS_OE_TO_MX,HTML_MESSAGE,JM_SOUGHT_3,MSGID_DOLLARS,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E4_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_PBL,RDNS_NONE,SARE_SPEC_REPLICA_OBFU,SARE_SPEC_ROLEX,SARE_SPEC_ROLEX_REP,URIBL_AB_SURBL,URIBL_BLACK,URIBL_JP_SURBL,URIBL_OB_SURBL,URIBL_SBL [30956] dbg: check: subtests=__ANY_OUTLOOK_MUA,__CT,__CTYPE_HAS_BOUNDARY,__CTYPE_MULTIPART_ALT,__DOS_DIRECT_TO_MX,__DOS_HAS_ANY_URI,__DOS_RCVD_MON,__DOS_SINGLE_EXT_RELAY,__ENV_AND_HDR_FROM_MATCH,__FB_S_PRICE,__FB_WALLETS,__FH_HAS_XMSMAIL,__FH_HAS_XPRIORITY,__FM_MY_PRICE,__HAS_ANY_URI,__HAS_MIMEOLE,__HAS_MSGID,__HAS_MSMAIL_PRI,__HAS_RCVD,__HAS_SUBJECT,__HAS_X_MAILER,__HDR_ORDER_FTSDMCXXXX,__HTML_LENGTH_1024_1536,__LAST_UNTRUSTED_RELAY_NO_AUTH,__LOCAL_PP_NONPPURL,__MIMEOLE_MS,__MIME_HTML,__MIME_QP,__MIME_VERSION,__MISSING_REF,__MSGID_DOLLARS_MAYBE,__MSGID_DOLLARS_OK,__MSGID_OK_HEX,__MSGID_OK_HOST,__MSGID_RANDY,__MY_ARIAL2,__MY_CLOSING,__MY_STYLE,__NONEMPTY_BODY,__NO_INR_YES_REF,__OE_MSGID_2,__OE_MUA,__RCVD_IN_ZEN,__RDNS_NONE,__SANE_MSGID,__SARE_BODY_BLANKS_5_100,__SARE_BODY_BLNK_5_100,__SARE_HAS_BG_COLOR,__SARE_HAS_FG_COLOR,__SARE_HEAD_MIME_VALID,__SARE_HTML_HAS_A,__SARE_HTML_HAS_BR,__SARE_HTML_HAS_DIV,__SARE_HTML_HAS_FONT,__SARE_META_MURTY3,__SARE_SPEC_ROLEX_BODY,__SARE_SPEC_ROLEX_REP1,__SARE_SPEC_SUBJ_LEO,__SARE_SPEC_WATCH_BODY,__SARE_SPEC_WATCH_SUBJ,__SARE_URI_ANY,__SARE_WHITELIST_FLAG,__SARE_WHITE_BG_COLOR,__SEEK_5DZDOH,__SEEK_GPRBUZ,__SEEK_IK5UYS,__SEEK_RUB3_U,__SEEK_WUDYUX,__TAG_EXISTS_BODY,__TAG_EXISTS_HEAD,__TAG_EXISTS_HTML,__TAG_EXISTS_META,__TOCC_EXISTS,__TVD_BODY,__TVD_MIME_ATT_TP,__XM_MSOE6,__XM_MS_IN_GENERAL,__XM_OUTLOOK_EXPRESS Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer spam_scan_sa_finish: timer set to 88 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) spam_scan: score=30.215 autolearn=spam tests=[BAYES_99=4,DOS_OE_TO_MX=2.75,HTML_MESSAGE=0.001,JM_SOUGHT_3=4,MSGID_DOLLARS=1,RAZOR2_CF_RANGE_51_100=0.5,RAZOR2_CF_RANGE_E4_51_100=1.5,RAZOR2_CF_RANGE_E8_51_100=1.5,RAZOR2_CHECK=0.5,RCVD_IN_PBL=0.905,RDNS_NONE=0.1,SARE_SPEC_REPLICA_OBFU=1.812,SARE_SPEC_ROLEX=1.666,SARE_SPEC_ROLEX_REP=1.666,URIBL_AB_SURBL=1.86,URIBL_BLACK=1.955,URIBL_JP_SURBL=1.501,URIBL_OB_SURBL=1.5,URIBL_SBL=1.499] Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer spam_scan: remaining time = 88 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_tag_level), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="-9999" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_tag_level) => true, "e.mohn@nowhere.at" matches, result="-9999", matching_key="(constant:-9999)" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_tag2_level), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="5" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_tag2_level) => true, "e.mohn@nowhere.at" matches, result="5", matching_key="(constant:5)" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_tag3_level) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_kill_level), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="10" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_kill_level) => true, "e.mohn@nowhere.at" matches, result="10", matching_key="(constant:10)" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(bypass_spam_checks), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (bypass_spam_checks) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(message_size_limit), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (message_size_limit) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_lover), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_lovers) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) blocking contents category is (6) for e.mohn@nowhere.at Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) blocking ccat=6, SMTP response: 250 2.7.0 Ok, discarded, id=30956-01 - SPAM Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) do_notify_and_quar: ccat=Spam (6,0) ("6":Spam, "5":Spammy, "1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(6), q_mth=local:spam-%m.gz, qar_mth= Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_tag_level), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="-9999" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_tag_level) => true, "e.mohn@nowhere.at" matches, result="-9999", matching_key="(constant:-9999)" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_tag2_level), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="5" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_tag2_level) => true, "e.mohn@nowhere.at" matches, result="5", matching_key="(constant:5)" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_kill_level), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup: (scalar) matches, result="10" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_kill_level) => true, "e.mohn@nowhere.at" matches, result="10", matching_key="(constant:10)" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_quarantine_to), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_quarantine_to) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_sql_field(spam_admin), "e.mohn@nowhere.at" no matching records Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) query_keys: e.mohn@nowhere.at, e.mohn@, nowhere.at, .nowhere.at, .at, . Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_hash(e.mohn@nowhere.at), no matches Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_admin) => undef, "e.mohn@nowhere.at" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_quarantine_bysender_to) => undef, "trinas@zdnetasia.com" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) SPAM, -> , Yes, score=30.215 tag=-9999 tag2=5 kill=10 tests=[BAYES_99=4, DOS_OE_TO_MX=2.75, HTML_MESSAGE=0.001, JM_SOUGHT_3=4, MSGID_DOLLARS=1, RAZOR2_CF_RANGE_51_100=0.5, RAZOR2_CF_RANGE_E4_51_100=1.5, RAZOR2_CF_RANGE_E8_51_100=1.5, RAZOR2_CHECK=0.5, RCVD_IN_PBL=0.905, RDNS_NONE=0.1, SARE_SPEC_REPLICA_OBFU=1.812, SARE_SPEC_ROLEX=1.666, SARE_SPEC_ROLEX_REP=1.666, URIBL_AB_SURBL=1.86, URIBL_BLACK=1.955, URIBL_JP_SURBL=1.501, URIBL_OB_SURBL=1.5, URIBL_SBL=1.499], autolearn=spam Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) skip admin notification, no administrators Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) do_notify_and_quarantine - done Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer aux_quarantine: remaining time = 88 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup (spam_dsn_cutoff_level_bysender) => undef, "trinas@zdnetasia.com" does not match Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) dsn: . 250 Spam -> : on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=, mta_resp: "250 2.7.0 Ok, discarded, id=30956-01 - SPAM" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) DSN: SUCC (discarded) . 250 Spam, destiny=DISCARD: -> Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) one_response_for_all : all DISCARD, '250 2.7.0 Ok, discarded, id=30956-01 - SPAM' Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) notif=N, suppressed=0, ndn_needed=, exit=99, 250 2.7.0 Ok, discarded, id=30956-01 - SPAM Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer delivery-notification: remaining time = 88 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) parse_received: from = dsl.dynamic8599137161.ttnet.net.tr (unknown [88.22[...]/dsl.dynamic8599137161.ttnet.net.tr/unknown/88.228.174.25 Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) parse_received: by = monty.wu-wien.ac.at /monty.wu-wien.ac.at// Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) parse_received: with = ESMTP /ESMTP // Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) parse_received: id = 09AAAE000D4\t/09AAAE000D4\t// Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) parse_received: for = /// Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) parse_received: ; = Mon, 1 Jun 2009 18:31:27 +0200 (CEST)/Mon, 1 Jun 2009 18:31:27 +0200 (CEST)// Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) fish_out_ip_from_received: 88.228.174.25, dsl.dynamic8599137161.ttnet.net.tr (unknown [88.228.174.25])\t Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) lookup_ip_acl (publicnetworks): key="88.228.174.25" matches "::FFFF:0:0/96", result=1 Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) best_try_originator_ip: 88.228.174.25 Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) Blocked SPAM, STRIKE/MYNETS LOCAL [137.208.16.200] [88.228.174.25] -> , Message-ID: <6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com>, mail_id: TDQdyV5IK8QS, Hits: 30.215, size: 2854, 1601 ms Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer main_log_entry: remaining time = 88 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql begin transaction Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: preparing and executing: INSERT INTO msgrcpt (mail_id, rid, ds, rs, bl, wl, bspam_level, smtp_resp) VALUES (?,?,?,?,?,?,?,?) Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) save_info_final TDQdyV5IK8QS, S, , , N, 30.215, Message-ID: <6dd401c9e2d5$66fe9bc0$72653dce@zdnetasia.com>, From: '"Adan Caldwell" ', Subject: 'Swiss Branded Watches' Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql: preparing and executing: UPDATE msgs SET content=?, quar_type=?, quar_loc=?, dsn_sent=?, spam_level=?, message_id=?, from_addr=?, subject=? WHERE mail_id=? Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sql commit Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) prolong_timer check done: remaining time = 88 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) sending SMTP response: "250 2.7.0 Ok, discarded, id=30956-01 - SPAM" Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 250 2.7.0 Ok, discarded, id=30956-01 - SPAM Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) TempDir::strip: /var/spool/amavisd/tmp/amavis-20090601T183127-30956 Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) rmdir_recursively: /var/spool/amavisd/tmp/amavis-20090601T183127-30956/parts, excl=1 Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) TIMING [total 1604 ms] - sql-prepare: 2 (0%)0, SMTP greeting: 2 (0%)0, SMTP EHLO: 1 (0%)0, SMTP pre-MAIL: 1 (0%)0, mkdir tempdir: 0 (0%)0, create email.txt: 0 (0%)0, sql-connect: 5 (0%)1, lookup_sql: 1 (0%)1, SMTP pre-DATA-flush: 2 (0%)1, SMTP DATA: 1 (0%)1, check_init: 1 (0%)1, digest_hdr: 1 (0%)1, digest_body: 0 (0%)1, sql-enter: 5 (0%)1, mkdir parts: 1 (0%)1, mime_decode: 12 (1%)2, get-file-type2: 11 (1%)3, decompose_part: 1 (0%)3, parts_decode: 0 (0%)3, check_header: 2 (0%)3, AV-scan-1: 68 (4%)7, spam-wb-list: 4 (0%)8, SA parse: 4 (0%)8, SA check: 1459 (91%)99, update_cache: 4 (0%)99, decide_mail_destiny: 2 (0%)99, prepare-dsn: 3 (0%)99, main_log_entry: 7 (0%)100, sql-update: 2 (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100, unlink-2-files: 0 (0%)100, rundown: 0 (0%)100 Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 6: was busy, 1590.7 ms, total idle 0.001 s, busy 1.604 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 1.604 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP< QUIT\r\n Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_my_time 90 s, SMTP QUIT received Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) ESMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) SMTP session over, timer stopped Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) extra modules loaded: auto/POSIX/SigAction/new.al Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) exiting process_request Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) post_process_request_hook: timer was not running Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) idle_proc, bye: was busy, 2.6 ms, total idle 0.001 s, busy 1.607 s Jun 1 18:31:29 strike.wu-wien.ac.at /usr/sbin/amavisd[30956]: (30956-01) load: 100 %, total idle 0.001 s, busy 1.607 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: Net::Server: 2009/06/01-18:31:34 CONNECT TCP Peer: "127.0.0.1:51547" Local: "127.0.0.1:10024" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: loaded base policy bank Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: loaded policy bank "STRIKE" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.0/8", result=1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: process_request: fileno sock=13, STDIN=0, STDOUT=1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: switch_to_my_time 90 s, new request Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: process_request: suggested_protocol="" on TCP Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 4: was busy, 3.9 ms, total idle 0.000 s, busy 0.004 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.000 s, busy 0.004 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) SMTP< EHLO strike.wu.ac.at\r\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_my_time 90 s, SMTP EHLO received Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-[127.0.0.1] Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-VRFY Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-PIPELINING Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-SIZE Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-ENHANCEDSTATUSCODES Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-8BITMIME Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250-DSN Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.000 s, busy 0.005 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.000 s, busy 0.005 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP< XFORWARD NAME=strike.wu-wien.ac.at ADDR=137.208.89.120 HELO=strike.wu-wien.ac.at PROTO=SMTP\r\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_my_time 90 s, SMTP XFORWARD received Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250 2.5.0 Ok XFORWARD Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 6: was busy, 0.6 ms, total idle 0.000 s, busy 0.006 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.006 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP< MAIL FROM:\r\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_my_time 90 s, SMTP MAIL received Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) check_mail_begin_task: task_count=1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) TempDir::prepare: creating directory /var/spool/amavisd/tmp/amavis-20090601T183134-30957 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) TempDir::prepare_file: creating file /var/spool/amavisd/tmp/amavis-20090601T183134-30957/email.txt Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) TempDir::prepare_file: layers: unix,perlio Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_ip_acl (mynetworks): key="137.208.89.120" matches "137.208.0.0/16", result=1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) loaded policy bank "MYNETS" over "STRIKE" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (debug_sender) => undef, "foo@strike.wu-wien.ac.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250 2.1.0 Sender OK Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 6: was busy, 2.6 ms, total idle 0.001 s, busy 0.008 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.008 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP< RCPT TO:\r\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_my_time 90 s, SMTP RCPT received Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_acl(leo@kloburg.at) matches key ".kloburg.at", result=1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (local_domains) => true, "leo@kloburg.at" matches, result="1", matching_key=".kloburg.at" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo, @kloburg.at, @.kloburg.at, @.at, @. Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql "leo@kloburg.at", query args: "leo@kloburg.at", "leo", "@kloburg.at", "@.kloburg.at", "@.at", "@." Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql select: SELECT *, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql begin, nontransaction Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Connecting to SQL database server Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) connect_to_sql: trying 'DBI:mysql:database=amavis;host=127.0.0.1' Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) connect_to_sql: 'DBI:mysql:database=amavis;host=127.0.0.1' succeeded Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql: preparing and executing: SELECT *, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql, "leo@kloburg.at" no match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(message_size_limit), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (message_size_limit) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 250 2.1.5 Recipient OK Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 6: was busy, 4.6 ms, total idle 0.001 s, busy 0.013 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.013 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP< DATA\r\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_my_time 90 s, SMTP DATA received Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP:[127.0.0.1]:10024 /var/spool/amavisd/tmp/amavis-20090601T183134-30957: -> Received: from strike.wu.ac.at ([127.0.0.1]) by localhost (strike.wu-wien.ac.at [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for ; Mon, 1 Jun 2009 18:31:34 +0200 (CEST) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP> 354 End data with . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, smtp response sent Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_client_time 1200 s, receiving data Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) switch_to_my_time 90 s, data-end received Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ESMTP< . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(local), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_acl(leo@kloburg.at) matches key ".kloburg.at", result=1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (local_domains) => true, "leo@kloburg.at" matches, result="1", matching_key=".kloburg.at" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) body type: unlabeled, good (h=0, b=0) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) body hash: 64a39722b883648e0c70a566840c8a29 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Original mail size: 39279; quota set to: 19639500 bytes Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql begin, nontransaction Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql: preparing and executing: SELECT id FROM maddr WHERE email=? Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) save_info_preliminary: 1191431, foo@strike.wu-wien.ac.at, exists Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql begin, nontransaction Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql: executing clause: SELECT id FROM maddr WHERE email=? Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) save_info_preliminary gJuEruKYGwxl, recip id: 23, leo@kloburg.at, exists Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql begin transaction Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql: preparing and executing: INSERT INTO msgs (mail_id, secret_id, am_id, time_num, time_iso, sid, policy, client_addr, size, host) VALUES (?,?,?,?,?,?,?,?,?,?) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) sql commit Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Checking: gJuEruKYGwxl STRIKE/MYNETS [137.208.89.120] -> Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) 2822.From: , 2821.Mail_From: Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(bypass_virus_checks), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (bypass_virus_checks) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Extracting mime components Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Issued a new file name: p001 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Issued a new file name: p002 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) mime_decode_preamble: 2 lines Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Issued a new pseudo part: p003 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) p003 1 Content-Type: multipart/mixed Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) mime_decode_epilogue: 1 lines Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Charging 461 bytes to remaining quota 19639500 (out of 19639500, (0%)) - by mime_decode Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) p001 1/1 Content-Type: text/plain, size: 461 B, name: Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) reparenting p001 from p000 to p003 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Charging 27154 bytes to remaining quota 19639039 (out of 19639500, (0%)) - by mime_decode Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) p002 1/2 Content-Type: application/zip, size: 27154 B, name: ecard.zip Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) reparenting p002 from p000 to p003 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer mime_decode: remaining time = 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer mime_decode-1: remaining time = 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) decode_parts: level=1, #parts=3 : p001, p002, p003 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) run_command: [30964] /usr/bin/file p001 p002 &1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) result line from file(1): p001: ASCII English text\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re("ASCII English text") matches key "(?i-xsm:^(ASCII|text)\b)", result="asc" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (map_full_type_to_short_type) => true, "ASCII English text" matches, result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) File-type of p001: ASCII English text; (asc) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) result line from file(1): p002: Zip archive data, at least v2.0 to extract\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re("Zip archive data, at least v2.0 to extract") matches key "(?i-xsm:^Zip archive\b)", result="zip" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (map_full_type_to_short_type) => true, "Zip archive data, at least v2.0 to extract" matches, result="zip", matching_key="(?i-xsm:^Zip archive\\b)" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) File-type of p002: Zip archive data, at least v2.0 to extract; (zip) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_ascii: Decoding part p001 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_ascii: Setting sigaction handler, was 0 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 60 s (was 90 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_ascii: Decoding part p001 (0 items), uulib V0.5pl20 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer do_ascii: timer set to 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) decompose_part: p001 - atomic Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Unzipping p002 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Issued a new file name: p004 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Charging 32768 bytes to remaining quota 19611885 (out of 19639500, (0%)) - by do_unzip Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re("Zip archive data, at least v2.0 to extract"), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (keep_decoded_original) => undef, "Zip archive data, at least v2.0 to extract" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) decompose_part: deleting /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts/p002 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) decompose_part: p002 - archive, unpacked Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) decode_parts: level=2, #parts=1 : p004 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) run_command: [30965] /usr/bin/file p004 &1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) result line from file(1): p004: PE32 executable for MS Windows (GUI) Intel 80386 32-bit\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re("PE32 executable for MS Windows (GUI) Intel 80386 32-bit") matches key "(?-xism:\bexecutable for MS Windows\b)", result=["exe","exe-ms"] Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (map_full_type_to_short_type) => true, "PE32 executable for MS Windows (GUI) Intel 80386 32-bit" matches, result=["exe","exe-ms"], matching_key="(?-xism:\\bexecutable for MS Windows\\b)" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) File-type of p004: PE32 executable for MS Windows (GUI) Intel 80386 32-bit; (exe, exe-ms) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Check whether p004 is a self-extracting archive Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Unzipping p004 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_unzip: ok, exe is not a zip sfx: AZ_FORMAT_ERROR (3) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Expanding RAR archive p004 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 60 s (was 90 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) run_command: [30966] /usr/bin/rar v -c- -p- -av- -idcdp -- /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts/p004 &1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer do_unrar: timer set to 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_executable: not a RAR sfx, ignoring: do_unrar: /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts/p004 is not RAR archive at (eval 89) line 834. at (eval 89) line 877. Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Expanding LHA archive p004 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 60 s (was 90 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) run_command: [30967] /usr/bin/lha lq /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts/p004.exe &1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_lha: skip: [unknown] 16776960 0.0% Nov 30 1979 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer do_lha: timer set to 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_executable: not a LHA sfx, ignoring: do_lha: (LHa: Warning: Checksum error (LHarc file?) Inappropriate ioctl for device, LHa: Fatal error: Unknown level header: Inappropriate ioctl for device) exit 1 at (eval 89) line 920. at (eval 89) line 933. Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Expanding ARJ archive p004 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 60 s (was 90 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) run_command: [30968] /usr/bin/arj l /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts/p004.arj &1 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer do_unarj: timer set to 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) do_executable: not an ARJ sfx, ignoring: do_unarj: not an ARJ archive? exit 9 at (eval 89) line 1092. at (eval 89) line 1154. Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) decompose_part: p004 - atomic Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer parts_decode: remaining time = 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(bypass_header_checks), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (bypass_header_checks) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) check_header: 0, OK Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(bypass_header_checks), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (bypass_header_checks) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Checking for banned types and filenames Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(bypass_banned_checks), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (bypass_banned_checks) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(banned_rulenames), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup: (scalar) matches, result="DEFAULT" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (banned_filename), 1 matches for "leo@kloburg.at", results: "(constant:DEFAULT)"=>"DEFAULT" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) collect banned table[0]: leo@kloburg.at, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x9f599bc) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) starting banned checks - traversing message structure tree Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) check_for_banned (p003,p001) multipart/mixed | text/plain,.asc Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) doing banned check for leo@kloburg.at on multipart/mixed | text/plain,.asc Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re(["multipart/mixed","text/plain",".asc"]), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (check_bann:leo@kloburg.at) => undef, ["multipart/mixed","text/plain",".asc"] does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) p.path leo@kloburg.at: "P=p003,L=1,M=multipart/mixed | P=p001,L=1/1,M=text/plain,T=asc" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) check_for_banned (p003,p002,p004) multipart/mixed | application/zip,.zip,ecard.zip | .exe,.exe-ms,ecard.exe Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) doing banned check for leo@kloburg.at on multipart/mixed | application/zip,.zip,ecard.zip | .exe,.exe-ms,ecard.exe Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re(["multipart/mixed","application/zip",".zip","ecard.zip",".exe",".exe-ms","ecard.exe"]) matches key "(?-xism:^.(exe-ms|dll)$)", result="1" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (check_bann:leo@kloburg.at) => true, ["multipart/mixed","application/zip",".zip","ecard.zip",".exe",".exe-ms","ecard.exe"] matches, result="1", matching_key="(?-xism:^\\.(exe-ms|dll)$)" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) p.path BANNED:1 leo@kloburg.at: "P=p003,L=1,M=multipart/mixed | P=p002,L=1/2,M=application/zip,T=zip,N=ecard.zip | P=p004,L=1/2/1,T=exe,T=exe-ms,N=ecard.exe", matching_key="(?-xism:^\\.(exe-ms|dll)$)" Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) banned check: any=1, all=Y (1) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re("MAIL"), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (keep_decoded_original) => undef, "MAIL" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) files_to_scan: info: part p002 (zip) no longer present Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Using AVG Anti-Virus: (built-in interface) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 60 s (was 90 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ask_av (AVG Anti-Virus): query template1: SCAN {}\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) Using (AVG Anti-Virus) on dir: SCAN /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 10 s (was 60 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) AVG Anti-Virus: Connecting to socket 127.0.0.1:55555 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) AVG Anti-Virus: Sending SCAN /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts\n to INET socket 127.0.0.1:55555 Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer ask_daemon_internal: timer set to 48 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ask_av (AVG Anti-Virus) result: 220-AVG7 Anti-Virus daemon mode scanner\r\n220-Program version 7.5.51, engine 442\r\n220-Virus Database: Version 270.12.36/2126 2009-05-21\r\n220 Ready\r\n200 OK\r\n Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) ask_av (AVG Anti-Virus): /var/spool/amavisd/tmp/amavis-20090601T183134-30957/parts CLEAN Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) AVG Anti-Virus result: clean Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) prolong_timer run_av: timer set to 90 s Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(bypass_virus_checks), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (bypass_virus_checks) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(bypass_spam_checks), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (bypass_spam_checks) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) wbl: checking sender Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_sql_field(id), "leo@kloburg.at" no matching records Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) wbl: (SQL) recip , 0 matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (blacklist_recip) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: foo@strike.wu-wien.ac.at, foo@, strike.wu-wien.ac.at, .strike.wu-wien.ac.at, .wu-wien.ac.at, .ac.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(foo@strike.wu-wien.ac.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (blacklist_sender) => undef, "foo@strike.wu-wien.ac.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (whitelist_recip) => undef, "leo@kloburg.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: foo@strike.wu-wien.ac.at, foo@, strike.wu-wien.ac.at, .strike.wu-wien.ac.at, .wu-wien.ac.at, .ac.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(foo@strike.wu-wien.ac.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (whitelist_sender) => undef, "foo@strike.wu-wien.ac.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: leo@kloburg.at, leo@, kloburg.at, .kloburg.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(leo@kloburg.at) matches keys: "."=>ARRAY(0x9f59f8c) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (score_sender), 1 matches for "leo@kloburg.at", results: "."=>[Amavis::Lookup::RE=ARRAY(0x9f59ccc),HASH(0x9f59d5c)] Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_re("foo@strike.wu-wien.ac.at"), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) query_keys: foo@strike.wu-wien.ac.at, foo@, strike.wu-wien.ac.at, .strike.wu-wien.ac.at, .wu-wien.ac.at, .ac.at, .at, . Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup_hash(foo@strike.wu-wien.ac.at), no matches Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) lookup (score_sender) => undef, "foo@strike.wu-wien.ac.at" does not match Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) SpamControl: calling spam scanner Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) spam_scan: DSPAM not available, skipping it Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) timer set to 60 s for SA (was 90 s) Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) calling SA parse, SA version 3.2.5, 3.002005, data as GLOB [30957] dbg: dns: name server: 137.208.3.3, LocalAddr: 0.0.0.0 [30957] dbg: dns: resolver socket rx buffer size is 111616 bytes [30957] dbg: message: main message type: multipart/mixed Jun 1 18:31:34 strike.wu-wien.ac.at /usr/sbin/amavisd[30957]: (30957-01) CALLING SA check [30957] dbg: conf: internal_networks not configured, using trusted_networks configuration for internal_networks; if you really want internal_networks to only contain the required 127/8 add 'internal_networks !0/0' to your configuration [30957] dbg: received-header: parsed as [ ip=137.208.89.120 rdns=strike.wu-wien.ac.at helo=strike.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=0 id= auth= msa=0 ] [30957] dbg: received-header: relay 137.208.89.120 trusted? yes internal? yes msa? no [30957] dbg: received-header: parsed as [ ip=137.208.16.200 rdns=monty.wu-wien.ac.at helo=monty.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=0 id= auth= msa=0 ] [30957] dbg: received-header: relay 137.208.16.200 trusted? yes internal? yes msa? no [30957] dbg: received-header: parsed as [ ip=96.239.224.37 rdns=pool-96-239-224-37.nwrknj.east.verizon.net helo=pool-96-239-224-37.nwrknj.east.verizon.net by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=4DE6AE000AA auth= msa=0 ] [30957] dbg: received-header: relay 96.239.224.37 trusted? no internal? no msa? no [30957] dbg: metadata: X-Spam-Relays-Trusted: [ ip=137.208.89.120 rdns=strike.wu-wien.ac.at helo=strike.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=1 id= auth= msa=0 ] [ ip=137.208.16.200 rdns=monty.wu-wien.ac.at helo=monty.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=1 id= auth= msa=0 ] [30957] dbg: metadata: X-Spam-Relays-Untrusted: [ ip=96.239.224.37 rdns=pool-96-239-224-37.nwrknj.east.verizon.net helo=pool-96-239-224-37.nwrknj.east.verizon.net by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=4DE6AE000AA auth= msa=0 ] [30957] dbg: metadata: X-Spam-Relays-Internal: [ ip=137.208.89.120 rdns=strike.wu-wien.ac.at helo=strike.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=1 id= auth= msa=0 ] [ ip=137.208.16.200 rdns=monty.wu-wien.ac.at helo=monty.wu-wien.ac.at by=strike.wu.ac.at ident= envfrom= intl=1 id= auth= msa=0 ] [30957] dbg: metadata: X-Spam-Relays-External: [ ip=96.239.224.37 rdns=pool-96-239-224-37.nwrknj.east.verizon.net helo=pool-96-239-224-37.nwrknj.east.verizon.net by=monty.wu-wien.ac.at ident= envfrom= intl=0 id=4DE6AE000AA auth= msa=0 ] [30957] dbg: message: ---- MIME PARSER START ---- [30957] dbg: message: parsing multipart, got boundary: ----=_NextPart_000_0006_01C9E243.F818F080 [30957] dbg: message: found part of type text/plain, boundary: ----=_NextPart_000_0006_01C9E243.F818F080 [30957] dbg: message: added part, type: text/plain [30957] dbg: message: found part of type application/zip, boundary: ----=_NextPart_000_0006_01C9E243.F818F080 [30957] dbg: message: added part, type: application/zip [30957] dbg: message: parsing normal part [30957] dbg: message: parsing normal part [30957] dbg: message: ---- MIME PARSER END ---- [30957] dbg: message: decoding other encoding type (7bit), ignoring [30957] dbg: uridnsbl: domains to query: 123greetings.com [30957] dbg: async: starting: URI-DNSBL, DNSBL:multi.surbl.org.:123greetings.com (timeout 15.0s, min 3.0s) [30957] dbg: dns: URIBL_PH_SURBL lookup start [30957] dbg: async: starting: URI-DNSBL, DNSBL:multi.uribl.com.:123greetings.com (timeout 15.0s, min 3.0s) [30957] dbg: dns: URIBL_BLACK lookup start [30957] dbg: dns: URIBL_RED lookup start [30957] dbg: dns: URIBL_GREY lookup start [30957] dbg: async: starting: URI-DNSBL, DNSBL:dob.sibl.support-intelligence.net:123greetings.com (timeout 15.0s, min 3.0s) [30957] dbg: dns: URIBL_RHS_DOB lookup start [30957] dbg: dns: URIBL_SC_SURBL lookup start [30957] dbg: dns: URIBL_AB_SURBL lookup start [30957] dbg: dns: URIBL_JP_SURBL lookup start [30957] dbg: dns: URIBL_WS_SURBL lookup start [30957] dbg: dns: URIBL_OB_SURBL lookup start [30957] dbg: async: starting: URI-NS, NS:123greetings.com (timeout 15.0s, min 3.0s) [30957] dbg: dns: URIBL_SBL lookup start [30957] dbg: dns: checking RBL sa-other.bondedsender.org., set bsp-untrusted [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: [30957] dbg: dns: checking RBL plus.bondedsender.org., set ssc-firsttrusted [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.plus.bondedsender.org. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.plus.bondedsender.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL combined.njabl.org., set njabl [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.combined.njabl.org. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.combined.njabl.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL bl.spamcop.net., set spamcop [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS TXT query for 37.224.239.96.bl.spamcop.net. in background [30957] dbg: async: starting: DNSBL-TXT, dns:TXT:37.224.239.96.bl.spamcop.net. (timeout 15.0s, min 3.0s) [30957] dbg: dns: _check_rbl_addresses RBL rhsbl.ahbl.org., set ahbl [30957] dbg: dns: launching DNS A query for strike.wu-wien.ac.at.rhsbl.ahbl.org. in background [30957] dbg: async: starting: DNSBL-A, dns:A:strike.wu-wien.ac.at.rhsbl.ahbl.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking A and MX for host strike.wu-wien.ac.at [30957] dbg: dns: launching DNS A query for strike.wu-wien.ac.at in background [30957] dbg: async: starting: NO_DNS_FOR_FROM, DNSBL-A, dns:A:strike.wu-wien.ac.at (timeout 15.0s, min 3.0s) [30957] dbg: dns: launching DNS MX query for strike.wu-wien.ac.at in background [30957] dbg: async: starting: NO_DNS_FOR_FROM, DNSBL-MX, dns:MX:strike.wu-wien.ac.at (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.zen.spamhaus.org. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.zen.spamhaus.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs-lastexternal [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.dnsbl.sorbs.net. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.dnsbl.sorbs.net. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL dnsbl.sorbs.net., set sorbs [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: checking RBL zen.spamhaus.org., set zen-lastexternal [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: checking RBL list.dnswl.org., set dnswl-firsttrusted [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.list.dnswl.org. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.list.dnswl.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL sa-accredit.habeas.com., set habeas-firsttrusted [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.sa-accredit.habeas.com. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.sa-accredit.habeas.com. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL sa-trusted.bondedsender.org., set bsp-firsttrusted [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS TXT query for 37.224.239.96.sa-trusted.bondedsender.org. in background [30957] dbg: async: starting: DNSBL-TXT, dns:TXT:37.224.239.96.sa-trusted.bondedsender.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL zen.spamhaus.org., set zen [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: _check_rbl_addresses RBL fulldom.rfc-ignorant.org., set rfci_envfrom [30957] dbg: dns: launching DNS A query for strike.wu-wien.ac.at.fulldom.rfc-ignorant.org. in background [30957] dbg: async: starting: DNSBL-A, dns:A:strike.wu-wien.ac.at.fulldom.rfc-ignorant.org. (timeout 15.0s, min 3.0s) [30957] dbg: dns: checking RBL iadb.isipp.com., set iadb-firsttrusted [30957] dbg: dns: IPs found: full-external: 96.239.224.37 untrusted: 96.239.224.37 originating: [30957] dbg: dns: only inspecting the following IPs: 96.239.224.37 [30957] dbg: dns: launching DNS A query for 37.224.239.96.iadb.isipp.com. in background [30957] dbg: async: starting: DNSBL-A, dns:A:37.224.239.96.iadb.isipp.com. (timeout 15.0s, min 3.0s) [30957] dbg: check: running tests for priority: -1000 [30957] dbg: dns: hit "Blocked - see http://www.spamcop.net/bl.shtml?96.239.224.37" [30957] dbg: dns: hit 137.208.89.120 [30957] dbg: dns: hit 10 strike.wu-wien.ac.at. [30957] dbg: dns: hit 127.0.0.4 [30957] dbg: dns: hit 127.0.0.10 [30957] dbg: dns: hit 127.0.0.10 [30957] dbg: async: select found 11 responses ready (t.o.=0.0) [30957] dbg: async: completed in 0.007 s: DNSBL-A, dns:A:strike.wu-wien.ac.at.fulldom.rfc-ignorant.org. [30957] dbg: async: completed in 0.008 s: DNSBL-A, dns:A:strike.wu-wien.ac.at.rhsbl.ahbl.org. [30957] dbg: async: completed in 0.010 s: DNSBL-A, dns:A:37.224.239.96.combined.njabl.org. [30957] dbg: async: completed in 0.008 s: NO_DNS_FOR_FROM, DNSBL-MX, dns:MX:strike.wu-wien.ac.at [30957] dbg: async: completed in 0.009 s: DNSBL-TXT, dns:TXT:37.224.239.96.bl.spamcop.net. [30957] dbg: async: completed in 0.009 s: DNSBL-A, dns:A:37.224.239.96.list.dnswl.org. [30957] dbg: async: completed in 0.007 s: DNSBL-A, dns:A:37.224.239.96.iadb.isipp.com. [30957] dbg: async: completed in 0.008 s: DNSBL-A, dns:A:37.224.239.96.zen.spamhaus.org. [30957] dbg: async: completed in 0.009 s: DNSBL-A, dns:A:37.224.239.96.dnsbl.sorbs.net. [30957] dbg: async: completed in 0.008 s: NO_DNS_FOR_FROM, DNSBL-A, dns:A:strike.wu-wien.ac.at [30957] dbg: async: completed in 0.011 s: URI-NS, NS:123greetings.com [30957] dbg: async: starting: URI-A, A:pdns2.ultradns.net. (timeout 15.0s, min 3.0s) [30957] dbg: async: starting: URI-A, A:pdns3.ultradns.org. (timeout 15.0s, min 3.0s) [30957] dbg: async: starting: URI-A, A:pdns4.ultradns.org. (timeout 15.0s, min 3.0s) [30957] dbg: async: starting: URI-A, A:pdns5.ultradns.info. (timeout 15.0s, min 3.0s) [30957] dbg: async: starting: URI-A, A:pdns6.ultradns.co.uk. (timeout 15.0s, min 3.0s) [30957] dbg: async: starting: URI-A, A:pdns1.ultradns.net. (timeout 15.0s, min 3.0s) [30957] dbg: async: queries completed: 11, started: 6 [30957] dbg: async: queries active: DNSBL-A=2 DNSBL-TXT=1 URI-A=6 URI-DNSBL=3 at Mon Jun 1 18:31:34 2009 [30957] dbg: dns: harvested completed queries [30957] dbg: rules: running head tests; score so far=6.775 [30957] dbg: eval: all '*From' addrs: bafflet0@mbpinet.com foo@strike.wu-wien.ac.at [30957] dbg: eval: all '*To' addrs: leo@kloburg.at nadezda@nowhere.at leo@nowhere.at [30957] dbg: rules: running body tests; score so far=6.775