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:<user@aserver.tld> 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 <user@aserver.tld> 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:<user2@ktl.fi> 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 <user2@ktl.fi> 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:<user3@ktl.fi> 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 <user3@ktl.fi> 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: <user@aserver.tld> -> <user2@ktl.fi>,<user3@ktl.fi> 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 <CR><LF>.<CR><LF>
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< .<CR><LF>
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 <user@aserver.tld> -> <user2@ktl.fi>,<user3@ktl.fi>
Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) 2822.From: <user@aserver.tld>
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 <user@aserver.tld>
Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (blacklist_recip<user2@ktl.fi>) => 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<user2@ktl.fi>) => 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<user2@ktl.fi>) => undef, "user2@ktl.fi" does not match
Mar 12 14:18:26 server /usr/sbin/amavisd[19494]: (19494-08) lookup (blacklist_recip<user3@ktl.fi>) => 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<user3@ktl.fi>) => 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<user3@ktl.fi>) => 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 <user2@ktl.fi>: 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: <user3@ktl.fi> 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, <user@aserver.tld> -> <user2@ktl.fi>,<user3@ktl.fi>, 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: <user@aserver.tld> -> <user2@ktl.fi>,<user3@ktl.fi>
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:<user@aserver.tld> BODY=7BIT
Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> RCPT TO:<user2@ktl.fi> ORCPT=rfc822;user2@ktl.fi
Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) smtp cmd> RCPT TO:<user3@ktl.fi> 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:<user@aserver.tld> BODY=7BIT\r\nRCPT TO:<user2@ktl.fi> ORCPT=rfc822;user2@ktl.fi\r\nRCPT TO:<user3@ktl.fi> 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 <CR><LF>.<CR><LF>\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) (<user2@ktl.fi>): 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) (<user3@ktl.fi>): 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 <CR><LF>.<CR><LF>
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 (<user2@ktl.fi>, 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: <user@aserver.tld> -> <user2@ktl.fi>,<user3@ktl.fi>,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 <user@aserver.tld> -> <user2@ktl.fi>: 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: <user@aserver.tld> -> <user2@ktl.fi>
Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) dsn: from MTA 250 NonBlocking:CleanTag <user@aserver.tld> -> <user3@ktl.fi>: 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: <user@aserver.tld> -> <user3@ktl.fi>
Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) one_response_for_all <user@aserver.tld>: 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, <user@aserver.tld> -> <user2@ktl.fi>,<user3@ktl.fi>, 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, <user@aserver.tld> -> <user2@ktl.fi>, 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, <user@aserver.tld> -> <user3@ktl.fi>, 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 <user2@ktl.fi>: "250 2.0.0 Ok: queued as 25C395D03CF"
Mar 12 14:18:33 server /usr/sbin/amavisd[19494]: (19494-08) LMTP response for <user3@ktl.fi>: "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