Ich habe postfix, amavis-new, dovecot eingerichtet auf meinem Ubuntu 16.04 server. Irgendwie kriege ich es nicht hin, daß amavis-new überhaupt meine mails durch den spamfilter schickt (spamassassin?).
Ich habe hier mal eine Mustermail (eine von ca. 100, die täglich durch die Maschen gehen und in meiner Thunderbird inbox landen)
Return-Path: <some_spammer@carnemexicana.org> Delivered-To: mich@mydomain.org Received: from mail.mydomain.org by mydomain.org (Dovecot) with LMTP id 546yMlB7tliDZwAAXmd1zw for <mich@mydomain.org>; Wed, 01 Mar 2017 08:42:08 +0100 Received: from localhost (localhost [127.0.0.1]) by mail.mydomain.org (Postfix) with ESMTP id C620C2106AB for <mich@mydomain.org>; Wed, 1 Mar 2017 08:42:08 +0100 (CET) X-Virus-Scanned: Debian amavisd-new at mydomain.org X-Spam-Flag: NO X-Spam-Score: -0.1 X-Spam-Level: X-Spam-Status: No, score=-0.1 required=5 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, HTML_MESSAGE=0.001, SPF_PASS=-0.001] autolearn=ham autolearn_force=no Authentication-Results: mydomain.org (amavisd-new); dkim=pass (2048-bit key) header.d=carnemexicana.org Received: from mail.mydomain.org ([127.0.0.1]) by localhost (mydomain.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id eSELU7cODc3W for <mich@mydomain.org>; Wed, 1 Mar 2017 08:42:07 +0100 (CET) Received: from ber.berry.mx (ber.berry.mx [198.154.250.141]) by mail.mydomain.org (Postfix) with ESMTPS id 8FDE32106AA for <mich@mydomain.org>; Wed, 1 Mar 2017 08:42:07 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=carnemexicana.org; s=default; h=Content-Transfer-Encoding:Content-Type: MIME-Version:Message-ID:From:Date:Subject:To:Sender:Reply-To:Cc:Content-ID: Content-Description:Resent-Date:Resent-From:Resent-Sender:Resent-To:Resent-Cc :Resent-Message-ID:In-Reply-To:References:List-Id:List-Help:List-Unsubscribe: List-Subscribe:List-Post:List-Owner:List-Archive; bh=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; b=XXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXX==; Received: from mexicarne by ber.berry.mx with local (Exim 4.88) (envelope-from <some_spammer@carnemexicana.org>) id 1ciytg-0006Im-6Y for mich@mydomain.org; Wed, 01 Mar 2017 01:42:05 -0600 To: mich@mydomain.org Subject: Use this program and become shamelessly rich! X-PHP-Script: carnemexicana.org/ for 127.0.0.1 Date: Wed, 1 Mar 2017 01:42:04 -0600 From: Ethan Newman <some_spammer@carnemexicana.org> Message-ID: <61364fdeb3b2aa7d2e5f3c986855b371@carnemexicana.org> X-Priority: 3 X-Mailer: PHPMailer 5.2.9 (https://github.com/PHPMailer/PHPMailer/) MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="b1_61364fdeb3b2aa7d2e5f3c986855b371" Content-Transfer-Encoding: 8bit X-OutGoing-Spam-Status: No, score=0.0 X-AntiAbuse: This header was added to track abuse, please include it with any abuse report X-AntiAbuse: Primary Hostname - ber.berry.mx X-AntiAbuse: Original Domain - mydomain.org X-AntiAbuse: Originator/Caller UID/GID - [629 32007] / [47 12] X-AntiAbuse: Sender Address Domain - carnemexicana.org X-Get-Message-Sender-Via: ber.berry.mx: authenticated_id: mexicarne/from_h X-Authenticated-Sender: ber.berry.mx: some_spammer@carnemexicana.org X-Source: /usr/bin/php X-Source-Args: /usr/bin/php /home/mexicarne/public_html/wp-includes/js/jcrop/list.php X-Source-Dir: carnemexicana.org:/public_html/wp-includes/js/jcrop --b1_61364fdeb3b2aa7d2e5f3c986855b371 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit Attention! This letter can change your life! A group of German mathematicians invented the smart program which trading on the exchange, brings great profit and never wrongs, and it making purchases only in a 100% profit. While about it do not know others, while it is available and it€s not blacked out, use your chance and turn your life into a dream! [ http://sxxxxik.com/inxxxxxtion.php?f=14X&Dtf=AVn&6=657v ] More information is here. --b1_61364fdeb3b2aa7d2e5f3c986855b371 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit <html> <body> Attention! This letter can change your life!<br> <br> A group of German mathematicians invented the smart program which trading on the exchange, brings great profit and never wrongs, and it making purchases only in a 100% profit.<br> <br> While about it do not know others, while it is available and it€s not blacked out, use your chance and turn your life into a dream! <a href="http://sxxxxxk.com/ixxxxxon.php?f=xxxxxxxxxxxxxxxxxxxxxxxx57v">More information is here.</a><br> </body> </html> --b1_61364fdeb3b2aa7d2e5f3c986855b371--
Hier der Debug-Output von amavisd-new (Die Mail, die darin empfangen wird, ist jetzt nicht dieselbe wie in dem Beispiel.
Script started on Wed 01 Mar 2017 14:50:32 CET Trying to run amavisd-new in debug mode... Mar 1 14:50:44.806 mail.mydomain.org /usr/sbin/amavisd-new[30081]: logging initialized, log level 0, syslog: amavis.mail Mar 1 14:50:44.806 mail.mydomain.org /usr/sbin/amavisd-new[30081]: starting. /usr/sbin/amavisd-new at mail.mydomain.org amavisd-new-2.10.1 (20141025), Unicode aware, LANG="en_GB.UTF-8" Mar 1 14:50:44.807 mail.mydomain.org /usr/sbin/amavisd-new[30081]: perl=5.022001, user=, EUID: 120 (120); group=, EGID: 126 126 (126 126) Mar 1 14:50:44.832 mail.mydomain.org /usr/sbin/amavisd-new[30081]: INFO: no optional modules: unicore::lib::Nt::De.pl Unix::Getrusage Mar 1 14:50:44.832 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SpamControl: attempting to load scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin Mar 1 14:50:44.833 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SpamControl: scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin Mar 1 14:50:45.003 mail.mydomain.org /usr/sbin/amavisd-new[30081]: INFO: SA version: 3.4.1, 3.004001, no optional modules: Net::CIDR::Lite Encode::Detect Image::Info Image::Info::GIF Image::Info::JPEG Image::Info::PNG Image::Info::BMP Image::Info::TIFF Mar 1 14:50:45.003 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SpamControl: init_pre_chroot on SpamAssassin done Mar 1 14:50:45.004 mail.mydomain.org /usr/sbin/amavisd-new[30081]: socket module IO::Socket::IP, protocol families available: INET Mar 1 14:50:45.004 mail.mydomain.org /usr/sbin/amavisd-new[30081]: bind to /var/lib/amavis/amavisd.sock|unix, 127.0.0.1:10024/tcp Mar 1 14:50:45.005 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: 2017/03/01-14:50:44 Amavis (type Net::Server::PreForkSimple) starting! pid(30081) Mar 1 14:50:45.007 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Binding to UNIX socket file "/var/lib/amavis/amavisd.sock" Mar 1 14:50:45.008 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4 Mar 1 14:50:45.008 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Group Not Defined. Defaulting to EGID '126 126' Mar 1 14:50:45.008 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: User Not Defined. Defaulting to EUID '120' Mar 1 14:50:45.008 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Setting up serialization via flock Mar 1 14:50:45.009 mail.mydomain.org /usr/sbin/amavisd-new[30081]: after_chroot_init: EUID: 120 (120); EGID: 126 126 (126 126) Mar 1 14:50:45.009 mail.mydomain.org /usr/sbin/amavisd-new[30081]: 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/21-ubuntu_defaults, /etc/amavis/conf.d/25-amavis_helpers, /etc/amavis/conf.d/30-template_localization, /etc/amavis/conf.d/40-policy_banks, /etc/amavis/conf.d/50-user Mar 1 14:50:45.017 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Amavis::Conf 2.404 Mar 1 14:50:45.017 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Archive::Zip 1.56 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module BerkeleyDB 0.55 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Compress::Raw::Zlib 2.068 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Compress::Zlib 2.068 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Crypt::OpenSSL::RSA 0.28 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module DB_File 1.835 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Digest::MD5 2.54 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Digest::SHA 5.95 Mar 1 14:50:45.018 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Encode 2.72 Mar 1 14:50:45.019 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module File::Temp 0.2304 Mar 1 14:50:45.019 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module IO::Socket::INET6 2.72 Mar 1 14:50:45.019 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module IO::Socket::IP 0.37 Mar 1 14:50:45.019 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module MIME::Entity 5.507 Mar 1 14:50:45.019 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module MIME::Parser 5.507 Mar 1 14:50:45.019 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module MIME::Tools 5.507 Mar 1 14:50:45.020 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Mail::DKIM::Signer 0.4 Mar 1 14:50:45.020 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Mail::DKIM::Verifier 0.4 Mar 1 14:50:45.020 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Mail::Header 2.13 Mar 1 14:50:45.020 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Mail::Internet 2.13 Mar 1 14:50:45.020 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Mail::SPF v2.009 Mar 1 14:50:45.020 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Mail::SpamAssassin 3.004001 Mar 1 14:50:45.021 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Net::DNS 0.81 Mar 1 14:50:45.021 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Net::LibIDN 0.12 Mar 1 14:50:45.021 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Net::Server 2.008 Mar 1 14:50:45.021 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module NetAddr::IP 4.078 Mar 1 14:50:45.021 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Razor2::Client::Version 2.84 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Scalar::Util 1.41 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Socket 2.018 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Socket6 0.25 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Time::HiRes 1.9726 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module URI 1.71 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Module Unix::Syslog 1.1 Mar 1 14:50:45.022 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Amavis::ZMQ code NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Amavis::DB code loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SQL base code NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SQL::Log code NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SQL::Quarantine NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Lookup::SQL code NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Lookup::LDAP code NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: AM.PDP-in proto code loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SMTP-in proto code loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Courier proto code NOT loaded Mar 1 14:50:45.023 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SMTP-out proto code loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Pipe-out proto code NOT loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: BSMTP-out proto code NOT loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Local-out proto code loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: OS_Fingerprint code NOT loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: ANTI-VIRUS code NOT loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: ANTI-SPAM code loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: ANTI-SPAM-EXT code NOT loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: ANTI-SPAM-C code NOT loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: ANTI-SPAM-SA code loaded Mar 1 14:50:45.024 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Unpackers code loaded Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: DKIM code loaded Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Tools code NOT loaded Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found $file at /usr/bin/file Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No $altermime, not using it Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Internal decoder for .mail Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .Z at /bin/uncompress Mar 1 14:50:45.025 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .gz at /bin/gzip -d Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Internal decoder for .gz (backup, not used) Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .bz2 at /bin/bzip2 -d Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .xz at /usr/bin/xz -dc Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .lzma at /usr/bin/xz -dc --format=lzma Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .lrz, tried: lrzip -q -k -d -o -, lrzcat -q -k Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .lzo, tried: lzop -d Mar 1 14:50:45.026 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .lz4, tried: lz4c -d Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .rpm, tried: rpm2cpio.pl, rpm2cpio Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .cpio at /bin/pax Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .tar at /bin/pax Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Found decoder for .deb at /usr/bin/ar Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .rar, tried: unrar-free Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .arj, tried: arj, unarj Mar 1 14:50:45.027 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .arc, tried: nomarch, arc Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .zoo, tried: zoo Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .doc, tried: ripole Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .cab, tried: cabextract Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Internal decoder for .tnef Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .zip, tried: 7za, 7z Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .kmz, tried: 7za, 7z Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Internal decoder for .zip Mar 1 14:50:45.028 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Internal decoder for .kmz Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .7z, tried: 7zr, 7za, 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .jar, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .arj, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .rar, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .swf, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .lha, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .iso, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .cab, tried: 7z Mar 1 14:50:45.029 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .rpm, tried: 7z Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No ext program for .exe, tried: unrar-free; arj, unarj Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .7z Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .F Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .arc Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .arj Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .cab Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .doc Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .exe Mar 1 14:50:45.030 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .iso Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .jar Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .lha Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .lrz Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .lz4 Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .lzo Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .rar Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .rpm Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .swf Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: No decoder for .zoo Mar 1 14:50:45.031 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Using internal spam scanner code for SpamAssassin Mar 1 14:50:45.032 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Deleting db files snmp.db,nanny.db,__db.002,__db.003,__db.001 in /var/lib/amavis/db Mar 1 14:50:45.032 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Creating db in /var/lib/amavis/db/; BerkeleyDB 0.55, libdb 5.3 Mar 1 14:50:45.055 mail.mydomain.org /usr/sbin/amavisd-new[30081]: initializing Mail::SpamAssassin (0) Mar 1 14:50:45.055 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SpamAssassin debug facilities: info Mar 1 14:50:45.787 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SA info: zoom: able to use 344/344 'body_0' compiled rules (100%) Mar 1 14:50:46.039 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SpamAssassin loaded plugins: AskDNS, AutoLearnThreshold, Bayes, BodyEval, Check, DKIM, DNSEval, FreeMail, HTMLEval, HTTPSMismatch, Hashcash, HeaderEval, ImageInfo, MIMEEval, MIMEHeader, Pyzor, Razor2, RelayEval, ReplaceTags, Rule2XSBody, SPF, SpamCop, TextCat, URIDNSBL, URIDetail, URIEval, VBounce, WLBLEval, WhiteListSubject Mar 1 14:50:46.040 mail.mydomain.org /usr/sbin/amavisd-new[30081]: SpamControl: init_pre_fork on SpamAssassin done Mar 1 14:50:46.040 mail.mydomain.org /usr/sbin/amavisd-new[30081]: extra modules loaded after daemonizing/chrooting: /etc/perl/Net/libnet.cfg, /usr/lib/i386-linux-gnu/perl5/5.22/auto/Net/SSLeay/autosplit.ix, /usr/lib/i386-linux-gnu/perl5/5.22/auto/Net/SSLeay/randomize.al, IO/Socket/SSL.pm, IO/Socket/SSL/PublicSuffix.pm, Mail/SpamAssassin/CompiledRegexps/body_0.pm, Mail/SpamAssassin/Plugin/FreeMail.pm, Mail/SpamAssassin/Plugin/SpamCop.pm, Net/Cmd.pm, Net/Config.pm, Net/SMTP.pm, Net/SSLeay.pm Mar 1 14:50:46.041 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Beginning prefork (2 processes) Mar 1 14:50:46.041 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Starting "2" children Mar 1 14:50:46.043 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Parent ready for children. Mar 1 14:50:46.045 mail.mydomain.org /usr/sbin/amavisd-new[30099]: Net::Server: Child Preforked (30099) Mar 1 14:50:46.045 mail.mydomain.org /usr/sbin/amavisd-new[30100]: Net::Server: Child Preforked (30100) Mar 1 14:50:46.045 mail.mydomain.org /usr/sbin/amavisd-new[30100]: entered child_init_hook Mar 1 14:50:46.046 mail.mydomain.org /usr/sbin/amavisd-new[30099]: entered child_init_hook Mar 1 14:50:46.049 mail.mydomain.org /usr/sbin/amavisd-new[30100]: SpamControl: init_child on SpamAssassin done Mar 1 14:50:46.050 mail.mydomain.org /usr/sbin/amavisd-new[30099]: SpamControl: init_child on SpamAssassin done Mar 1 14:52:52.946 mail.mydomain.org /usr/sbin/amavisd-new[30099]: Net::Server: 2017/03/01-14:52:52 CONNECT TCP Peer: "[127.0.0.1]:41484" Local: "[127.0.0.1]:10024" Mar 1 14:52:52.948 mail.mydomain.org /usr/sbin/amavisd-new[30099]: loaded base policy bank Mar 1 14:52:52.949 mail.mydomain.org /usr/sbin/amavisd-new[30099]: lookup_ip_acl (inet_acl) arr.obj: key="127.0.0.1" matches "127.0.0.1", result=1 Mar 1 14:52:52.950 mail.mydomain.org /usr/sbin/amavisd-new[30099]: process_request: fileno sock=12, STDIN=0, STDOUT=1 Mar 1 14:52:52.951 mail.mydomain.org /usr/sbin/amavisd-new[30099]: get_deadline switch_to_my_time(new request) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.951 mail.mydomain.org /usr/sbin/amavisd-new[30099]: prolong_timer switch_to_my_time(new request): timer 288, was 0, deadline in 480.0 s Mar 1 14:52:52.952 mail.mydomain.org /usr/sbin/amavisd-new[30099]: process_request: suggested_protocol="" on a TCP socket Mar 1 14:52:52.953 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Mar 1 14:52:52.954 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.954 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 4: was busy, 7.3 ms, total idle 0.000 s, busy 0.007 s Mar 1 14:52:52.955 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp readline: read 24 bytes, new size: 24 Mar 1 14:52:52.955 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 5: was idle, 0.6 ms, total idle 0.001 s, busy 0.007 s Mar 1 14:52:52.955 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) SMTP< EHLO mail.mydomain.org\r\n Mar 1 14:52:52.955 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx SMTP EHLO) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx SMTP EHLO): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-[127.0.0.1] Mar 1 14:52:52.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-VRFY Mar 1 14:52:52.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-PIPELINING Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-SIZE Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-ENHANCEDSTATUSCODES Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-8BITMIME Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-SMTPUTF8 Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250-DSN Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 6: was busy, 2.6 ms, total idle 0.001 s, busy 0.010 s Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp readline: read 259 bytes, new size: 259 Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.010 s Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP< XFORWARD NAME=sqlite.org ADDR=67.18.92.124 PORT=58030\r\n Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250 2.5.0 Ok XFORWARD Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 6: was busy, 0.8 ms, total idle 0.001 s, busy 0.011 s Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.011 s Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP< XFORWARD PROTO=ESMTP HELO=sqlite.org IDENT=A92292106AA SOURCE=REMOTE\r\n Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250 2.5.0 Ok XFORWARD Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 6: was busy, 0.7 ms, total idle 0.001 s, busy 0.011 s Mar 1 14:52:52.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.011 s Mar 1 14:52:52.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP< MAIL FROM:<sqlite-users-bounces@mailinglists.sqlite.org> SIZE=4808\r\n Mar 1 14:52:52.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx SMTP MAIL) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx SMTP MAIL): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) check_mail_begin_task: task_count=1 Mar 1 14:52:52.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) TempDir::prepare_dir: created directory /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48 Mar 1 14:52:52.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) TempDir::prepare_file: creating file /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48/email.txt Mar 1 14:52:52.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) TempDir::prepare_file: layers: unix,perlio Mar 1 14:52:52.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_ip_acl (client_ipaddr_policy) arr.obj: key="67.18.92.124", no match Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [debug_sender] => undef, "sqlite-users-bounces@mailinglists.sqlite.org" does not match Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) mesage size set to a declared size 4808 Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250 2.1.0 Sender <sqlite-users-bounces@mailinglists.sqlite.org> OK Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 6: was busy, 2.6 ms, total idle 0.001 s, busy 0.014 s Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.014 s Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP< RCPT TO:<mich@mydomain.org> ORCPT=rfc822;mich@mydomain.org\r\n Mar 1 14:52:52.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx SMTP RCPT) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx SMTP RCPT): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup => undef, "mich@mydomain.org", no lookup tables Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 250 2.1.5 Recipient <mich@mydomain.org> OK Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 6: was busy, 0.9 ms, total idle 0.001 s, busy 0.015 s Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.015 s Mar 1 14:52:52.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP< DATA\r\n Mar 1 14:52:52.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx SMTP DATA) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx SMTP DATA): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP :10024 /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48: <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org> SIZE=4808 Received: from mail.mydomain.org ([127.0.0.1]) by localhost (mail.mydomain.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <mich@mydomain.org>; Wed, 1 Mar 2017 14:52:52 +0100 (CET) Mar 1 14:52:52.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Mar 1 14:52:52.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, smtp response sent Mar 1 14:52:52.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) switch_to_client_time 480 s, receiving data Mar 1 14:52:52.996 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp copy: read 4817 bytes into buffer, new size: 4817 Mar 1 14:52:52.997 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp copy: 6 bytes still buffered at end Mar 1 14:52:52.997 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline switch_to_my_time(rx data-end) - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:52.998 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer switch_to_my_time(rx data-end): timer 288, was 480, deadline in 480.0 s Mar 1 14:52:52.998 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ESMTP< .<CR><LF> Mar 1 14:52:52.999 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline get_body_digest - deadline in 480.0 s, set to 30.000 s Mar 1 14:52:53.000 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline digest_pre - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:53.000 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer digest_pre: timer 288, was 288, deadline in 480.0 s Mar 1 14:52:53.001 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) DNS resolver created, UDP payload size 1220, NS: 213.133.98.98, 213.133.99.99, 213.133.100.100 Mar 1 14:52:53.001 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_body_digest: reading header section from memory Mar 1 14:52:53.002 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_body_digest: feeding header section to DKIM verifier Mar 1 14:52:53.004 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_body_digest: sending h/b separator to DKIM Mar 1 14:52:53.005 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline digest_hdr - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:53.005 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer digest_hdr: timer 288, was 288, deadline in 480.0 s Mar 1 14:52:53.005 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_body_digest: reading mail body from memory, 1 DKIM signatures Mar 1 14:52:53.011 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline digest_body - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:53.011 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer digest_body: timer 288, was 287, deadline in 480.0 s Mar 1 14:52:53.011 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_body_digest: message size 4808, header+sep 3788, body 1020 Mar 1 14:52:53.011 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) body type (8bit-MIMEtransport): unlabeled, good (h=0, b=0) Mar 1 14:52:53.011 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) body hash: 05867ed930e95c9287fc518c67a0ffad Mar 1 14:52:53.012 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) references: <1255DC43-5010-4EA9-827E-4F3798A3E2F8@bigfraud.org>, <CAEK7D32_VBeRkGuVFBR-JM2ZGtZB00TRWObirz2RuLC_EVLR4A@mail.gmail.com> Mar 1 14:52:53.012 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ip_from_received: 67.18.92.124 Mar 1 14:52:53.013 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ip_from_received: IPv6:::1 Mar 1 14:52:53.013 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ip_from_received: 209.85.217.171 Mar 1 14:52:53.013 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ip_from_received: no IP address in: by mail-ua0-f171.google.com with SMTP id 72so41275681uaf.3\n for <sqlite-users@mailinglists.sqlite.org>;\n Wed, 01 Mar 2017 05:52:48 -0800 (PST)\n Mar 1 14:52:53.014 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) ip_from_received: no IP address in: by 10.103.120.83 with HTTP; Wed, 1 Mar 2017 05:52:46 -0800 (PST)\n Mar 1 14:52:53.014 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_ip_acl (public_nets) arr.obj: key="127.0.0.1" matches "!127.0.0.0/8", result=0 Mar 1 14:52:53.014 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_ip_acl (public_nets) arr.obj: key="67.18.92.124" matches "::ffff:0:0/96", result=1 Mar 1 14:52:53.014 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_ip_acl (public_nets) arr.obj: key="::1" matches "!::1", result=0 Mar 1 14:52:53.014 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_ip_acl (public_nets) arr.obj: key="209.85.217.171" matches "::ffff:0:0/96", result=1 Mar 1 14:52:53.015 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) trace: ESMTP://[127.0.0.1]:41484 < ESMTP://[67.18.92.124]:58030 < ESMTP://::1 < ESMTPS://209.85.217.171 < SMTP://x < HTTP://x Mar 1 14:52:53.015 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) dkim: public key s=20161025 d=gmail.com k=rsa, 2048-bit key Mar 1 14:52:53.015 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) dkim: FAILED third-party signature by d=gmail.com, From: <drh@sqlite.org>, a=rsa-sha256, c=relaxed/relaxed, s=20161025, i=@gmail.com, m.list(ml:sqlite-users.mailinglists.sqlite.org), fail (message has been altered) Mar 1 14:52:53.015 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Original mail size: 4808; quota set to: 2404000 bytes (fmin=5, fmax=500, qmin=102400, qmax=314572800) Mar 1 14:52:53.015 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Checking: sbh7deZSzOVI [67.18.92.124] <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org> Mar 1 14:52:53.016 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) 2822.From: <drh@sqlite.org>, 2822.Sender: <sqlite-users-bounces@mailinglists.sqlite.org> Mar 1 14:52:53.016 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_acl(mich@mydomain.org) matches key ".mydomain.org", result=1 Mar 1 14:52:53.016 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [local_domains] => true, "mich@mydomain.org" matches, result="1", matching_key=".mydomain.org" Mar 1 14:52:53.016 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (scalar) matches, result="1" Mar 1 14:52:53.016 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [bypass_virus_checks] => true, "mich@mydomain.org" matches, result="1", matching_key="(constant:1)" Mar 1 14:52:53.016 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [bypass_banned_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.017 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [bypass_spam_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.017 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Extracting mime components from a string Mar 1 14:52:53.020 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Issued a new file name: p001 Mar 1 14:52:53.021 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Charging 744 bytes to remaining quota 2404000 (out of 2404000, (0%)) - by mime_decode Mar 1 14:52:53.021 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) p001 1 Content-Type: text/plain, size: 744 B, name: Mar 1 14:52:53.022 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline mime_decode - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:53.022 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer mime_decode: timer 288, was 288, deadline in 480.0 s Mar 1 14:52:53.022 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline mime_decode-1 - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:53.022 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer mime_decode-1: timer 288, was 288, deadline in 480.0 s Mar 1 14:52:53.022 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) decode_parts: level=1, #parts=1 : p001 Mar 1 14:52:53.022 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) running file(1) on 1 files, arglist size 18 Mar 1 14:52:53.024 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) run_command: [30109] /usr/bin/file p001 </dev/null 2>&1 Mar 1 14:52:53.030 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) result line from file(1): p001: ASCII text\n Mar 1 14:52:53.031 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_re("ASCII text") matches key "(?^i:^(ASCII|text)\\b)", result="asc" Mar 1 14:52:53.031 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [map_full_type_to_short_type] => true, "ASCII text" matches, result="asc", matching_key="(?^i:^(ASCII|text)\\b)" Mar 1 14:52:53.031 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) File-type of p001: ASCII text; (asc) Mar 1 14:52:53.032 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) decompose_part: p001 - atomic Mar 1 14:52:53.032 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline parts_decode - deadline in 480.0 s, set to 288.000 s Mar 1 14:52:53.032 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer parts_decode: timer 288, was 288, deadline in 480.0 s Mar 1 14:52:53.032 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [bypass_header_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) check_header: 0, OK Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [bypass_header_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Checking for banned types and filenames Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (scalar) matches, result="DEFAULT" Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [banned_filename], 1 matches for "mich@mydomain.org", results: "(constant:DEFAULT)"=>"DEFAULT" Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) collect banned table[0]: mich@mydomain.org, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0xac6a368) Mar 1 14:52:53.033 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) starting banned checks - traversing message structure tree Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) check_for_banned (p001) text/plain,.asc Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) doing banned check for mich@mydomain.org on text/plain,.asc Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_re(["text/plain",".asc"]), no matches Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [check_bann:mich@mydomain.org] => undef, ["text/plain",".asc"] does not match Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [banned_namepath_re] => undef, "P=p001\tL=1\tM=text/plain\tT=asc" does not match Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) p.path mich@mydomain.org: "P=p001,L=1,M=text/plain,T=asc" Mar 1 14:52:53.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) banned check: any=0, all=N (1) Mar 1 14:52:53.035 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) no anti-virus code loaded, skipping virus_scan Mar 1 14:52:53.035 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) wbl: checking sender <sqlite-users-bounces@mailinglists.sqlite.org>, <drh@sqlite.org> Mar 1 14:52:53.035 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [blacklist_recip<mich@mydomain.org>] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.035 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [blacklist_sender<sqlite-users-bounces@mailinglists.sqlite.org>,blacklist_sender] => undef, "sqlite-users-bounces@mailinglists.sqlite.org" does not match Mar 1 14:52:53.035 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [whitelist_recip<mich@mydomain.org>] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.036 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_acl(sqlite-users-bounces@mailinglists.sqlite.org), no match Mar 1 14:52:53.036 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [whitelist_sender<sqlite-users-bounces@mailinglists.sqlite.org>,whitelist_sender] => undef, "sqlite-users-bounces@mailinglists.sqlite.org" does not match Mar 1 14:52:53.036 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) query_keys: mich@mydomain.org, mich@, mydomain.org, .mydomain.org, .org, . Mar 1 14:52:53.036 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_hash(mich@mydomain.org) matches keys: "."=>ARRAY(0xab34c7c) Mar 1 14:52:53.036 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [score_recip<mich@mydomain.org>,score_sender], 1 matches for "mich@mydomain.org", results: "."=>[Amavis::Lookup::RE=ARRAY(0xab3422c),{}] Mar 1 14:52:53.037 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_re("sqlite-users-bounces@mailinglists.sqlite.org"), no matches Mar 1 14:52:53.037 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [score_sender<sqlite-users-bounces@mailinglists.sqlite.org>] => undef, "sqlite-users-bounces@mailinglists.sqlite.org" does not match Mar 1 14:52:53.037 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [blacklist_recip<mich@mydomain.org>] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.037 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [blacklist_sender<drh@sqlite.org>,blacklist_sender] => undef, "drh@sqlite.org" does not match Mar 1 14:52:53.037 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [whitelist_recip<mich@mydomain.org>] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.037 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_acl(drh@sqlite.org), no match Mar 1 14:52:53.038 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [whitelist_sender<drh@sqlite.org>,whitelist_sender] => undef, "drh@sqlite.org" does not match Mar 1 14:52:53.039 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) query_keys: cached mich@mydomain.org Mar 1 14:52:53.039 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_hash(mich@mydomain.org) matches keys: "."=>ARRAY(0xab34c7c) Mar 1 14:52:53.039 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [score_recip<mich@mydomain.org>,score_sender], 1 matches for "mich@mydomain.org", results: "."=>[Amavis::Lookup::RE=ARRAY(0xab3422c),{}] Mar 1 14:52:53.040 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup_re("drh@sqlite.org"), no matches Mar 1 14:52:53.041 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [score_sender<drh@sqlite.org>] => undef, "drh@sqlite.org" does not match Mar 1 14:52:53.041 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) SpamControl: calling spam scanner SpamAssassin Mar 1 14:52:53.042 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline spam_scan_sa_pre - deadline in 480.0 s, set to 476.000 s Mar 1 14:52:53.042 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer spam_scan_sa_pre: timer 476, was 288, deadline in 480.0 s Mar 1 14:52:53.043 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) SA user config: "", username: "amavis", 0, (0)mich@mydomain.org Mar 1 14:52:53.043 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) calling SA parse (0), SA vers 3.4.1, 3.004001, data as STRING_REF, recips_ind [0], user: "amavis" Mar 1 14:52:53.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline SA check - deadline in 480.0 s, set to 475.000 s Mar 1 14:52:53.046 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) CALLING SA check (0) Mar 1 14:52:53.336 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) DONE SA check (0) Mar 1 14:52:53.338 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline spam_scan_sa - deadline in 479.7 s, set to 288.000 s Mar 1 14:52:53.338 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer spam_scan_sa: timer 288, was 476, deadline in 479.7 s Mar 1 14:52:53.338 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) spam_scan: score=0.119 autolearn=no autolearn_force=no tests=[DKIM_SIGNED=0.1,RP_MATCHES_RCVD=-0.001,T_DKIM_INVALID=0.01,T_SPF_HELO_PERMERROR=0.01] recips=0 Mar 1 14:52:53.339 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline spam_scan - deadline in 479.7 s, set to 288.000 s Mar 1 14:52:53.339 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer spam_scan: timer 288, was 288, deadline in 479.7 s Mar 1 14:52:53.339 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_tag_level] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.339 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (scalar) matches, result="5" Mar 1 14:52:53.340 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_tag2_level] => true, "mich@mydomain.org" matches, result="5", matching_key="(constant:5)" Mar 1 14:52:53.341 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_tag3_level] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.341 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (scalar) matches, result="20" Mar 1 14:52:53.342 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_kill_level] => true, "mich@mydomain.org" matches, result="20", matching_key="(constant:20)" Mar 1 14:52:53.342 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) final_destiny (ccat=0) is PASS, recip mich@mydomain.org Mar 1 14:52:53.343 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) final_destiny PASS, recip mich@mydomain.org Mar 1 14:52:53.343 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) do_notify_and_quar: ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(), qar_mth= Mar 1 14:52:53.344 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) do_notify_and_quarantine: not quarantining, q_method off Mar 1 14:52:53.344 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) skip admin notification, no administrators Mar 1 14:52:53.345 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) do_notify_and_quarantine - done Mar 1 14:52:53.345 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (opaque) matches, result="smtp:[127.0.0.1]:10025" Mar 1 14:52:53.346 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [forward_method] => true, "mich@mydomain.org" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)" Mar 1 14:52:53.346 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) delivery method is 1, recips: mich@mydomain.org Mar 1 14:52:53.347 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_tag_level] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.347 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (scalar) matches, result="5" Mar 1 14:52:53.347 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_tag2_level] => true, "mich@mydomain.org" matches, result="5", matching_key="(constant:5)" Mar 1 14:52:53.348 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_subject_tag] => undef, "mich@mydomain.org" does not match Mar 1 14:52:53.348 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) headers CLUSTERING: NEW CLUSTER <mich@mydomain.org>: score=0.119, tag=1, tag2=0, local=1, bl=, s=, mangle= Mar 1 14:52:53.348 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header encoded (all-ASCII): X-Spam-Flag: NO Mar 1 14:52:53.349 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header: X-Spam-Flag: NO\n Mar 1 14:52:53.349 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header encoded (all-ASCII): X-Spam-Score: 0.119 Mar 1 14:52:53.349 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header: X-Spam-Score: 0.119\n Mar 1 14:52:53.349 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header encoded (all-ASCII): X-Spam-Level: Mar 1 14:52:53.350 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header: X-Spam-Level:\n Mar 1 14:52:53.350 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header encoded (all-ASCII): X-Spam-Status: No,\n score=0.119\n required=5\n tests=[DKIM_SIGNED=0.1,\n RP_MATCHES_RCVD=-0.001,\n T_DKIM_INVALID=0.01,\n T_SPF_HELO_PERMERROR=0.01]\n autolearn=no autolearn_force=no Mar 1 14:52:53.350 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header: X-Spam-Status: No, score=0.119 required=5 tests=[DKIM_SIGNED=0.1,\n\tRP_MATCHES_RCVD=-0.001, T_DKIM_INVALID=0.01,\n\tT_SPF_HELO_PERMERROR=0.01] autolearn=no autolearn_force=no\n Mar 1 14:52:53.351 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) fwd: scanner provided a header field X-Spam-Checker-Version, inhibited by %allowed_added_header_fields Mar 1 14:52:53.351 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) fwd: scanner provided a header field X-Spam-Level, but we preferred our own Mar 1 14:52:53.351 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) fwd: scanner provided a header field X-Spam-Status, but we preferred our own Mar 1 14:52:53.352 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header encoded (all-ASCII): Authentication-Results: mail.mydomain.org (amavisd-new);\n dkim=fail (2048-bit key)\n reason="fail (message has been altered)"\n header.d=gmail.com Mar 1 14:52:53.352 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header: Authentication-Results: mail.mydomain.org (amavisd-new);\n\tdkim=fail (2048-bit key) reason="fail (message has been altered)"\n\theader.d=gmail.com\n Mar 1 14:52:53.352 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header encoded (all-ASCII): Received: from mail.mydomain.org ([127.0.0.1])\n by localhost (mail.mydomain.org [127.0.0.1]) (amavisd-new, port 10024)\n with ESMTP\n id sbh7deZSzOVI\n for <mich@mydomain.org>;\n Wed, 1 Mar 2017 14:52:52 +0100 (CET) Mar 1 14:52:53.353 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) header: Received: from mail.mydomain.org ([127.0.0.1])\n\tby localhost (mail.mydomain.org [127.0.0.1]) (amavisd-new, port 10024)\n\twith ESMTP id sbh7deZSzOVI for <mich@mydomain.org>;\n\tWed, 1 Mar 2017 14:52:52 +0100 (CET)\n Mar 1 14:52:53.353 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) headers CLUSTERING: done all 1 recips in one go Mar 1 14:52:53.353 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) spam-tag, <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org>, No, score=0.119 required=5 tests=[DKIM_SIGNED=0.1, RP_MATCHES_RCVD=-0.001, T_DKIM_INVALID=0.01, T_SPF_HELO_PERMERROR=0.01] autolearn=no autolearn_force=no Mar 1 14:52:53.353 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) about to connect to smtp:[127.0.0.1]:10025, sbh7deZSzOVI FWD from <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org> Mar 1 14:52:53.353 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline fwd_init - deadline in 479.6 s, set to 480.000 s Mar 1 14:52:53.353 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp session: setting up a new session Mar 1 14:52:53.354 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) establish_or_refresh, state: down Mar 1 14:52:53.354 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) new socket using IO::Socket::IP to [127.0.0.1]:10025, timeout 35 Mar 1 14:52:53.358 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) connected to [127.0.0.1]:10025 successfully Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=1, flush=0, wr=0, timeout=35 Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: receiving Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop read 46 chars< 220 mail.mydomain.org ESMTP Postfix (Ubuntu)\r\n Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp greeting: 220 mail.mydomain.org ESMTP Postfix (Ubuntu), dt: 5.3 ms Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp cmd> EHLO localhost Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=0, flush=1, wr=1, timeout=300 Mar 1 14:52:53.359 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: sending 16 chars Mar 1 14:52:53.360 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop sent 16> EHLO localhost\r\n Mar 1 14:52:53.360 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=1, flush=0, wr=0, timeout=300 Mar 1 14:52:53.360 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: receiving Mar 1 14:52:53.360 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop read 130 chars< 250-mail.mydomain.org\r\n250-PIPELINING\r\n250-SIZE 51200000\r\n250-ETRN\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250-DSN\r\n250 SMTPUTF8\r\n Mar 1 14:52:53.360 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp resp to EHLO: 250 mail.mydomain.org\nPIPELINING\nSIZE 51200000\nETRN\nENHANCEDSTATUSCODES\n8BITMIME\nDSN\nSMTPUTF8 Mar 1 14:52:53.360 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) tls active=0, capable=, sec_level=0 Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Remote host presents itself as: mail.mydomain.org, handles DSN, PIPELINING, 8BITMIME, SMTPUTF8 Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) AUTH not needed, user='', MTA offers '' Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp cmd> MAIL FROM:<sqlite-users-bounces@mailinglists.sqlite.org> BODY=7BIT Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) orcpt_encode rfc822, mich@mydomain.org, encode_for_smtp Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp cmd> RCPT TO:<mich@mydomain.org> ORCPT=rfc822;mich@mydomain.org Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp cmd> DATA Mar 1 14:52:53.361 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=0, flush=1, wr=1, timeout=120 Mar 1 14:52:53.362 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: sending 134 chars Mar 1 14:52:53.364 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop sent 134> MAIL FROM:<sqlite-users-bounces@mailinglists.sqlite.org> BODY=7BIT\r\nRCPT TO:<mich@mydomain.org> ORCPT=rfc822;mich@mydomain.org\r\nDATA\r\n Mar 1 14:52:53.364 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=1, flush=0, wr=0, timeout=300 Mar 1 14:52:53.364 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: receiving Mar 1 14:52:53.364 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop read 65 chars< 250 2.1.0 Ok\r\n250 2.1.5 Ok\r\n354 End data with <CR><LF>.<CR><LF>\r\n Mar 1 14:52:53.364 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp resp to MAIL (pip): 250 2.1.0 Ok Mar 1 14:52:53.364 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp resp to RCPT (pip) (<mich@mydomain.org>): 250 2.1.5 Ok Mar 1 14:52:53.365 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF> Mar 1 14:52:53.365 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) write_header: 1, Amavis::Out::SMTP::Protocol=HASH(0xe41c1e8) Mar 1 14:52:53.365 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=1, flush=0, wr=1, timeout=479.988 Mar 1 14:52:53.365 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: sending 5401 chars Mar 1 14:52:53.366 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop sent 5401> X-Spam-Flag: NO\r\nX-Spam-Score: 0.119\r\nX-Spam-Level:\r\nX-Spam-Status: No, score=0.119 required=5 tests=[DKIM_SIGNED=0.1,\r\n\tRP_MATCHES_RCVD=-0.001, T_DKIM_INVALID=0.01,\r\n\tT_SPF_HELO_PERMERROR=0.01] autol [...] Mar 1 14:52:53.367 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: needline=1, flush=0, wr=0, timeout=479.988 Mar 1 14:52:53.384 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop: receiving Mar 1 14:52:53.386 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) rw_loop read 37 chars< 250 2.0.0 Ok: queued as 588D72106AB\r\n Mar 1 14:52:53.387 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) smtp resp to data-dot (<mich@mydomain.org>): 250 2.0.0 Ok: queued as 588D72106AB, dt: 20.2 ms Mar 1 14:52:53.387 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) Amavis::Out::SMTP::Session close, keeping connection Mar 1 14:52:53.388 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline fwd-end-chkpnt - deadline in 479.6 s, set to 288.000 s Mar 1 14:52:53.388 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer fwd-end-chkpnt: timer 288, was 0, deadline in 479.6 s Mar 1 14:52:53.388 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) sbh7deZSzOVI FWD from <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org>, BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 588D72106AB Mar 1 14:52:53.388 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline forwarding - deadline in 479.6 s, set to 288.000 s Mar 1 14:52:53.388 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer forwarding: timer 288, was 288, deadline in 479.6 s Mar 1 14:52:53.390 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) DSN: sender NOT credible, SA: 0.119, <sqlite-users-bounces@mailinglists.sqlite.org> Mar 1 14:52:53.391 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup: (scalar) matches, result="10" Mar 1 14:52:53.391 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) lookup [spam_dsn_cutoff_level_bysender] => true, "sqlite-users-bounces@mailinglists.sqlite.org" matches, result="10", matching_key="(constant:10)" Mar 1 14:52:53.391 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) dsn: from MTA 250 NonBlocking:CleanTag <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org>: on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=1, destiny=1, mta_resp: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 588D72106AB" Mar 1 14:52:53.391 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) DSN: SUCC from MTA 250 NonBlocking:CleanTag, no DSN requested: <sqlite-users-bounces@mailinglists.sqlite.org> -> <mich@mydomain.org> Mar 1 14:52:53.391 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) delivery_status_notification: notif 0 bytes, suppressed: no Mar 1 14:52:53.391 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) one_response_for_all, per_recip_capable: N, suppressed: N Mar 1 14:52:53.392 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) one_response_for_all <sqlite-users-bounces@mailinglists.sqlite.org>: success, r=0,b=0,d=0, ndn_needed=0, '250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 588D72106AB' Mar 1 14:52:53.392 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) notif=N, suppressed=0, ndn_needed=0, exit=0, 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 588D72106AB Mar 1 14:52:53.395 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline delivery-notification - deadline in 479.6 s, set to 288.000 s Mar 1 14:52:53.396 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer delivery-notification: timer 288, was 288, deadline in 479.6 s Mar 1 14:52:53.397 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) status counters: InMsgsStatus{Relayed,RelayedUntagged,RelayedUntaggedInbound} Mar 1 14:52:53.397 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) get_deadline snmp-counters - deadline in 479.6 s, set to 288.000 s Mar 1 14:52:53.398 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) prolong_timer snmp-counters: timer 288, was 288, deadline in 479.6 s Mar 1 14:52:53.398 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) orcpt_encode rfc822, mich@mydomain.org, smtputf8 Mar 1 14:52:53.401 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-01) oldest_public_ip_addr_from_received: 209.85.217.171 ... ... ... '''J E T Z T K O M M T E I N E S P A M M A I L ''' Mar 1 14:57:33.565 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) exiting process_request Mar 1 14:57:33.565 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) idle_proc, bye: was busy, 1.6 ms, total idle 225.800 s, busy 1.404 s Mar 1 14:57:33.565 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) load: 1 %, total idle 225.800 s, busy 1.404 s Mar 1 14:59:07.675 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-02) Net::Server: 2017/03/01-14:59:07 CONNECT TCP Peer: "[127.0.0.1]:41528" Local: "[127.0.0.1]:10024" Mar 1 14:59:07.676 mail.mydomain.org /usr/sbin/amavisd-new[30099]: idle_proc, hi : was idle, 177408.0 ms, total idle 373.835 s, busy 0.893 s Mar 1 14:59:07.676 mail.mydomain.org /usr/sbin/amavisd-new[30099]: loaded base policy bank Mar 1 14:59:07.677 mail.mydomain.org /usr/sbin/amavisd-new[30099]: lookup_ip_acl (inet_acl) arr.obj: key="127.0.0.1" matches "127.0.0.1", result=1 Mar 1 14:59:07.677 mail.mydomain.org /usr/sbin/amavisd-new[30099]: process_request: fileno sock=12, STDIN=0, STDOUT=1 Mar 1 14:59:07.677 mail.mydomain.org /usr/sbin/amavisd-new[30099]: get_deadline switch_to_my_time(new request) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.677 mail.mydomain.org /usr/sbin/amavisd-new[30099]: prolong_timer switch_to_my_time(new request): timer 288, was 0, deadline in 480.0 s Mar 1 14:59:07.677 mail.mydomain.org /usr/sbin/amavisd-new[30099]: process_request: suggested_protocol="" on a TCP socket Mar 1 14:59:07.677 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Mar 1 14:59:07.678 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.678 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 4: was busy, 2.0 ms, total idle 373.835 s, busy 0.895 s Mar 1 14:59:07.678 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp readline: read 24 bytes, new size: 24 Mar 1 14:59:07.679 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 1.3 ms, total idle 373.837 s, busy 0.895 s Mar 1 14:59:07.679 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SMTP< EHLO mail.mydomain.org\r\n Mar 1 14:59:07.680 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP EHLO) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.681 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP EHLO): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.681 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-[127.0.0.1] Mar 1 14:59:07.681 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-VRFY Mar 1 14:59:07.682 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-PIPELINING Mar 1 14:59:07.682 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-SIZE Mar 1 14:59:07.682 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-ENHANCEDSTATUSCODES Mar 1 14:59:07.682 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-8BITMIME Mar 1 14:59:07.682 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-SMTPUTF8 Mar 1 14:59:07.683 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250-DSN Mar 1 14:59:07.683 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE Mar 1 14:59:07.683 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.684 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 6: was busy, 4.9 ms, total idle 373.837 s, busy 0.900 s Mar 1 14:59:07.684 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp readline: read 292 bytes, new size: 292 Mar 1 14:59:07.684 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 0.6 ms, total idle 373.837 s, busy 0.900 s Mar 1 14:59:07.685 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< XFORWARD NAME=cloudserver053871.home.net.pl ADDR=79.96.12.23 PORT=62828\r\n Mar 1 14:59:07.685 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.685 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.686 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250 2.5.0 Ok XFORWARD Mar 1 14:59:07.686 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.686 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 6: was busy, 1.9 ms, total idle 373.837 s, busy 0.902 s Mar 1 14:59:07.687 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 0.3 ms, total idle 373.837 s, busy 0.902 s Mar 1 14:59:07.687 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< XFORWARD PROTO=ESMTP HELO=football.kuazsuw.pl IDENT=8D4952106AA SOURCE=REMOTE\r\n Mar 1 14:59:07.687 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.687 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.688 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250 2.5.0 Ok XFORWARD Mar 1 14:59:07.688 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.688 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 6: was busy, 1.7 ms, total idle 373.837 s, busy 0.904 s Mar 1 14:59:07.689 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 0.3 ms, total idle 373.838 s, busy 0.904 s Mar 1 14:59:07.689 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< MAIL FROM:<ethan_harrington@football.kuazsuw.pl> SIZE=1893 BODY=8BITMIME\r\n Mar 1 14:59:07.689 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP MAIL) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.689 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP MAIL): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.690 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) check_mail_begin_task: task_count=3 Mar 1 14:59:07.690 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_ip_acl (client_ipaddr_policy) arr.obj: key="79.96.12.23", no match Mar 1 14:59:07.691 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [debug_sender] => undef, "ethan_harrington@football.kuazsuw.pl" does not match Mar 1 14:59:07.691 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) mesage size set to a declared size 1893 Mar 1 14:59:07.692 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250 2.1.0 Sender <ethan_harrington@football.kuazsuw.pl> OK Mar 1 14:59:07.692 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.692 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 6: was busy, 3.6 ms, total idle 373.838 s, busy 0.908 s Mar 1 14:59:07.692 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 0.1 ms, total idle 373.838 s, busy 0.908 s Mar 1 14:59:07.692 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< RCPT TO:<mich@mydomain.org> ORCPT=rfc822;mich@mydomain.org\r\n Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP RCPT) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP RCPT): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup => undef, "mich@mydomain.org", no lookup tables Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250 2.1.5 Recipient <mich@mydomain.org> OK Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 6: was busy, 0.9 ms, total idle 373.838 s, busy 0.908 s Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 0.1 ms, total idle 373.838 s, busy 0.908 s Mar 1 14:59:07.693 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< DATA\r\n Mar 1 14:59:07.694 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP DATA) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.694 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP DATA): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.694 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP :10024 /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48: <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org> SIZE=1893 BODY=8BITMIME Received: from mail.mydomain.org ([127.0.0.1]) by localhost (mail.mydomain.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <mich@mydomain.org>; Wed, 1 Mar 2017 14:59:07 +0100 (CET) Mar 1 14:59:07.694 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 354 End data with <CR><LF>.<CR><LF> Mar 1 14:59:07.694 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:07.694 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, receiving data Mar 1 14:59:07.724 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp copy: read 1898 bytes into buffer, new size: 1898 Mar 1 14:59:07.725 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp copy: 6 bytes still buffered at end Mar 1 14:59:07.725 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx data-end) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.725 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx data-end): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:07.725 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< .<CR><LF> Mar 1 14:59:07.726 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Actual message size 1889 B less than the declared 1893 B Mar 1 14:59:07.726 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp connection cache, dt: 177.4, state: 0 Mar 1 14:59:07.726 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline get_body_digest - deadline in 480.0 s, set to 30.000 s Mar 1 14:59:07.727 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline digest_pre - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.727 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer digest_pre: timer 288, was 288, deadline in 480.0 s Mar 1 14:59:07.727 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_body_digest: reading header section from memory Mar 1 14:59:07.728 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_body_digest: feeding header section to DKIM verifier Mar 1 14:59:07.728 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_body_digest: sending h/b separator to DKIM Mar 1 14:59:07.729 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline digest_hdr - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.729 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer digest_hdr: timer 288, was 288, deadline in 480.0 s Mar 1 14:59:07.729 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_body_digest: reading mail body from memory, 0 DKIM signatures Mar 1 14:59:07.729 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline digest_body - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.730 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer digest_body: timer 288, was 288, deadline in 480.0 s Mar 1 14:59:07.730 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_body_digest: message size 1889, header+sep 611, body 1278 Mar 1 14:59:07.730 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) body type (8bit-MIMEtransport): labeled 8BITMIME, good (h=0, b=1) Mar 1 14:59:07.730 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) body hash: 75118fb9e64bc0f0318159639b724b12 Mar 1 14:59:07.732 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ip_from_received: 79.96.12.23 Mar 1 14:59:07.732 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_ip_acl (public_nets) arr.obj: key="127.0.0.1" matches "!127.0.0.0/8", result=0 Mar 1 14:59:07.733 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_ip_acl (public_nets) arr.obj: key="79.96.12.23" matches "::ffff:0:0/96", result=1 Mar 1 14:59:07.733 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) trace: ESMTP://[127.0.0.1]:41528 < ESMTP://[79.96.12.23]:62828 Mar 1 14:59:07.733 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Original mail size: 1889; quota set to: 944500 bytes (fmin=5, fmax=500, qmin=102400, qmax=314572800) Mar 1 14:59:07.734 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Checking: BfWkmxIH6IgN [79.96.12.23] <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org> Mar 1 14:59:07.734 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) 2822.From: <ethan_harrington@football.kuazsuw.pl> Mar 1 14:59:07.734 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_acl(mich@mydomain.org) matches key ".mydomain.org", result=1 Mar 1 14:59:07.735 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [local_domains] => true, "mich@mydomain.org" matches, result="1", matching_key=".mydomain.org" Mar 1 14:59:07.735 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (scalar) matches, result="1" Mar 1 14:59:07.735 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [bypass_virus_checks] => true, "mich@mydomain.org" matches, result="1", matching_key="(constant:1)" Mar 1 14:59:07.736 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [bypass_banned_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.736 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [bypass_spam_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.737 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Extracting mime components from a string Mar 1 14:59:07.740 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Issued a new file name: p001 Mar 1 14:59:07.741 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Issued a new file name: p002 Mar 1 14:59:07.742 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Issued a new pseudo part: p003 Mar 1 14:59:07.742 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) p003 1 Content-Type: multipart/alternative Mar 1 14:59:07.742 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) mime_decode_epilogue: 1 lines Mar 1 14:59:07.742 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Charging 462 bytes to remaining quota 944500 (out of 944500, (0%)) - by mime_decode Mar 1 14:59:07.742 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) p001 1/1 Content-Type: text/plain, size: 462 B, name: Mar 1 14:59:07.743 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) reparenting p001 from p000 to p003 Mar 1 14:59:07.743 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Charging 523 bytes to remaining quota 944038 (out of 944500, (0%)) - by mime_decode Mar 1 14:59:07.743 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) p002 1/2 Content-Type: text/html, size: 523 B, name: Mar 1 14:59:07.743 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) reparenting p002 from p000 to p003 Mar 1 14:59:07.743 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline mime_decode - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.743 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer mime_decode: timer 288, was 288, deadline in 480.0 s Mar 1 14:59:07.744 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline mime_decode-1 - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.744 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer mime_decode-1: timer 288, was 288, deadline in 480.0 s Mar 1 14:59:07.744 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) decode_parts: level=1, #parts=3 : p001, p002, p003 Mar 1 14:59:07.744 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) running file(1) on 2 files, arglist size 23 Mar 1 14:59:07.746 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) run_command: [30138] /usr/bin/file p001 p002 </dev/null 2>&1 Mar 1 14:59:07.752 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) result line from file(1): p001: UTF-8 Unicode text\n Mar 1 14:59:07.753 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_re("UTF-8 Unicode text") matches key "(?^i:^UTF.* Unicode text\\b)", result="txt" Mar 1 14:59:07.753 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [map_full_type_to_short_type] => true, "UTF-8 Unicode text" matches, result="txt", matching_key="(?^i:^UTF.* Unicode text\\b)" Mar 1 14:59:07.753 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) File-type of p001: UTF-8 Unicode text; (txt) Mar 1 14:59:07.753 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) result line from file(1): p002: HTML document, UTF-8 Unicode text\n Mar 1 14:59:07.753 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_re("HTML document, UTF-8 Unicode text") matches key "(?^i:\\btext\\b)", result="asc" Mar 1 14:59:07.754 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [map_full_type_to_short_type] => true, "HTML document, UTF-8 Unicode text" matches, result="asc", matching_key="(?^i:\\btext\\b)" Mar 1 14:59:07.754 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) File-type of p002: HTML document, UTF-8 Unicode text; (asc) Mar 1 14:59:07.754 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) decompose_part: p001 - atomic Mar 1 14:59:07.754 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) decompose_part: p002 - atomic Mar 1 14:59:07.754 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline parts_decode - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:07.754 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer parts_decode: timer 288, was 288, deadline in 480.0 s Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [bypass_header_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) check_header: 0, OK Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [bypass_header_checks] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Checking for banned types and filenames Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (scalar) matches, result="DEFAULT" Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [banned_filename], 1 matches for "mich@mydomain.org", results: "(constant:DEFAULT)"=>"DEFAULT" Mar 1 14:59:07.755 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) collect banned table[0]: mich@mydomain.org, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0xac6a368) Mar 1 14:59:07.756 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) starting banned checks - traversing message structure tree Mar 1 14:59:07.756 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) check_for_banned (p003,p001) multipart/alternative | text/plain,.txt Mar 1 14:59:07.756 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) doing banned check for mich@mydomain.org on multipart/alternative | text/plain,.txt Mar 1 14:59:07.756 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_re(["multipart/alternative","text/plain",".txt"]), no matches Mar 1 14:59:07.756 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [check_bann:mich@mydomain.org] => undef, ["multipart/alternative","text/plain",".txt"] does not match Mar 1 14:59:07.756 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [banned_namepath_re] => undef, "P=p003\tL=1\tM=multipart/alternative\nP=p001\tL=1/1\tM=text/plain\tT=txt" does not match Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) p.path mich@mydomain.org: "P=p003,L=1,M=multipart/alternative | P=p001,L=1/1,M=text/plain,T=txt" Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) check_for_banned (p003,p002) multipart/alternative | text/html,.asc Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) doing banned check for mich@mydomain.org on multipart/alternative | text/html,.asc Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_re(["multipart/alternative","text/html",".asc"]), no matches Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [check_bann:mich@mydomain.org] => undef, ["multipart/alternative","text/html",".asc"] does not match Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [banned_namepath_re] => undef, "P=p003\tL=1\tM=multipart/alternative\nP=p002\tL=1/2\tM=text/html\tT=asc" does not match Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) p.path mich@mydomain.org: "P=p003,L=1,M=multipart/alternative | P=p002,L=1/2,M=text/html,T=asc" Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) banned check: any=0, all=N (1) Mar 1 14:59:07.757 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) no anti-virus code loaded, skipping virus_scan Mar 1 14:59:07.758 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) wbl: checking sender <ethan_harrington@football.kuazsuw.pl> Mar 1 14:59:07.758 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [blacklist_recip<mich@mydomain.org>] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.758 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [blacklist_sender<ethan_harrington@football.kuazsuw.pl>,blacklist_sender] => undef, "ethan_harrington@football.kuazsuw.pl" does not match Mar 1 14:59:07.758 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [whitelist_recip<mich@mydomain.org>] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.758 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_acl(ethan_harrington@football.kuazsuw.pl), no match Mar 1 14:59:07.758 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [whitelist_sender<ethan_harrington@football.kuazsuw.pl>,whitelist_sender] => undef, "ethan_harrington@football.kuazsuw.pl" does not match Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) query_keys: cached mich@mydomain.org Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_hash(mich@mydomain.org) matches keys: "."=>ARRAY(0xab34c7c) Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [score_recip<mich@mydomain.org>,score_sender], 1 matches for "mich@mydomain.org", results: "."=>[Amavis::Lookup::RE=ARRAY(0xab3422c),{}] Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup_re("ethan_harrington@football.kuazsuw.pl"), no matches Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [score_sender<ethan_harrington@football.kuazsuw.pl>] => undef, "ethan_harrington@football.kuazsuw.pl" does not match Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SpamControl: calling spam scanner SpamAssassin Mar 1 14:59:07.759 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline spam_scan_sa_pre - deadline in 480.0 s, set to 476.000 s Mar 1 14:59:07.760 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer spam_scan_sa_pre: timer 476, was 288, deadline in 480.0 s Mar 1 14:59:07.760 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SA user config: "", username: "amavis", 0, (0)mich@mydomain.org Mar 1 14:59:07.760 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) calling SA parse (0), SA vers 3.4.1, 3.004001, data as STRING_REF, recips_ind [0], user: "amavis" Mar 1 14:59:07.760 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline SA check - deadline in 480.0 s, set to 475.000 s Mar 1 14:59:07.761 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) CALLING SA check (0) Mar 1 14:59:07.946 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) DONE SA check (0) Mar 1 14:59:07.950 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline spam_scan_sa - deadline in 479.8 s, set to 288.000 s Mar 1 14:59:07.950 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer spam_scan_sa: timer 288, was 476, deadline in 479.8 s Mar 1 14:59:07.951 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) spam_scan: score=0.001 autolearn=ham autolearn_force=no tests=[HTML_MESSAGE=0.001] recips=0 Mar 1 14:59:07.952 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline spam_scan - deadline in 479.8 s, set to 288.000 s Mar 1 14:59:07.952 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer spam_scan: timer 288, was 288, deadline in 479.8 s Mar 1 14:59:07.953 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_tag_level] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.953 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (scalar) matches, result="5" Mar 1 14:59:07.954 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_tag2_level] => true, "mich@mydomain.org" matches, result="5", matching_key="(constant:5)" Mar 1 14:59:07.954 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_tag3_level] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.955 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (scalar) matches, result="20" Mar 1 14:59:07.955 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_kill_level] => true, "mich@mydomain.org" matches, result="20", matching_key="(constant:20)" Mar 1 14:59:07.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) final_destiny (ccat=0) is PASS, recip mich@mydomain.org Mar 1 14:59:07.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) final_destiny PASS, recip mich@mydomain.org Mar 1 14:59:07.956 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) do_notify_and_quar: ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(), qar_mth= Mar 1 14:59:07.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) do_notify_and_quarantine: not quarantining, q_method off Mar 1 14:59:07.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) skip admin notification, no administrators Mar 1 14:59:07.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) do_notify_and_quarantine - done Mar 1 14:59:07.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (opaque) matches, result="smtp:[127.0.0.1]:10025" Mar 1 14:59:07.957 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [forward_method] => true, "mich@mydomain.org" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)" Mar 1 14:59:07.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) delivery method is 1, recips: mich@mydomain.org Mar 1 14:59:07.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_tag_level] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (scalar) matches, result="5" Mar 1 14:59:07.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_tag2_level] => true, "mich@mydomain.org" matches, result="5", matching_key="(constant:5)" Mar 1 14:59:07.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_subject_tag] => undef, "mich@mydomain.org" does not match Mar 1 14:59:07.958 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) headers CLUSTERING: NEW CLUSTER <mich@mydomain.org>: score=0.001, tag=1, tag2=0, local=1, bl=, s=, mangle= Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header encoded (all-ASCII): X-Spam-Flag: NO Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header: X-Spam-Flag: NO\n Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header encoded (all-ASCII): X-Spam-Score: 0.001 Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header: X-Spam-Score: 0.001\n Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header encoded (all-ASCII): X-Spam-Level: Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header: X-Spam-Level:\n Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header encoded (all-ASCII): X-Spam-Status: No,\n score=0.001\n required=5\n tests=[HTML_MESSAGE=0.001]\n autolearn=ham autolearn_force=no Mar 1 14:59:07.959 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header: X-Spam-Status: No, score=0.001 required=5 tests=[HTML_MESSAGE=0.001]\n\tautolearn=ham autolearn_force=no\n Mar 1 14:59:07.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) fwd: scanner provided a header field X-Spam-Checker-Version, inhibited by %allowed_added_header_fields Mar 1 14:59:07.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) fwd: scanner provided a header field X-Spam-Level, but we preferred our own Mar 1 14:59:07.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) fwd: scanner provided a header field X-Spam-Status, but we preferred our own Mar 1 14:59:07.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header encoded (all-ASCII): Received: from mail.mydomain.org ([127.0.0.1])\n by localhost (mail.mydomain.org [127.0.0.1]) (amavisd-new, port 10024)\n with ESMTP\n id BfWkmxIH6IgN\n for <mich@mydomain.org>;\n Wed, 1 Mar 2017 14:59:07 +0100 (CET) Mar 1 14:59:07.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) header: Received: from mail.mydomain.org ([127.0.0.1])\n\tby localhost (mail.mydomain.org [127.0.0.1]) (amavisd-new, port 10024)\n\twith ESMTP id BfWkmxIH6IgN for <mich@mydomain.org>;\n\tWed, 1 Mar 2017 14:59:07 +0100 (CET)\n Mar 1 14:59:07.960 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) headers CLUSTERING: done all 1 recips in one go Mar 1 14:59:07.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) spam-tag, <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org>, No, score=0.001 required=5 tests=[HTML_MESSAGE=0.001] autolearn=ham autolearn_force=no Mar 1 14:59:07.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) about to connect to smtp:[127.0.0.1]:10025, BfWkmxIH6IgN FWD from <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org> Mar 1 14:59:07.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline fwd_init - deadline in 479.8 s, set to 480.000 s Mar 1 14:59:07.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp session: setting up a new session Mar 1 14:59:07.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) establish_or_refresh, state: down Mar 1 14:59:07.961 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) new socket using IO::Socket::IP to [127.0.0.1]:10025, timeout 35 Mar 1 14:59:07.962 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) connected to [127.0.0.1]:10025 successfully Mar 1 14:59:07.963 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=1, flush=0, wr=0, timeout=35 Mar 1 14:59:07.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: receiving Mar 1 14:59:07.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop read 46 chars< 220 mail.mydomain.org ESMTP Postfix (Ubuntu)\r\n Mar 1 14:59:07.964 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp greeting: 220 mail.mydomain.org ESMTP Postfix (Ubuntu), dt: 3.0 ms Mar 1 14:59:07.965 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp cmd> EHLO localhost Mar 1 14:59:07.965 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=0, flush=1, wr=1, timeout=300 Mar 1 14:59:07.965 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: sending 16 chars Mar 1 14:59:07.966 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop sent 16> EHLO localhost\r\n Mar 1 14:59:07.966 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=1, flush=0, wr=0, timeout=300 Mar 1 14:59:07.966 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: receiving Mar 1 14:59:07.967 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop read 130 chars< 250-mail.mydomain.org\r\n250-PIPELINING\r\n250-SIZE 51200000\r\n250-ETRN\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250-DSN\r\n250 SMTPUTF8\r\n Mar 1 14:59:07.967 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp resp to EHLO: 250 mail.mydomain.org\nPIPELINING\nSIZE 51200000\nETRN\nENHANCEDSTATUSCODES\n8BITMIME\nDSN\nSMTPUTF8 Mar 1 14:59:07.967 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) tls active=0, capable=, sec_level=0 Mar 1 14:59:07.968 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Remote host presents itself as: mail.mydomain.org, handles DSN, PIPELINING, 8BITMIME, SMTPUTF8 Mar 1 14:59:07.968 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) AUTH not needed, user='', MTA offers '' Mar 1 14:59:07.968 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp cmd> MAIL FROM:<ethan_harrington@football.kuazsuw.pl> BODY=8BITMIME Mar 1 14:59:07.968 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) orcpt_encode rfc822, mich@mydomain.org, encode_for_smtp Mar 1 14:59:07.968 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp cmd> RCPT TO:<mich@mydomain.org> ORCPT=rfc822;mich@mydomain.org Mar 1 14:59:07.969 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp cmd> DATA Mar 1 14:59:07.969 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=0, flush=1, wr=1, timeout=120 Mar 1 14:59:07.969 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: sending 130 chars Mar 1 14:59:07.971 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop sent 130> MAIL FROM:<ethan_harrington@football.kuazsuw.pl> BODY=8BITMIME\r\nRCPT TO:<mich@mydomain.org> ORCPT=rfc822;mich@mydomain.org\r\nDATA\r\n Mar 1 14:59:07.971 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=1, flush=0, wr=0, timeout=300 Mar 1 14:59:07.971 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: receiving Mar 1 14:59:07.971 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop read 65 chars< 250 2.1.0 Ok\r\n250 2.1.5 Ok\r\n354 End data with <CR><LF>.<CR><LF>\r\n Mar 1 14:59:07.971 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp resp to MAIL (pip): 250 2.1.0 Ok Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp resp to RCPT (pip) (<mich@mydomain.org>): 250 2.1.5 Ok Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF> Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) write_header: 1, Amavis::Out::SMTP::Protocol=HASH(0xe796244) Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp connection_cache disabled, sending QUIT Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp cmd> QUIT Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=0, flush=1, wr=1, timeout=479.989 Mar 1 14:59:07.972 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: sending 2271 chars Mar 1 14:59:07.973 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop sent 2271> X-Spam-Flag: NO\r\nX-Spam-Score: 0.001\r\nX-Spam-Level:\r\nX-Spam-Status: No, score=0.001 required=5 tests=[HTML_MESSAGE=0.001]\r\n\tautolearn=ham autolearn_force=no\r\nReceived: from mail.mydomain.org ([127.0.0 [...] Mar 1 14:59:07.973 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: needline=1, flush=0, wr=0, timeout=479.989 Mar 1 14:59:08.027 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop: receiving Mar 1 14:59:08.028 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rw_loop read 52 chars< 250 2.0.0 Ok: queued as ECBD72106AB\r\n221 2.0.0 Bye\r\n Mar 1 14:59:08.028 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) smtp resp to data-dot (<mich@mydomain.org>): 250 2.0.0 Ok: queued as ECBD72106AB, dt: 55.1 ms Mar 1 14:59:08.029 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Amavis::Out::SMTP::Session close, disconnecting Mar 1 14:59:08.029 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline fwd-end-chkpnt - deadline in 479.7 s, set to 288.000 s Mar 1 14:59:08.029 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer fwd-end-chkpnt: timer 288, was 0, deadline in 479.7 s Mar 1 14:59:08.029 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) BfWkmxIH6IgN FWD from <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org>, BODY=8BITMIME 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECBD72106AB Mar 1 14:59:08.031 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline forwarding - deadline in 479.7 s, set to 288.000 s Mar 1 14:59:08.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer forwarding: timer 288, was 288, deadline in 479.7 s Mar 1 14:59:08.034 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) DSN: sender NOT credible, SA: 0.001, <ethan_harrington@football.kuazsuw.pl> Mar 1 14:59:08.035 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup: (scalar) matches, result="10" Mar 1 14:59:08.036 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) lookup [spam_dsn_cutoff_level_bysender] => true, "ethan_harrington@football.kuazsuw.pl" matches, result="10", matching_key="(constant:10)" Mar 1 14:59:08.038 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) dsn: from MTA 250 NonBlocking:CleanTag <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org>: on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=1, destiny=1, mta_resp: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECBD72106AB" Mar 1 14:59:08.038 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) DSN: SUCC from MTA 250 NonBlocking:CleanTag, no DSN requested: <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org> Mar 1 14:59:08.039 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) delivery_status_notification: notif 0 bytes, suppressed: no Mar 1 14:59:08.040 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) one_response_for_all, per_recip_capable: N, suppressed: N Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) one_response_for_all <ethan_harrington@football.kuazsuw.pl>: success, r=0,b=0,d=0, ndn_needed=0, '250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECBD72106AB' Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) notif=N, suppressed=0, ndn_needed=0, exit=0, 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECBD72106AB Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline delivery-notification - deadline in 479.7 s, set to 288.000 s Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer delivery-notification: timer 288, was 288, deadline in 479.7 s Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) status counters: InMsgsStatus{Relayed,RelayedUntagged,RelayedUntaggedInbound} Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline snmp-counters - deadline in 479.7 s, set to 288.000 s Mar 1 14:59:08.044 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer snmp-counters: timer 288, was 288, deadline in 479.7 s Mar 1 14:59:08.045 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) orcpt_encode rfc822, mich@mydomain.org, smtputf8 Mar 1 14:59:08.046 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) oldest_public_ip_addr_from_received: 79.96.12.23 Mar 1 14:59:08.051 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Passed CLEAN {RelayedInbound}, [79.96.12.23]:62828 [79.96.12.23] <ethan_harrington@football.kuazsuw.pl> -> <mich@mydomain.org>, Queue-ID: 8D4952106AA, Message-ID: <e4d3feb355b2d00841d1db1af218f71d@football.kuazsuw.pl>, mail_id: BfWkmxIH6IgN, Hits: 0.001, size: 1889, queued_as: ECBD72106AB, 375 ms Mar 1 14:59:08.051 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline main_log_entry - deadline in 479.7 s, set to 288.000 s Mar 1 14:59:08.051 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer main_log_entry: timer 288, was 288, deadline in 479.7 s Mar 1 14:59:08.051 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) TIMING-SA total 189 ms - parse: 0.60 (0.3%), extract_message_metadata: 11 (5.7%), get_uri_detail_list: 1.14 (0.6%), tests_pri_-1000: 1.34 (0.7%), tests_pri_-950: 0.51 (0.3%), tests_pri_-900: 0.54 (0.3%), tests_pri_-400: 0.49 (0.3%), tests_pri_0: 93 (49.5%), check_dkim_adsp: 34 (18.0%), check_spf: 11 (5.8%), poll_dns_idle: 4.6 (2.4%), check_pyzor: 0.02 (0.0%), tests_pri_500: 1.44 (0.8%), learn: 72 (38.3%), b_learn: 71 (37.6%), b_count_change: 7 (3.8%), get_report: 0.66 (0.4%) Mar 1 14:59:08.052 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) updating snmp variables in BDB Mar 1 14:59:08.052 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline check done - deadline in 479.7 s, set to 288.000 s Mar 1 14:59:08.053 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer check done: timer 288, was 288, deadline in 479.7 s Mar 1 14:59:08.053 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) sending SMTP response: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECBD72106AB" Mar 1 14:59:08.053 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as ECBD72106AB Mar 1 14:59:08.055 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:08.055 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) TempDir::strip: /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48 Mar 1 14:59:08.055 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rmdir_recursively: /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48/parts, excl=1 Mar 1 14:59:08.056 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) size: 1889, TIMING [total 380 ms] - SMTP greeting: 1.9 (1%)1, SMTP EHLO: 6 (2%)2, SMTP pre-MAIL: 6 (2%)4, SMTP pre-DATA-flush: 4.7 (1%)5, SMTP DATA: 31 (8%)13, check_init: 0.9 (0%)13, digest_hdr: 2.1 (1%)14, digest_body_dkim: 2.1 (1%)14, collect_info: 2.7 (1%)15, mime_decode: 10 (3%)18, get-file-type2: 11 (3%)21, parts_decode: 0.3 (0%)21, check_header: 0.7 (0%)21, spam-wb-list: 4.1 (1%)22, SA msg read: 0.5 (0%)22, SA parse: 1.5 (0%)23, SA check: 186 (49%)71, decide_mail_destiny: 9 (2%)74, notif-quar: 0.6 (0%)74, fwd-connect: 11 (3%)77, fwd-mail-pip: 3.4 (1%)78, fwd-rcpt-pip: 0.2 (0%)78, fwd-data-chkpnt: 0.0 (0%)78, write-header: 0.4 (0%)78, fwd-data-contents: 0.0 (0%)78, fwd-end-chkpnt: 59 (16%)94, prepare-dsn: 13 (3%)97, report: 1.3 (0%)97, main_log_entry: 6 (2%)99, update_snmp: 1.3 (0%)99, SMTP pre-response: 0.3 (0%)99, SMTP response: 2.0 (1%)100, unlink-2-files: 0.3 (0%)100, rundown: 0.3 (0%)100 Mar 1 14:59:08.056 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 6: was busy, 362.9 ms, total idle 373.838 s, busy 1.271 s Mar 1 14:59:08.059 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, 5: was idle, 3.3 ms, total idle 373.841 s, busy 1.271 s Mar 1 14:59:08.060 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP< QUIT\r\n Mar 1 14:59:08.060 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) get_deadline switch_to_my_time(rx SMTP QUIT) - deadline in 480.0 s, set to 288.000 s Mar 1 14:59:08.060 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) prolong_timer switch_to_my_time(rx SMTP QUIT): timer 288, was 480, deadline in 480.0 s Mar 1 14:59:08.060 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) ESMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel Mar 1 14:59:08.060 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) switch_to_client_time 480 s, smtp response sent Mar 1 14:59:08.060 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SMTP session over, timer stopped Mar 1 14:59:08.061 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) exiting process_request Mar 1 14:59:08.061 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) idle_proc, bye: was busy, 1.5 ms, total idle 373.841 s, busy 1.273 s Mar 1 14:59:08.061 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) load: 0 %, total idle 373.841 s, busy 1.273 s ^CMar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) child_goes_idle (child finishing) Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) child_goes_idle: disconnected none (child finishing) Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) SA rundown_child (0) Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) SpamControl: rundown_child on SpamAssassin done Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) child_finish_hook: invoking DESTROY methods Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) TempDir::DESTROY called Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) TempDir removal: empty tempdir is being removed: /var/lib/amavis/tmp/amavis-20170301T145346-30100-iM64fKoD Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) rmdir_recursively: /var/lib/amavis/tmp/amavis-20170301T145346-30100-iM64fKoD, excl= Mar 1 15:00:10.212 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) rmdir_recursively: /var/lib/amavis/tmp/amavis-20170301T145346-30100-iM64fKoD/parts, excl= Mar 1 15:00:10.213 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) Amavis::DB::SNMP DESTROY called Mar 1 15:00:10.213 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: 2017/03/01-15:00:10 Server closing! Mar 1 15:00:10.214 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Kill TERM pid 30099 Mar 1 15:00:10.214 mail.mydomain.org /usr/sbin/amavisd-new[30081]: Net::Server: Kill TERM pid 30100 Mar 1 15:00:10.216 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) child_goes_idle (child finishing) Mar 1 15:00:10.216 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) child_goes_idle: disconnected none (child finishing) Mar 1 15:00:10.216 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) SA rundown_child (0) Mar 1 15:00:10.216 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) SpamControl: rundown_child on SpamAssassin done Mar 1 15:00:10.216 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) child_finish_hook: invoking DESTROY methods Mar 1 15:00:10.218 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) child_goes_idle (child finishing) Mar 1 15:00:10.218 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) child_goes_idle: disconnected none (child finishing) Mar 1 15:00:10.218 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SA rundown_child (0) Mar 1 15:00:10.220 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) SpamControl: rundown_child on SpamAssassin done Mar 1 15:00:10.220 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) child_finish_hook: invoking DESTROY methods Mar 1 15:00:10.220 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) TempDir::DESTROY called Mar 1 15:00:10.220 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) TempDir removal: empty tempdir is being removed: /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48 Mar 1 15:00:10.220 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rmdir_recursively: /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48, excl= Mar 1 15:00:10.231 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) rmdir_recursively: /var/lib/amavis/tmp/amavis-20170301T145252-30099-r1x4oO48/parts, excl= Mar 1 15:00:10.232 mail.mydomain.org /usr/sbin/amavisd-new[30099]: (30099-03) Amavis::DB::SNMP DESTROY called Mar 1 15:00:10.233 mail.mydomain.org /usr/sbin/amavisd-new[30100]: (30100-02) Amavis::DB::SNMP DESTROY called # Script done on Wed 01 Mar 2017 15:00:15 CET
Ich habe versucht, die Email und den output weitgehend zu neutralisieren. mich@mydomain.org ist meine Emailadresses auf dem empfangenden Server mail.mydomain.org.Ich sehe da eigentlich nichts, was darauf hindeutet, daß ein Spamfilter aktiv ist.
Kann jemand helfen?
Grüße Christoph