Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 4: was busy, 3.5 ms, total idle 16531.903 s, busy 48.238 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 5: was idle, 0.3 ms, total idle 16531.903 s, busy 48.238 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) SMTP< LHLO server\r\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, SMTP LHLO received Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-[127.0.0.1] Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-VRFY Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-PIPELINING Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-SIZE Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-ENHANCEDSTATUSCODES Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-8BITMIME Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250-DSN Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250 XFORWARD NAME ADDR PROTO HELO Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 6: was busy, 1.7 ms, total idle 16531.903 s, busy 48.239 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 5: was idle, 0.3 ms, total idle 16531.903 s, busy 48.239 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP< MAIL FROM: SIZE=6513\r\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, SMTP MAIL received Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) check_mail_begin_task: task_count=8 Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_ip_acl (mynetworks): key="0.0.0.0", no match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (debug_sender) => undef, "user@aserver.tld" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250 2.1.0 Sender OK Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 6: was busy, 2.4 ms, total idle 16531.903 s, busy 48.242 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 5: was idle, 0.2 ms, total idle 16531.903 s, busy 48.242 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP< RCPT TO: ORCPT=rfc822;user2@ktl.fi\r\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, SMTP RCPT received Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250 2.1.5 Recipient OK Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 6: was busy, 1.1 ms, total idle 16531.903 s, busy 48.243 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 5: was idle, 0.2 ms, total idle 16531.904 s, busy 48.243 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP< RCPT TO: ORCPT=rfc822;user3@ktl.fi\r\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, SMTP RCPT received Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250 2.1.5 Recipient OK Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 6: was busy, 1.1 ms, total idle 16531.904 s, busy 48.244 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 5: was idle, 0.2 ms, total idle 16531.904 s, busy 48.244 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP< DATA\r\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, SMTP DATA received Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP::10024 /var/amavis/tmp/amavis-20080312T094206-19494: -> , SIZE=6513 Received: from server ([127.0.0.1]) by localhost (server [127.0.0.1]) (amavisd-new, port 10024) with LMTP; Wed, 12 Mar 2008 14:18:26 +0100 (CET) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 354 End data with . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, receiving data Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, data-end received Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) LMTP< . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_re("user2@ktl.fi") matches key "(?i-xsm:.*)", result="1" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (local_domains) => true, "user2@ktl.fi" matches, result="1", matching_key="(?i-xsm:.*)" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_re("user3@ktl.fi") matches key "(?i-xsm:.*)", result="1" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (local_domains) => true, "user3@ktl.fi" matches, result="1", matching_key="(?i-xsm:.*)" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) body type: unlabeled, good (h=0, b=0) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) body hash: 9d9f13db44140a5adda8e513a48280b4 Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Original mail size: 6513; quota set to: 3256500 bytes Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Checking: ovG4qRtzOaRm -> , Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) 2822.From: Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_virus_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_virus_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_header_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_header_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) check_header: 0, OK Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_header_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_header_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Checking for banned types and filenames Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_banned_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="DEFAULT" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (banned_filename), 1 matches for "user2@ktl.fi", results: "(constant:DEFAULT)"=>"DEFAULT" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) collect banned table[0]: user2@ktl.fi, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x8ec8c64) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_banned_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="DEFAULT" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (banned_filename), 1 matches for "user3@ktl.fi", results: "(constant:DEFAULT)"=>"DEFAULT" Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) collect banned table[0]: user3@ktl.fi, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x8ec8c64) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) starting banned checks - traversing message structure tree Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) banned check: any=0, all=N (2) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Issued a new file name: p001 Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) presenting full original message to scanners as /var/amavis/tmp/amavis-20080312T094206-19494/parts/p001 Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Using ClamAV-clamd: (built-in interface) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) timer set to 200 s (was 300 s) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ask_av (ClamAV-clamd): query template1: CONTSCAN {}\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Using (ClamAV-clamd) on dir: CONTSCAN /var/amavis/tmp/amavis-20080312T094206-19494/parts\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) timer set to 10 s (was 200 s) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ClamAV-clamd: Connecting to socket /var/run/clamav/clamd Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ClamAV-clamd: Sending CONTSCAN /var/amavis/tmp/amavis-20080312T094206-19494/parts\n to UNIX socket /var/run/clamav/clamd Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer ask_daemon_internal: timer set to 160 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ask_av (ClamAV-clamd) result: /var/amavis/tmp/amavis-20080312T094206-19494/parts: OK\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ask_av (ClamAV-clamd): /var/amavis/tmp/amavis-20080312T094206-19494/parts CLEAN Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ClamAV-clamd result: clean Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer run_av: timer set to 300 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Using Sophie: (built-in interface) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) timer set to 200 s (was 300 s) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ask_av (Sophie): query template1: {}/\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Using (Sophie) on dir: /var/amavis/tmp/amavis-20080312T094206-19494/parts/\n Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) timer set to 10 s (was 200 s) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Sophie: Sending /var/amavis/tmp/amavis-20080312T094206-19494/parts/\n to UNIX socket /var/run/sophie Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Sophie broken pipe (don't worry), retrying (1) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) timer set to 10 s (was 200 s) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Sophie: Connecting to socket /var/run/sophie, retry #1 Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Sophie: Sending /var/amavis/tmp/amavis-20080312T094206-19494/parts/\n to UNIX socket /var/run/sophie Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer ask_daemon_internal: timer set to 160 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ask_av (Sophie) result: 0 Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) ask_av (Sophie): /var/amavis/tmp/amavis-20080312T094206-19494/parts CLEAN Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) Sophie result: clean Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer run_av: timer set to 300 s Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_virus_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_virus_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_spam_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_spam_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) wbl: checking sender Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (blacklist_recip) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user@aserver.tld, user@, aserver.tld, .aserver.tld, .uni-stuttgart.de, .de, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user@aserver.tld), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (blacklist_sender) => undef, "user@aserver.tld" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (whitelist_recip) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user@aserver.tld, user@, aserver.tld, .aserver.tld, .uni-stuttgart.de, .de, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user@aserver.tld), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (whitelist_sender) => undef, "user@aserver.tld" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (score_recip) => undef, "user2@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (blacklist_recip) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user@aserver.tld, user@, aserver.tld, .aserver.tld, .uni-stuttgart.de, .de, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user@aserver.tld), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (blacklist_sender) => undef, "user@aserver.tld" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (whitelist_recip) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user@aserver.tld, user@, aserver.tld, .aserver.tld, .uni-stuttgart.de, .de, . Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user@aserver.tld), no matches Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (whitelist_sender) => undef, "user@aserver.tld" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (score_recip) => undef, "user3@ktl.fi" does not match Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) SpamControl: calling spam scanner Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) spam_scan: DSPAM not available, skipping it Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) timer set to 200 s for SA (was 300 s) Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) calling SA parse, SA version 3.2.2, 3.002002, data as GLOB Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) CALLING SA check Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer spam_scan_sa_finish: timer set to 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) spam_scan: score=-4.398 autolearn=ham tests=[ALL_TRUSTED=-1.8,BAYES_00=-2.599,HTML_MESSAGE=0.001] Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer spam_scan: remaining time = 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) enqueue: stat is not numeric: "" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user2@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag3_level) => undef, "user2@ktl.fi" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_kill_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user2@ktl.fi, user2@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user2@ktl.fi), no matches Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_spam_checks) => undef, "user2@ktl.fi" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) final_destiny (ccat=0) is PASS, recip user2@ktl.fi Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) final_destiny PASS, recip user2@ktl.fi Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user3@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag3_level) => undef, "user3@ktl.fi" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_kill_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) query_keys: user3@ktl.fi, user3@, ktl.fi, .ktl.fi, .fi, . Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup_hash(user3@ktl.fi), no matches Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (bypass_spam_checks) => undef, "user3@ktl.fi" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) final_destiny (ccat=0) is PASS, recip user3@ktl.fi Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) final_destiny PASS, recip user3@ktl.fi Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) do_notify_and_quar: ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(), q_mth=, qar_mth= Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user2@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_kill_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user3@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_kill_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) skip admin notification, no administrators Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) do_notify_and_quarantine - done Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user2@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="1" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_modifies_subj) => true, "user2@ktl.fi" matches, result="1", matching_key="(constant:1)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_subject_tag) => undef, "user2@ktl.fi" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) headers CLUSTERING: NEW CLUSTER : score=-4.398, tag=1, tag2=0, local=1, bl=, s=, mangle= Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) header: X-Virus-Scanned: by amavisd-new at server\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) header: X-Spam-Flag: NO\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) header: X-Spam-Score: -4.398\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) header: X-Spam-Level: \n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) header: X-Spam-Status: No, score=-4.398 tagged_above=-999 required=5\n\ttests=[ALL_TRUSTED=-1.8, BAYES_00=-2.599, HTML_MESSAGE=0.001]\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) header: Received: from server ([127.0.0.1])\n\tby localhost (server [127.0.0.1]) (amavisd-new, port 10024)\n\twith LMTP id ovG4qRtzOaRm; Wed, 12 Mar 2008 14:18:26 +0100 (CET)\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user3@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="1" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_modifies_subj) => true, "user3@ktl.fi" matches, result="1", matching_key="(constant:1)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_subject_tag) => undef, "user3@ktl.fi" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) headers CLUSTERING: joining cluster Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) headers CLUSTERING: done all 2 recips in one go Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) SPAM-TAG, -> ,, No, score=-4.398 tagged_above=-999 required=5 tests=[ALL_TRUSTED=-1.8, BAYES_00=-2.599, HTML_MESSAGE=0.001] Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) (about to connect to [127.0.0.1]:10025) FWD via SMTP: -> , Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp creating socket by IO::Socket::INET: 127.0.0.1 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=1, flush=0, wr=0, timeout=30 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: receiving Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop read 48 chars< 220 server ESMTP Postfix\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to greeting: 220 server ESMTP Postfix Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> EHLO localhost Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=0, flush=1, wr=1, timeout=293 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: sending Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop send 16> EHLO localhost\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=1, flush=0, wr=0, timeout=293 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: receiving Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop read 127 chars< 250-server\r\n250-PIPELINING\r\n250-SIZE 31457280\r\n250-ETRN\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250 DSN\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to EHLO: 250 server\nPIPELINING\nSIZE 31457280\nETRN\nENHANCEDSTATUSCODES\n8BITMIME\nDSN Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) Remote host presents itself as: server, handles DSN, handles PIPELINING Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) AUTH not needed, user='', MTA offers '' Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> MAIL FROM: BODY=7BIT Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> RCPT TO: ORCPT=rfc822;user2@ktl.fi Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> RCPT TO: ORCPT=rfc822;user3@ktl.fi Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> DATA Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=0, flush=1, wr=1, timeout=120 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: sending Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop send 199> MAIL FROM: BODY=7BIT\r\nRCPT TO: ORCPT=rfc822;user2@ktl.fi\r\nRCPT TO: ORCPT=rfc822;user3@ktl.fi\r\nDATA\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=1, flush=0, wr=0, timeout=293 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: receiving Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop read 79 chars< 250 2.1.0 Ok\r\n250 2.1.5 Ok\r\n250 2.1.5 Ok\r\n354 End data with .\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to MAIL (pip): 250 2.1.0 Ok Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to RCPT (pip) (): 250 2.1.5 Ok, id=19494-08, from MTA([127.0.0.1]:10025): 250 2.1.5 Ok Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to RCPT (pip) (): 250 2.1.5 Ok, id=19494-08, from MTA([127.0.0.1]:10025): 250 2.1.5 Ok Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to DATA: 354 End data with . Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) write_header: 0, Amavis::Out::SMTP::Protocol=HASH(0xb601118) Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> QUIT Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=0, flush=1, wr=1, timeout=293 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: sending Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop send 6978> X-Virus-Scanned: by amavisd-new at server\r\nX-Spam-Flag: NO\r\nX-Spam-Score: -4.398\r\nX-Spam-Level: \r\nX-Spam-Status: No, score=-4.398 tagged_above=-999 required=5\r\n\ttests=[ALL_TRUSTE [...] Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: needline=1, flush=0, wr=0, timeout=293 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop: receiving Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rw_loop read 52 chars< 250 2.0.0 Ok: queued as 25C395D03CF\r\n221 2.0.0 Bye\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to data-dot (, etc.): 250 2.0.0 Ok: queued as 25C395D03CF Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp resp to QUIT: 221 2.0.0 Bye Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer fwd-end-chkpnt: timer set to 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) FWD via SMTP: -> ,,BODY=7BIT 250 2.6.0 Ok, id=19494-08, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 25C395D03CF Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer forwarding: remaining time = 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_dsn_cutoff_level_bysender) => undef, "user@aserver.tld" does not match Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) dsn: from MTA 250 NonBlocking:CleanTag -> : on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=1, mta_resp: "250 2.0.0 Ok: queued as 25C395D03CF" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) DSN: SUCC from MTA 250 NonBlocking:CleanTag, no DSN requested: -> Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) dsn: from MTA 250 NonBlocking:CleanTag -> : on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=1, mta_resp: "250 2.0.0 Ok: queued as 25C395D03CF" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) DSN: SUCC from MTA 250 NonBlocking:CleanTag, no DSN requested: -> Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) one_response_for_all : success, r=0,b=0,d=0, ndn_needed=0, '250 2.0.0 Ok: queued as 25C395D03CF' Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) notif=N, suppressed=0, ndn_needed=0, exit=0, 250 2.0.0 Ok: queued as 25C395D03CF Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer delivery-notification: remaining time = 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) Passed CLEAN, -> ,, Message-ID: <95FCCF713536A94E8A504D87BE620F25012C568E@marvin.aserver.tld>, mail_id: ovG4qRtzOaRm, Hits: -4.398, size: 6513, queued_as: 25C395D03CF, 6514 ms Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user2@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_kill_level) => true, "user2@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) Passed CLEAN, -> , Hits: -4.398, tag=-999, tag2=5, kill=5, queued_as: 25C395D03CF, L/Y/0/0 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="-999" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag_level) => true, "user3@ktl.fi" matches, result="-999", matching_key="(constant:-999)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_tag2_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup: (scalar) matches, result="5" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) lookup (spam_kill_level) => true, "user3@ktl.fi" matches, result="5", matching_key="(constant:5)" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) Passed CLEAN, -> , Hits: -4.398, tag=-999, tag2=5, kill=5, queued_as: 25C395D03CF, L/Y/0/0 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer main_log_entry: remaining time = 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) updating snmp variables Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) prolong_timer check done: remaining time = 293 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP response for : "250 2.0.0 Ok: queued as 25C395D03CF" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP response for : "250 2.0.0 Ok: queued as 25C395D03CF" Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250 2.0.0 Ok: queued as 25C395D03CF Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 250 2.0.0 Ok: queued as 25C395D03CF Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) TempDir::strip: /var/amavis/tmp/amavis-20080312T094206-19494 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) rmdir_recursively: /var/amavis/tmp/amavis-20080312T094206-19494/parts, excl=1 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) TIMING [total 6528 ms] - SMTP greeting: 3 (0%)0, SMTP LHLO: 2 (0%)0, SMTP pre-MAIL: 1 (0%)0, SMTP pre-DATA-flush: 6 (0%)0, SMTP DATA: 76 (1%)1, check_init: 2 (0%)1, digest_hdr: 0 (0%)1, digest_body: 0 (0%)1, gen_mail_id: 1 (0%)1, check_header: 5 (0%)1, AV-scan-1: 24 (0%)2, AV-scan-2: 13 (0%)2, spam-wb-list: 6 (0%)2, SA parse: 4 (0%)2, SA check: 6322 (97%)99, update_cache: 9 (0%)99, decide_mail_destiny: 4 (0%)99, fwd-connect: 14 (0%)99, fwd-mail-pip: 4 (0%)100, fwd-rcpt-pip: 1 (0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 1 (0%)100, fwd-data-contents: 0 (0%)100, fwd-end-chkpnt: 8 (0%)100, prepare-dsn: 2 (0%)100, main_log_entry: 15 (0%)100, update_snmp: 2 (0%)100, SMTP pre-response: 1 (0%)100, SMTP response: 1 (0%)100, unlink-1-files: 0 (0%)100, rundown: 0 (0%)100 Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 6: was busy, 6518.4 ms, total idle 16531.904 s, busy 54.762 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, 5: was idle, 0.2 ms, total idle 16531.904 s, busy 54.762 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP< QUIT\r\n Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_my_time 300 s, SMTP QUIT received Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) switch_to_client_time 480 s, smtp response sent Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) SMTP session over, timer stopped Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) exiting process_request Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) post_process_request_hook: timer was not running Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) idle_proc, bye: was busy, 2.5 ms, total idle 16531.904 s, busy 54.765 s Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) load: 0 %, total idle 16531.904 s, busy 54.765 s Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) child_finish_hook: invoking DESTROY methods Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) Amavis::TempDir DESTROY called Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) TempDir removal: empty tempdir is being removed: /var/amavis/tmp/amavis-20080312T094206-19494 Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) rmdir_recursively: /var/amavis/tmp/amavis-20080312T094206-19494, excl= Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) rmdir_recursively: /var/amavis/tmp/amavis-20080312T094206-19494/parts, excl=0 Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) Amavis::Cache DESTROY called Mar 12 17:25:44 server /usr/sbin/amavisd[19494]: (19494-08) Amavis::DB::SNMP DESTROY called