[Postfixbuch-users] SpamAssassin (amavis) und Debian 5.0 (Lenny) funktionieren nicht so wie gewollt

Martin MŸüller | Rudolf Hausstein OHG m.mueller at hausstein.at
Mi Apr 1 18:13:34 CEST 2009


Hallo!


Den amavis-new hab ich nach den Änderungen gestartet, an dem liegt es 
also nicht.

Folgend das Syslog fürs Debugging.

Auffällig die Zeile
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: cannot load 
Mail::SPF module or create Mail::SPF::Server object: Can't locate 
Mail/SPF.pm in @INC (@INC contains: lib /etc/perl 
/usr/local/lib/perl/5.10.0 /usr/local/share/perl/5.10.0 /usr/lib/perl5 
/usr/share/perl5 /usr/lib/perl/5.10 /usr/share/perl/5.10 
/usr/local/lib/site_perl) at 
/usr/share/perl5/Mail/SpamAssassin/Plugin/SPF.pm line 390.

obwohl die SPF.pm unter laut find / -name SPF.pm unter
/usr/share/perl5/Mail/SpamAssassin/Plugin/SPF.pm zu finden ist.

-------------------------(ACHTUNG: was Syslog bei der Einlieferung einer 
Mail meint, findet man weiter unten - vielleicht zu rest lesen ) 
-------------------------

Apr  1 17:39:23 CENSORED amavis[20419]: logging initialized, log level 
2, syslog: amavis.local5
Apr  1 17:39:23 CENSORED amavis[20419]: starting.  /usr/sbin/amavisd-new 
at CENSORED.hausstein.at amavisd-new-2.6.1 (20080629), Unicode aware, 
LANG="de_AT.UTF-8"
Apr  1 17:39:23 CENSORED amavis[20419]: user=, EUID: 115 (115);  group=, 
EGID: 119 119 (119 119)
Apr  1 17:39:23 CENSORED amavis[20419]: Perl version               5.010000
Apr  1 17:39:23 CENSORED amavis[20419]: INFO: no optional modules: 
IO::Socket::INET6
Apr  1 17:39:24 CENSORED amavis[20419]: INFO: SA version: 3.2.5, 
3.002005, no optional modules: Mail::SpamAssassin::BayesStore::PgSQL 
Encode::Detect Mail::SpamAssassin::Plugin::DKIM IP::Country::Fast 
Mail::DKIM Mail::DKIM::Verifier Image::Info Image::Info::GIF 
Image::Info::JPEG Image::Info::PNG Image::Info::TIFF Mail::SPF 
Mail::SPF::Server Mail::SPF::Request Mail::SPF::Mech Mail::SPF::Mech::A 
Mail::SPF::Mech::PTR Mail::SPF::Mech::All Mail::SPF::Mech::Exists 
Mail::SPF::Mech::IP4 Mail::SPF::Mech::IP6 Mail::SPF::Mech::Include 
Mail::SPF::Mech::MX Mail::SPF::Mod Mail::SPF::Mod::Exp 
Mail::SPF::Mod::Redirect Mail::SPF::SenderIPAddrMech 
Mail::SPF::v1::Record Mail::SPF::v2::Record NetAddr::IP 
NetAddr::IP::Util auto::NetAddr::IP::Util::inet_n2dx 
auto::NetAddr::IP::Util::ipv6_n2d auto::NetAddr::IP::Util::ipv6_n2x 
Crypt::OpenSSL::RSA auto::Crypt::OpenSSL::RSA::new_public_key 
auto::Crypt::OpenSSL::RSA::new_key_from_parameters 
auto::Crypt::OpenSSL::RSA::get_key_parameters 
auto::Crypt::OpenSSL::RSA::import_random_see...
Apr  1 17:39:24 CENSORED amavis[20419]: ...d Error
Apr  1 17:39:24 CENSORED amavis[20419]: SpamControl: init_pre_chroot on 
SpamAssassin done
Apr  1 17:39:24 CENSORED amavis[20424]: Net::Server: Process Backgrounded
Apr  1 17:39:24 CENSORED amavis[20424]: Net::Server: 2009/04/01-17:39:24 
Amavis (type Net::Server::PreForkSimple) starting! pid(20424)
Apr  1 17:39:24 CENSORED amavis[20424]: Net::Server: Binding to UNIX 
socket file /var/lib/amavis/amavisd.sock using SOCK_STREAM
Apr  1 17:39:24 CENSORED amavis[20424]: Net::Server: Binding to TCP port 
10024 on host 127.0.0.1
Apr  1 17:39:24 CENSORED amavis[20424]: Net::Server: Group Not Defined. 
  Defaulting to EGID '119 119'
Apr  1 17:39:24 CENSORED amavis[20424]: Net::Server: User Not Defined. 
Defaulting to EUID '115'
Apr  1 17:39:24 CENSORED amavis[20424]: config files read: 
/usr/share/amavis/conf.d/10-debian_scripts, 
/usr/share/amavis/conf.d/20-package, /etc/amavis/conf.d/01-debian, 
/etc/amavis/conf.d/05-domain_id, /etc/amavis/conf.d/05-node_id, 
/etc/amavis/conf.d/15-av_scanners, 
/etc/amavis/conf.d/15-content_filter_mode, 
/etc/amavis/conf.d/20-debian_defaults, 
/etc/amavis/conf.d/25-amavis_helpers, 
/etc/amavis/conf.d/30-template_localization, /etc/amavis/conf.d/50-user
Apr  1 17:39:24 CENSORED amavis[20424]: Module Amavis::Conf        2.103
Apr  1 17:39:24 CENSORED amavis[20424]: Module Archive::Zip        1.18
Apr  1 17:39:24 CENSORED amavis[20424]: Module BerkeleyDB          0.34
Apr  1 17:39:24 CENSORED amavis[20424]: Module Compress::Zlib      2.012
Apr  1 17:39:24 CENSORED amavis[20424]: Module Convert::TNEF       0.17
Apr  1 17:39:24 CENSORED amavis[20424]: Module Convert::UUlib      1.11
Apr  1 17:39:24 CENSORED amavis[20424]: Module DBD::mysql          4.007
Apr  1 17:39:24 CENSORED amavis[20424]: Module DBI                 1.605
Apr  1 17:39:24 CENSORED amavis[20424]: Module DB_File             1.816_1
Apr  1 17:39:24 CENSORED amavis[20424]: Module Digest::MD5         2.36_01
Apr  1 17:39:24 CENSORED amavis[20424]: Module Digest::SHA         5.45
Apr  1 17:39:24 CENSORED amavis[20424]: Module Digest::SHA1        2.11
Apr  1 17:39:24 CENSORED amavis[20424]: Module MIME::Entity        5.427
Apr  1 17:39:24 CENSORED amavis[20424]: Module MIME::Parser        5.427
Apr  1 17:39:24 CENSORED amavis[20424]: Module MIME::Tools         5.427
Apr  1 17:39:24 CENSORED amavis[20424]: Module Mail::Header        2.03
Apr  1 17:39:24 CENSORED amavis[20424]: Module Mail::Internet      2.03
Apr  1 17:39:24 CENSORED amavis[20424]: Module Mail::SPF::Query    1.999001
Apr  1 17:39:24 CENSORED amavis[20424]: Module Mail::SpamAssassin  3.002005
Apr  1 17:39:24 CENSORED amavis[20424]: Module Net::DNS            0.63
Apr  1 17:39:24 CENSORED amavis[20424]: Module Net::Server         0.97
Apr  1 17:39:24 CENSORED amavis[20424]: Module Razor2::Client::Version 2.84
Apr  1 17:39:24 CENSORED amavis[20424]: Module Socket6             0.20
Apr  1 17:39:24 CENSORED amavis[20424]: Module Time::HiRes         1.9711
Apr  1 17:39:24 CENSORED amavis[20424]: Module URI                 1.35
Apr  1 17:39:24 CENSORED amavis[20424]: Module Unix::Syslog        1.1
Apr  1 17:39:24 CENSORED amavis[20424]: Amavis::DB code      loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Amavis::Cache code   loaded
Apr  1 17:39:24 CENSORED amavis[20424]: SQL base code        NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: SQL::Log code        NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: SQL::Quarantine      NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Lookup::SQL code     NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Lookup::LDAP code    NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: AM.PDP-in proto code loaded
Apr  1 17:39:24 CENSORED amavis[20424]: SMTP-in proto code   loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Courier proto code   NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: SMTP-out proto code  loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Pipe-out proto code  NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: BSMTP-out proto code NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Local-out proto code loaded
Apr  1 17:39:24 CENSORED amavis[20424]: OS_Fingerprint code  NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: ANTI-VIRUS code      loaded
Apr  1 17:39:24 CENSORED amavis[20424]: ANTI-SPAM code       loaded
Apr  1 17:39:24 CENSORED amavis[20424]: ANTI-SPAM-SA code    loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Unpackers code       loaded
Apr  1 17:39:24 CENSORED amavis[20424]: DKIM code            NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Tools code           NOT loaded
Apr  1 17:39:24 CENSORED amavis[20424]: Found $file            at 
/usr/bin/file
Apr  1 17:39:24 CENSORED amavis[20424]: No $dspam,             not using it
Apr  1 17:39:24 CENSORED amavis[20424]: No $altermime,         not using it
Apr  1 17:39:24 CENSORED amavis[20424]: Internal decoder for .mail
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .F
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .Z    at 
/bin/uncompress
Apr  1 17:39:24 CENSORED amavis[20424]: Internal decoder for .gz
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .gz   at 
/bin/gzip -d (backup, not used)
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .bz2  at 
/bin/bzip2 -d
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .lzo  at 
/usr/bin/lzop -d
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .rpm 
tried: rpm2cpio.pl, rpm2cpio
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .cpio 
tried: pax
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .cpio at 
/bin/cpio
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .tar 
tried: pax
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .tar  at 
/bin/cpio
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .deb  at 
/usr/bin/ar
Apr  1 17:39:24 CENSORED amavis[20424]: Internal decoder for .zip
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .7z 
tried: 7zr, 7za, 7z
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .rar
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .arj  at 
/usr/bin/arj
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .arc  at 
/usr/bin/arc
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .zoo  at 
/usr/bin/zoo
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .lha
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .doc 
tried: ripole
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .cab  at 
/usr/bin/cabextract
Apr  1 17:39:24 CENSORED amavis[20424]: No decoder for       .tnef
Apr  1 17:39:24 CENSORED amavis[20424]: Internal decoder for .tnef
Apr  1 17:39:24 CENSORED amavis[20424]: Found decoder for    .exe  at 
/usr/bin/arj
Apr  1 17:39:24 CENSORED amavis[20424]: Using primary internal av 
scanner code for ClamAV-clamd
Apr  1 17:39:24 CENSORED amavis[20424]: Using primary internal av 
scanner code for check-jpeg
Apr  1 17:39:24 CENSORED amavis[20424]: Found secondary av scanner 
ClamAV-clamscan at /usr/bin/clamscan
Apr  1 17:39:24 CENSORED amavis[20424]: Found secondary av scanner FRISK 
F-Prot Antivirus at /usr/local/bin/f-prot
Apr  1 17:39:24 CENSORED amavis[20424]: Creating db in 
/var/lib/amavis/db/; BerkeleyDB 0.34, libdb 4.6
Apr  1 17:39:24 CENSORED amavis[20424]: SpamControl: initializing 
Mail::SpamAssassin
Apr  1 17:39:24 CENSORED amavis[20424]: SpamAssassin debug facilities: 
info,all
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: logger: adding 
facilities: info, all
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: logger: logging level is DBG
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: generic: SpamAssassin 
version 3.2.5
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: score set 0 chosen.
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: running in taint 
mode? yes
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: taint mode: 
deleting unsafe environment variables, resetting PATH
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: PATH included 
'/usr/local/sbin', keeping
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: PATH included 
'/usr/local/bin', keeping
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: PATH included 
'/usr/sbin', keeping
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: PATH included 
'/sbin', keeping
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: PATH included 
'/usr/bin', keeping
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: PATH included 
'/bin', keeping
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: util: final PATH set to: 
/usr/local/sbin:/usr/local/bin:/usr/sbin:/sbin:/usr/bin:/bin
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: dns: no ipv6
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: dns: is 
Net::DNS::Resolver available? yes
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: dns: Net::DNS version: 0.63
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: ignore: test message to 
precompile patterns and load modules
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: using 
"/etc/spamassassin" for site rules pre files
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/etc/spamassassin/init.pre
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/etc/spamassassin/v310.pre
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/etc/spamassassin/v312.pre
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/etc/spamassassin/v320.pre
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: using 
"/usr/share/spamassassin" for sys rules pre files
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: using 
"/usr/share/spamassassin" for default rules dir
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/10_default_prefs.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_advance_fee.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_body_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_compensate.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_dnsbl_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_drugs.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_dynrdns.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_fake_helo_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_head_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_html_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_imageinfo.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_meta_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_net_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_phrases.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_porn.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_ratware.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_uri_tests.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/20_vbounce.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/23_bayes.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_accessdb.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_antivirus.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_asn.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_dcc.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_dkim.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_domainkeys.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_hashcash.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_pyzor.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_razor2.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_replace.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_spf.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_textcat.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/25_uribl.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/30_text_de.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/30_text_fr.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/30_text_it.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/30_text_nl.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/30_text_pl.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/30_text_pt_br.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/50_scores.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_awl.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_shortcircuit.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_whitelist.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_whitelist_dk.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_whitelist_dkim.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_whitelist_spf.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/60_whitelist_subject.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/72_active.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/usr/share/spamassassin/72_removed.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: using 
"/etc/spamassassin" for site rules dir
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/etc/spamassassin/65_debian.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: config: read file 
/etc/spamassassin/local.cf
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::URIDNSBL from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::Hashcash from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::SPF from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::Pyzor from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: pyzor: network tests on, 
attempting Pyzor
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::Razor2 from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: razor2: razor2 is 
available, version 2.84
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::SpamCop from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: reporter: network tests 
on, attempting SpamCop
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::AWL from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::WhiteListSubject from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::MIMEHeader from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::ReplaceTags from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::Check from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::HTTPSMismatch from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::URIDetail from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::Bayes from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::BodyEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::DNSEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::HTMLEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::HeaderEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::MIMEEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::RelayEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::URIEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::WLBLEval from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::VBounce from @INC
Apr  1 17:39:24 CENSORED amavis[20424]: SA dbg: plugin: loading 
Mail::SpamAssassin::Plugin::ImageInfo from @INC
Apr  1 17:39:25 CENSORED amavis[20424]: SA info: config: failed to parse 
line, skipping, in "/etc/spamassassin/local.cf": 
bayes_auto_learn_threshold_nospam 1.0
Apr  1 17:39:25 CENSORED amavis[20424]: SA info: config: failed to parse 
line, skipping, in "/etc/spamassassin/local.cf": use_dcc 1
Apr  1 17:39:25 CENSORED amavis[20424]: SA info: config: failed to parse 
line, skipping, in "/etc/spamassassin/local.cf": dcc_timeout 5
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_9B90B 
merged duplicates: __MO_OL_C65FA
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __XM_OL_22B61 
merged duplicates: __XM_OL_A842E
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_07794 
merged duplicates: __MO_OL_8627E __MO_OL_F3B05
Apr  1 17:39:25 CENSORED amavis[20424]: SA 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
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: FH_MSGID_01C67 
merged duplicates: __MSGID_VGA
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: 
FS_NEW_SOFT_UPLOAD merged duplicates: HS_SUBJ_NEW_SOFTWARE
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __FH_HAS_XMSMAIL 
merged duplicates: __HAS_MSMAIL_PRI
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_015D5 
merged duplicates: __MO_OL_6554A
Apr  1 17:39:25 CENSORED amavis[20424]: SA 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
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_91287 
merged duplicates: __MO_OL_B30D1 __MO_OL_CF0C0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: KAM_STOCKOTC 
merged duplicates: KAM_STOCKTIP15 KAM_STOCKTIP20 KAM_STOCKTIP21 
KAM_STOCKTIP4 KAM_STOCKTIP6
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_22B61 
merged duplicates: __MO_OL_4F240 __MO_OL_ADFF7
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_812FF 
merged duplicates: __MO_OL_BC7E6
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_25340 
merged duplicates: __MO_OL_4EEDB __MO_OL_7533E
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_58CB5 
merged duplicates: __MO_OL_B4B40
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __DOS_HAS_ANY_URI 
merged duplicates: __HAS_ANY_URI
Apr  1 17:39:25 CENSORED amavis[20424]: SA 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 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
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_72641 
merged duplicates: __MO_OL_A842E
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_F475E 
merged duplicates: __MO_OL_FF5C8
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: __MO_OL_4BF4C 
merged duplicates: __MO_OL_F6D01
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: conf: finish parsing
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: plugin: 
Mail::SpamAssassin::Plugin::ReplaceTags=HASH(0xa3d5890) implements 
'finish_parsing_end', priority 0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: replacetags: replacing tags
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: replacetags: done 
replacing tags
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: bayes: tie-ing to DB 
file R/O /var/lib/amavis/.spamassassin/bayes_toks
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: bayes: tie-ing to DB 
file R/O /var/lib/amavis/.spamassassin/bayes_seen
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: bayes: found bayes db 
version 3
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: bayes: DB journal sync: 
last sync: 1238591884
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: config: score set 3 chosen.
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: message: main message 
type: text/plain
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: message: ---- MIME 
PARSER START ----
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: message: parsing normal part
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: message: ---- MIME 
PARSER END ----
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: plugin: 
Mail::SpamAssassin::Plugin::DNSEval=HASH(0xa3d6320) implements 
'check_start', priority 0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: plugin: 
Mail::SpamAssassin::Plugin::Check=HASH(0xa729ad0) implements 
'check_main', priority 0
Apr  1 17:39:25 CENSORED amavis[20424]: SA 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
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: metadata: 
X-Spam-Relays-Trusted:
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: metadata: 
X-Spam-Relays-Untrusted:
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: metadata: 
X-Spam-Relays-Internal:
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: metadata: 
X-Spam-Relays-External:
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: message: no encoding 
detected
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: plugin: 
Mail::SpamAssassin::Plugin::URIDNSBL=HASH(0x9640e78) implements 
'parsed_metadata', priority 0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: no ipv6
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: is 
Net::DNS::Resolver available? yes
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: Net::DNS version: 0.63
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: name server: 
127.0.0.1, LocalAddr: 0.0.0.0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: resolver socket rx 
buffer size is 109568 bytes
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: dns_available set 
to yes in config file, skipping test
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: uridnsbl: domains to query:
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
sa-other.bondedsender.org., set bsp-untrusted
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
plus.bondedsender.org., set ssc-firsttrusted
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
combined.njabl.org., set njabl
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
bl.spamcop.net., set spamcop
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
zen.spamhaus.org., set zen-lastexternal
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
dnsbl.sorbs.net., set sorbs-lastexternal
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
dnsbl.sorbs.net., set sorbs
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
zen.spamhaus.org., set zen-lastexternal
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
sa-accredit.habeas.com., set habeas-firsttrusted
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
list.dnswl.org., set dnswl-firsttrusted
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
sa-trusted.bondedsender.org., set bsp-firsttrusted
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
zen.spamhaus.org., set zen
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: dns: checking RBL 
iadb.isipp.com., set iadb-firsttrusted
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: -1000
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: eval: all '*From' addrs: 
ignore at compiling.spamassassin.taint.org
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: eval: all '*To' addrs:
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: -950
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: -900
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: -400
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: 0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=0
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
__MISSING_REF ======> got hit: "UNSET"
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
__MSGID_OK_HOST ======> got hit: "@spamassassin_spamd_init>"
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
__MSGID_OK_DIGITS ======> got hit: "1238600364"
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
__MSOE_MID_WRONG_CASE ======> got hit: "
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: Message-Id: "
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
__HAS_MSGID ======> got hit: "<"
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
__SANE_MSGID ======> got hit: "<1238600364.53905 at spamassassin_spamd_init>
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: "
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: rules: ran header rule 
MISSING_DATE ======> got hit: "UNSET"
Apr  1 17:39:25 CENSORED amavis[20424]: SA dbg: spf: checking to see if 
the message has a Received-SPF header that we can use
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: cannot load 
Mail::SPF module or create Mail::SPF::Server object: Can't locate 
Mail/SPF.pm in @INC (@INC contains: lib /etc/perl 
/usr/local/lib/perl/5.10.0 /usr/local/share/perl/5.10.0 /usr/lib/perl5 
/usr/share/perl5 /usr/lib/perl/5.10 /usr/share/perl/5.10 
/usr/local/lib/site_perl) at 
/usr/share/perl5/Mail/SpamAssassin/Plugin/SPF.pm line 390.
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: attempting to use 
legacy Mail::SPF::Query module instead
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: using 
Mail::SPF::Query for SPF checks
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: no suitable relay 
for spf use found, skipping SPF-helo check
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: already checked for 
Received-SPF headers, proceeding with DNS based checks
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: no suitable relay 
for spf use found, skipping SPF check
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: ran eval rule 
NO_RELAYS ======> got hit (1)
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: ran eval rule 
__GATED_THROUGH_RCVD_REMOVER ======> got hit (1)
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: 
def_spf_whitelist_from: already checked spf and didn't get pass, 
skipping whitelist check
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: ran eval rule 
MISSING_HEADERS ======> got hit (1)
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: spf: whitelist_from_spf: 
already checked spf and didn't get pass, skipping whitelist check
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=1.292
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: ran body rule 
__NONEMPTY_BODY ======> got hit: "I"
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=1.292
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: eval: stock info total: 0
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=1.292
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=1.292
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:26 CENSORED amavis[20424]: SA dbg: info: entering 
helper-app run mode
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: info: leaving helper-app 
run mode
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: razor2: part=0 engine=4 
contested=0 confidence=0
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: razor2: results: spam? 0
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: razor2: results: engine 
8, highest cf score: 0
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: razor2: results: engine 
4, highest cf score: 0
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: util: current PATH is: 
/usr/local/sbin:/usr/local/bin:/usr/sbin:/sbin:/usr/bin:/bin
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: util: executable for 
pyzor was found at /usr/bin/pyzor
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: pyzor: pyzor is 
available: /usr/bin/pyzor
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: info: entering 
helper-app run mode
Apr  1 17:39:28 CENSORED amavis[20424]: SA dbg: pyzor: opening pipe: 
/usr/bin/pyzor check < /var/lib/amavis/tmp/.spamassassin20424La3h8Dtmp
Apr  1 17:39:28 CENSORED amavis[20425]: SA dbg: util: setuid: ruid=115 
euid=115
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: pyzor: killed stale 
helper [20425]
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: pyzor: [20425] 
terminated: exit=0x000f
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: info: leaving helper-app 
run mode
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: pyzor: check timed out 
after 3.5 seconds
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: 500
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: dns: harvest_dnsbl_queries
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=1.292
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: meta test 
DIGEST_MULTIPLE has undefined dependency 'DCC_CHECK'
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: check: running tests for 
priority: 1000
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running head 
tests; score so far=3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled head tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: locker: safe_lock: 
created 
/var/lib/amavis/.spamassassin/auto-whitelist.lock.CENSORED.CENSORED.at.20424
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: locker: safe_lock: 
trying to get lock on /var/lib/amavis/.spamassassin/auto-whitelist with 
0 retries
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: locker: safe_lock: link 
to /var/lib/amavis/.spamassassin/auto-whitelist.lock: link ok
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: auto-whitelist: tie-ing 
to DB file of type DB_File R/W in 
/var/lib/amavis/.spamassassin/auto-whitelist
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: auto-whitelist: db-based 
ignore at compiling.spamassassin.taint.org|ip=none scores 0/0
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: auto-whitelist: AWL 
active, pre-score: 3.053, autolearn score: 3.053, mean: undef, IP: undef
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: auto-whitelist: DB addr 
list: untie-ing and unlocking
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: auto-whitelist: DB addr 
list: file locked, breaking lock
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: locker: safe_unlock: 
unlink /var/lib/amavis/.spamassassin/auto-whitelist.lock
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: auto-whitelist: post 
auto-whitelist score: 3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running body 
tests; score so far=3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled body tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running uri 
tests; score so far=3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled uri tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running rawbody 
tests; score so far=3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled rawbody 
tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running full 
tests; score so far=3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled full tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: running meta 
tests; score so far=3.053
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: rules: compiled meta tests
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: check: is spam? 
score=3.053 required=5
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: check: 
tests=MISSING_DATE,MISSING_HEADERS,MISSING_SUBJECT,NO_RECEIVED,NO_RELAYS
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: check: 
subtests=__GATED_THROUGH_RCVD_REMOVER,__HAS_MSGID,__MISSING_REF,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__MSOE_MID_WRONG_CASE,__NONEMPTY_BODY,__SANE_MSGID,__UNUSABLE_MSGID
Apr  1 17:39:31 CENSORED amavis[20424]: SA dbg: bayes: untie-ing
Apr  1 17:39:31 CENSORED amavis[20424]: SpamControl: init_pre_fork on 
SpamAssassin done
Apr  1 17:39:31 CENSORED amavis[20426]: TIMING [total 10 ms] - bdb-open: 
9 (100%)100, rundown: 0 (0%)100
Apr  1 17:39:31 CENSORED amavis[20426]: SpamControl: init_child on 
SpamAssassin done
Apr  1 17:39:31 CENSORED amavis[20427]: TIMING [total 10 ms] - bdb-open: 
10 (100%)100, rundown: 0 (0%)100
Apr  1 17:39:31 CENSORED amavis[20427]: SpamControl: init_child on 
SpamAssassin done

--------------------------------------------


Wenn eine normale Mail einlangt, spricht das Syslog:

Apr  1 17:52:40 CENSORED amavis[20447]: (20447-01) Passed CLEAN, 
[83.64.124.110] [83.64.124.110] <m.mueller at hausstein.at> -> 
<max.muster at derist.org>, Message-ID: <49D38DBD.1010406 at hausstein.at>, 
mail_id: gZHDSnBgXhfB, Hits: 1.257, size: 1334, queued_as: 181CD3A52F, 
3019 ms

Apr  1 17:52:40 CENSORED amavis[20447]: (20447-01) TIMING [total 3025 
ms] - SMTP greeting: 8 (0%)0, SMTP EHLO: 3 (0%)0, SMTP pre-MAIL: 1 
(0%)0, mkdir tempdir: 1 (0%)0, create email.txt: 1 (0%)0, SMTP 
pre-DATA-flush: 6 (0%)1, SMTP DATA: 34 (1%)2, check_init: 2 (0%)2, 
digest_hdr: 1 (0%)2, digest_body: 1 (0%)2, gen_mail_id: 2 (0%)2, mkdir 
parts: 2 (0%)2, mime_decode: 19 (1%)3, get-file-type0: 1 (0%)3, 
parts_decode: 0 (0%)3, check_header: 2 (0%)3, AV-scan-1: 3 (0%)3, 
AV-scan-2: 0 (0%)3, spam-wb-list: 3 (0%)3, SA parse: 9 (0%)3, SA check: 
2733 (90%)94, update_cache: 9 (0%)94, decide_mail_destiny: 1 (0%)94, 
fwd-connect: 123 (4%)98, fwd-mail-pip: 5 (0%)98, fwd-rcpt-pip: 0 (0%)98, 
fwd-data-chkpnt: 0 (0%)98, write-header: 1 (0%)98, fwd-data-contents: 0 
(0%)98, fwd-end-chkpnt: 28 (1%)99, prepare-dsn: 1 (0%)99, 
main_log_entry: 20 (1%)100, update_snmp: 2 (0%)100, SMTP pre-response: 1 
(0%)100, SMTP response: 0 (0%)100, unlink-0-files: 0 (0%)100, rundown: 1 
(0%)100


Die Prüfung dürfte also erfolgreich sein, dennoch sehe ich es nicht im 
Mailheader:


 From - Wed Apr  1 17:52:53 2009
X-Mozilla-Status: 0001
X-Mozilla-Status2: 00000000
Return-Path: <m.mueller at hausstein.at>
X-Original-To: max.muster at derist.org
Delivered-To: max.muster at derist.org
Received: from localhost (localhost [127.0.0.1])
	by mail.CENSORED.org (Postfix) with ESMTP id 181CD3A52F
	for <max.muster at derist.org>; Wed,  1 Apr 2009 17:52:40 +0200 (CEST)
X-Virus-Scanned: Debian amavisd-new at mail.CENSORED.org
Received: from mail.CENSORED.org ([127.0.0.1])
	by localhost (CENSORED.CENSORED.at [127.0.0.1]) (amavisd-new, port 10024)
	with ESMTP id gZHDSnBgXhfB for <max.muster at derist.org>;
	Wed,  1 Apr 2009 17:52:37 +0200 (CEST)
Received: from CENSORED.CENSORED.at 
(83-64-124-110.wr-neustadt.xdsl-line.inode.at [83.64.124.110])
	by mail.CENSORED.org (Postfix) with ESMTP id 126C93A52E
	for <max.muster at derist.org>; Wed,  1 Apr 2009 17:52:36 +0200 (CEST)
Received: from localhost (localhost [127.0.0.1])
	by mail.CENSORED.at (Postfix) with ESMTP id B10B187292
	for <max.muster at derist.org>; Wed,  1 Apr 2009 17:52:35 +0200 (CEST)
X-Virus-Scanned: Debian amavisd-new at #homestone2.hausstein.at
Received: from mail.CENSORED.at ([127.0.0.1])
	by localhost (CENSORED.CENSORED.at [127.0.0.1]) (amavisd-new, port 10024)
	with ESMTP id E1fjnwJ2ioWX for <max.muster at derist.org>;
	Wed,  1 Apr 2009 17:52:29 +0200 (CEST)
Received: from MacPro.local (unknown [192.168.100.111])
	by mail.CENSORED.at (Postfix) with ESMTP id CF26B8719C
	for <max.muster at derist.org>; Wed,  1 Apr 2009 17:52:29 +0200 (CEST)
Message-ID: <49D38DBD.1010406 at hausstein.at>
Date: Wed, 01 Apr 2009 17:52:29 +0200
From: =?UTF-8?B?TWFydGluIE3Cn8O8bGxlciB8IFJ1ZG9sZiBIYXVzc3RlaW4gT0hH?=
  <m.mueller at hausstein.at>
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; 
rv:1.9.1b3pre) Gecko/20090218 Thunderbird/3.0b2
MIME-Version: 1.0
To: max.muster at derist.org
Subject: TESTFEU II
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit


Definitve SPAM-Mails weisen leider auch kein X-Spam-Flag aus.

Habt ihr Ideen? Oder bin ich einfach nur zu blöd um SA nach der 
Neuinstallation richtig zu konfigurieren?


Danke im Voraus!


Martin




Mehr Informationen über die Mailingliste Postfixbuch-users