Mark Martinec wrote:
If this is not the case, it would be worth taking a look at level 4 or 5
log and see how the sender address lookups are being done.
Attached is a legit case of where this is happening.
[EMAIL PROTECTED] is the recipient, [EMAIL PROTECTED]
is the sender which has been whitelisted in the database.
Cami
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
check_mail_begin_task: task_count=74
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(debug_sender) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 250
2.1.0 Sender [EMAIL PROTECTED] OK
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 6:
was busy, 3.1 ms, total idle 487.514 s, busy 170.590 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 5:
was idle, 0.4 ms, total idle 487.514 s, busy 170.590 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after reading SMTP command: remaining time = 300 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP< RCPT
TO:<[EMAIL PROTECTED]>\r\n
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) query_keys:
[EMAIL PROTECTED], mathurs@, mweb.co.za, .mweb.co.za, .co.za, .za, .
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_hash([EMAIL PROTECTED]) matches key "mweb.co.za", result=1
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(local_domains) => true, "[EMAIL PROTECTED]" matches, result="1",
matching_key="mweb.co.za"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) query_keys:
[EMAIL PROTECTED], mathurs, @mweb.co.za, @.mweb.co.za, @.co.za, @.za, @.
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup_sql
"[EMAIL PROTECTED]", query args: "[EMAIL PROTECTED]", "mathurs", "@mweb.co.za",
"@.mweb.co.za", "@.co.za", "@.za", "@."
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup_sql
select: SELECT *,users.id FROM users LEFT JOIN policy ON
users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?,?) ORDER BY
users.priority DESC
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) sql begin,
nontransaction
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) sql:
executing clause: SELECT *,users.id FROM users LEFT JOIN policy ON
users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?,?) ORDER BY
users.priority DESC
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql([EMAIL PROTECTED]) matches, result=(id=>"250611", priority=>"7",
policy_id=>"1", email=>"[EMAIL PROTECTED]", fullname=>"[EMAIL PROTECTED]",
uid=>"mathurs", ibssubscriberno=>"267360", id=>"250611",
policy_name=>"SpamCheckEnabled", virus_lover=>"N", spam_lover=>"N",
banned_files_lover=>"N", bad_header_lover=>"N", bypass_virus_checks=>"N",
bypass_spam_checks=>"N", bypass_banned_checks=>"N", bypass_header_checks=>"N",
spam_modifies_subj=>"N", spam_quarantine_to=>-, spam_tag_level=>"3",
spam_tag2_level=>"7.5", spam_kill_level=>"7.5", id=>"250611")
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql([EMAIL PROTECTED]) matches, result=(id=>"4", priority=>"1",
policy_id=>"1", email=>"@mweb.co.za", fullname=>"Mervyn said so...",
uid=>"@mweb.co.za", ibssubscriberno=>"0", id=>"4",
policy_name=>"SpamCheckEnabled", virus_lover=>"N", spam_lover=>"N",
banned_files_lover=>"N", bad_header_lover=>"N", bypass_virus_checks=>"N",
bypass_spam_checks=>"N", bypass_banned_checks=>"N", bypass_header_checks=>"N",
spam_modifies_subj=>"N", spam_quarantine_to=>-, spam_tag_level=>"3",
spam_tag2_level=>"7.5", spam_kill_level=>"7.5", id=>"4")
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(message_size_limit), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(message_size_limit), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(message_size_limit) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 250
2.1.5 Recipient [EMAIL PROTECTED] OK
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 6:
was busy, 16.4 ms, total idle 487.514 s, busy 170.606 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 5:
was idle, 0.3 ms, total idle 487.514 s, busy 170.606 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after reading SMTP command: remaining time = 300 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP< DATA\r\n
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after DATA received - timer reset: remaining time = 300 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
LMTP:[196.2.50.195]:10024 /var/amavis/tmp/amavis-20051007T180012-03478: <[EMAIL
PROTECTED]> -> <[EMAIL PROTECTED]> Received: SIZE=2137 BODY=8BITMIME from
postwall07.mweb.co.za ([196.2.42.27]) by spamwall01.mweb.co.za
(spamwall01.mweb.co.za [196.2.50.195]) (amavisd-new, port 10024) with LMTP id
03478-01-74 for <[EMAIL PROTECTED]>; Fri, 7 Oct 2005 18:11:10 +0200 (SAST)
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 354 End
data with <CR><LF>.<CR><LF>
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP< .\r\n
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Actual
message size 2136 B, declared 2137 B
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) body hash:
332a59115b898c041f3910d3f9dd6a59
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Original mail
size: 2136; quota set to: 1068000 bytes
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Checking:
mwM7K-2wcotO [217.146.176.73] <[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]>
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Extracting
mime components
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Issued a new
file name: p001
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Charging 1033
bytes to remaining quota 1068000 (out of 1068000, (0%)) - by mime_decode
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) p001 1
Content-Type: text/plain, size: 1033 B, name:
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after mime_decode-1: remaining time = 300 s
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(bypass_header_checks) "[EMAIL PROTECTED]" result=0
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(bypass_header_checks) => false, "[EMAIL PROTECTED]" matches, result="0",
matching_key="/cached/"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) check_header:
OK
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Checking for
banned types and filenames
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(bypass_banned_checks) "[EMAIL PROTECTED]" result=0
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(bypass_banned_checks) => false, "[EMAIL PROTECTED]" matches, result="0",
matching_key="/cached/"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(banned_rulenames), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(banned_rulenames), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup:
(scalar) matches, result="DEFAULT"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(banned_filename), 1 matches for "[EMAIL PROTECTED]", results:
"(constant:DEFAULT)"=>"DEFAULT"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) collect
banned table[0]: [EMAIL PROTECTED], tables:
DEFAULT=>Amavis::Lookup::RE=ARRAY(0xa347cac)
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) starting
banned checks - traversing message structure tree
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
check_for_banned (p001) text/plain
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) doing banned
check for [EMAIL PROTECTED] on text/plain
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_re(["text/plain"]), no matches
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(check_bann:[EMAIL PROTECTED]) => undef, ["text/plain"] does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) p.path [EMAIL
PROTECTED]: "P=p001,L=1,M=text/plain"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) banned check:
any=0, all=N (1)
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) no anti-virus
code loaded, skipping virus_scan
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(bypass_spam_checks) "[EMAIL PROTECTED]" result=0
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(bypass_spam_checks) => false, "[EMAIL PROTECTED]" matches, result="0",
matching_key="/cached/"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) wbl: checking
sender <[EMAIL PROTECTED]>
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(id) "[EMAIL PROTECTED]" result=250611
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(id) "[EMAIL PROTECTED]" result=4
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup, 2
matches for "[EMAIL PROTECTED]", results: "/cached/"=>"250611", "/cached/"=>"4"
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) wbl: (SQL)
recip <[EMAIL PROTECTED]>, 2 matches
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup_sql
disabled for clause: sel_wblist
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(wb), "[EMAIL PROTECTED]" no matching records
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup =>
undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) wbl: (SQL)
recip <[EMAIL PROTECTED]>, rid=250611, got: ""
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup_sql
disabled for clause: sel_wblist
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(wb), "[EMAIL PROTECTED]" no matching records
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup =>
undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) wbl: (SQL)
recip <[EMAIL PROTECTED]>, rid=4, got: ""
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(blacklist_recip<[EMAIL PROTECTED]>) => undef, "[EMAIL PROTECTED]" does not
match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_re("[EMAIL PROTECTED]"), no matches
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(blacklist_sender) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(whitelist_recip<[EMAIL PROTECTED]>) => undef, "[EMAIL PROTECTED]" does not
match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) query_keys:
[EMAIL PROTECTED], mmsain13@, yahoo.es, .yahoo.es, .es, .
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_hash([EMAIL PROTECTED]), no matches
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(whitelist_sender) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) query_keys:
[EMAIL PROTECTED], mathurs@, mweb.co.za, .mweb.co.za, .co.za, .za, .
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_hash([EMAIL PROTECTED]) matches keys: "."=>ARRAY(0x9cda240)
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(score_sender), 1 matches for "[EMAIL PROTECTED]", results:
"."=>[Amavis::Lookup::RE=ARRAY(0x9cda048),HASH(0x9cda0b4)]
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_re("[EMAIL PROTECTED]"), no matches
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) query_keys:
[EMAIL PROTECTED], mmsain13@, yahoo.es, .yahoo.es, .es, .
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_hash([EMAIL PROTECTED]), no matches
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(score_sender<[EMAIL PROTECTED]>) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) spam_scan:
DSPAM not available, skipping it
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) calling SA
parse, SA version 3.1.0
Oct 7 18:11:10 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) CALLING SA
check
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) RETURNED FROM
SA check, time left: 30 s
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after spam_scan_SA: remaining time = 300 s
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) spam_scan:
score=3.7 tests=[BAYES_60=3.5,DNS_FROM_RFC_ABUSE=0.2]
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after spam_scan: remaining time = 300 s
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) enqueue: stat
is not numeric: ""
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_kill_level) "[EMAIL PROTECTED]" result=7.5
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_kill_level) => true, "[EMAIL PROTECTED]" matches, result="7.5",
matching_key="/cached/"
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(message_size_limit), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(message_size_limit), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(message_size_limit) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) header:
Received: from postwall07.mweb.co.za ([196.2.42.27])\n by spamwall01.mweb.co.za
(spamwall01.mweb.co.za [196.2.50.195]) (amavisd-new, port 10024)\n with LMTP id
03478-01-74 for <[EMAIL PROTECTED]>;\n Fri, 7 Oct 2005 18:11:10 +0200 (SAST)\n
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(local), no field, "[EMAIL PROTECTED]" result=1
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(local_domains) => true, "[EMAIL PROTECTED]" matches, result="1",
matching_key="/cached/"
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(bypass_spam_checks) "[EMAIL PROTECTED]" result=0
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(bypass_spam_checks) => false, "[EMAIL PROTECTED]" matches, result="0",
matching_key="/cached/"
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_tag_level) "[EMAIL PROTECTED]" result=3
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_tag_level) => true, "[EMAIL PROTECTED]" matches, result="3",
matching_key="/cached/"
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_tag2_level) "[EMAIL PROTECTED]" result=7.5
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_tag2_level) => true, "[EMAIL PROTECTED]" matches, result="7.5",
matching_key="/cached/"
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_subject_tag), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_subject_tag), no field, "[EMAIL PROTECTED]" result=undef
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_subject_tag) => undef, "[EMAIL PROTECTED]" does not match
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) headers
CLUSTERING: NEW CLUSTER <[EMAIL PROTECTED]>: score=3.7, tag=1, tag2=0, subj=0,
subj_u=0, local=1, bl=, s=
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) header:
X-Spam-Status: No, score=3.7 tagged_above=3 required=7.5 tests=[BAYES_60=3.5,\n
DNS_FROM_RFC_ABUSE=0.2]\n
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) header:
X-Spam-Score: 3.7\n
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) header:
X-Spam-Level: ***\n
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) headers
CLUSTERING: done all 1 recips in one go
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) SPAM-TAG,
<[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]>, No, score=3.7 tagged_above=3
required=7.5 tests=[BAYES_60=3.5, DNS_FROM_RFC_ABUSE=0.2]
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) (about to
connect to [196.2.50.226]:10025) FWD via SMTP: <[EMAIL PROTECTED]> -> <[EMAIL
PROTECTED]>
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) Remote host
presents itself as: smtp.passthru
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after fwd-connect: remaining time = 300 s
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) AUTH not
needed, user='', MTA offers ''
Oct 7 18:11:11 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after fwd-mail-from: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) response to
RCPT TO for <[EMAIL PROTECTED]>: "250 2.1.5 Ok"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after fwd-rcpt-to: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) response to
DATA: "354 Start mail input; end with <CRLF>.<CRLF>"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) write_header:
0, Amavis::Out=HASH(0xe43fae4)
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after fwd-data: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after fwd-data-end: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) response to
data end: "250 2.0.0 Ok: queued as 7A53266"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after fwd-rundown-1: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) FWD via SMTP:
<[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]>, BODY=8BITMIME, 250 2.6.0 Ok,
id=03478-01-74, from MTA([196.2.50.226]:10025): 250 2.0.0 Ok: queued as 7A53266
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after forwarding: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
one_response_for_all <[EMAIL PROTECTED]>: success, r=0,b=0,d=0, dsn_needed=0,
'250 2.6.0 Ok, id=03478-01-74, from MTA([196.2.50.226]:10025): 250 2.0.0 Ok:
queued as 7A53266'
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
warnsender_with_pass=0 (,,,), dsn_needed=0, cnt=, exit=0, 250 2.6.0 Ok,
id=03478-01-74, from MTA([196.2.50.226]:10025): 250 2.0.0 Ok: queued as 7A53266
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after delivery-notification: remaining time = 300 s
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_tag2_level) "[EMAIL PROTECTED]" result=7.5
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_tag2_level) => true, "[EMAIL PROTECTED]" matches, result="7.5",
matching_key="/cached/"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup_ip_acl
(mynetworks): key="217.146.176.73", no match
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) CLEAN,
<[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]>, Message-ID: <[EMAIL PROTECTED]>,
Hits=3.7 tag1=3.0 tag2=7.5 kill=7.5, tests=BAYES_60=3.5,DNS_FROM_RFC_ABUSE=0.2,
[217.146.176.73]
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(local), no field, "[EMAIL PROTECTED]" result=1
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(local_domains) => true, "[EMAIL PROTECTED]" matches, result="1",
matching_key="/cached/"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_tag_level) "[EMAIL PROTECTED]" result=3
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_tag_level) => true, "[EMAIL PROTECTED]" matches, result="3",
matching_key="/cached/"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_tag2_level) "[EMAIL PROTECTED]" result=7.5
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_tag2_level) => true, "[EMAIL PROTECTED]" matches, result="7.5",
matching_key="/cached/"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
lookup_sql_field(spam_kill_level) "[EMAIL PROTECTED]" result=7.5
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) lookup
(spam_kill_level) => true, "[EMAIL PROTECTED]" matches, result="7.5",
matching_key="/cached/"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) <[EMAIL
PROTECTED]>,<[EMAIL PROTECTED]>,Passed,Hits=3.7,Message-ID=<[EMAIL
PROTECTED]>,Size=2136
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) updating snmp
variables
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) sending LMTP
response for <[EMAIL PROTECTED]>: "250 2.6.0 Ok, id=03478-01-74, from
MTA([196.2.50.226]:10025): 250 2.0.0 Ok: queued as 7A53266"
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) timer stopped
after DATA end
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
strip_tempdir: /var/amavis/tmp/amavis-20051007T180012-03478
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74)
rmdir_recursively: /var/amavis/tmp/amavis-20051007T180012-03478/parts, excl=1
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) TIMING [total
1938 ms] - lookup_sql: 18 (1%)1, SMTP pre-DATA-flush: 4 (0%)1, SMTP DATA: 18
(1%)2, body_digest: 1 (0%)2, gen_mail_id: 1 (0%)2, mime_decode: 12 (1%)3,
spam-wb-list: 18 (1%)4, SA msg read: 1 (0%)4, SA parse: 2 (0%)4, SA check: 1669
(86%)90, update_cache: 3 (0%)90, deal_with_mail_size: 2 (0%)90, fwd-connect: 55
(3%)93, fwd-mail-from: 4 (0%)93, fwd-rcpt-to: 4 (0%)94, write-header: 2 (0%)94,
fwd-data: 1 (0%)94, fwd-data-end: 100 (5%)99, fwd-rundown: 3 (0%)99,
main_log_entry: 16 (1%)100, update_snmp: 1 (0%)100, unlink-1-files: 2 (0%)100,
rundown: 1 (0%)100
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 250
2.6.0 Ok, id=03478-01-74, from MTA([196.2.50.226]:10025): 250 2.0.0 Ok: queued
as 7A53266
Oct 7 18:11:12 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 6:
was busy, 1919.7 ms, total idle 487.514 s, busy 172.526 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 5:
was idle, 8589.3 ms, total idle 496.104 s, busy 172.526 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after reading SMTP command: remaining time = 0 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP< RSET\r\n
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 250
2.0.0 Ok RSET
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 6:
was busy, 1.0 ms, total idle 496.104 s, busy 172.527 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 5:
was idle, 0.7 ms, total idle 496.104 s, busy 172.527 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after reading SMTP command: remaining time = 60 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP<
XFORWARD NAME=mail2.securedc.com ADDR=67.18.121.132\r\n
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 250
2.5.0 Ok XFORWARD
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 6:
was busy, 0.9 ms, total idle 496.104 s, busy 172.528 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 5:
was idle, 0.2 ms, total idle 496.105 s, busy 172.528 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after reading SMTP command: remaining time = 60 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP<
XFORWARD PROTO=SMTP HELO=mail2.securedc.com\r\n
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP> 250
2.5.0 Ok XFORWARD
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 6:
was busy, 1.6 ms, total idle 496.105 s, busy 172.530 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) idle_proc, 5:
was idle, 0.4 ms, total idle 496.105 s, busy 172.530 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after reading SMTP command: remaining time = 60 s
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) LMTP< MAIL
FROM:<[EMAIL PROTECTED]> SIZE=5378\r\n
Oct 7 18:11:20 spamwall01.mweb.co.za amavis[3478]: (03478-01-74) prolong_timer
after MAIL FROM received - timer reset: remaining time = 300 s
