I have been having a problem with my amavis-new spamassassin install. I have
had a user who complains of spam getting through despite the fact that I am
using dns black lists and rule modifications to try and keep up with things.
The most annoying part that I find is that the messages that get through
have no SA tags in them. I have set the tags trigger at -999 so I should see
headers in all of my messages. After turning up my verbosity on my log files
I find that SA's rules are not being called on these messages at all (except
of course for Bayse which seems to only remove points from these messages.
Anyone who can help me figure this out would be much appreciated.
Here is my log output for this message exchange
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) SMTP> 220 [127.0.0.1] ESMTP
amavisd-new service ready
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 4: was busy, 2.4 ms,
total idle 24.570 s, busy 4.828 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.2 ms,
total idle 24.570 s, busy 4.828 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) SMTP< EHLO ws3.adiis.net\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250-[127.0.0.1]
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250-PIPELINING
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250-SIZE
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250-8BITMIME
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250-ENHANCEDSTATUSCODES
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250 XFORWARD NAME ADDR
PROTO HELO
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 6: was busy, 1.1 ms,
total idle 24.570 s, busy 4.829 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.2 ms,
total idle 24.571 s, busy 4.829 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP< XFORWARD
NAME=ms1.adiis.net ADDR=207.177.36.3\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250 2.5.0 Ok XFORWARD
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 6: was busy, 0.6 ms,
total idle 24.571 s, busy 4.830 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.1 ms,
total idle 24.571 s, busy 4.830 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP< XFORWARD PROTO=ESMTP
HELO=ms1.adiis.net\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250 2.5.0 Ok XFORWARD
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 6: was busy, 0.6 ms,
total idle 24.571 s, busy 4.830 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.1 ms,
total idle 24.571 s, busy 4.830 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP< MAIL
FROM:<[EMAIL PROTECTED]> SIZE=1483\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after MAIL FROM
received - timer reset: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) check_mail_begin_task:
task_count=3
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) lookup (debug_sender) => undef,
"[EMAIL PROTECTED]" does not match
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250 2.1.0 Sender
[EMAIL PROTECTED] OK
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 6: was busy, 1.3 ms,
total idle 24.571 s, busy 4.832 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.1 ms,
total idle 24.571 s, busy 4.832 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP< RCPT
TO:<[EMAIL PROTECTED]>\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250 2.1.5 Recipient
[EMAIL PROTECTED] OK
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 6: was busy, 0.6 ms,
total idle 24.571 s, busy 4.832 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.1 ms,
total idle 24.571 s, busy 4.832 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP< RCPT
TO:<[EMAIL PROTECTED]>\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP> 250 2.1.5 Recipient
[EMAIL PROTECTED] OK
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 6: was busy, 0.6 ms,
total idle 24.571 s, busy 4.833 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) idle_proc, 5: was idle, 0.1 ms,
total idle 24.571 s, busy 4.833 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after reading
SMTP command: remaining time = 480 s
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) ESMTP< DATA\r\n
Jun 20 15:17:28 ws3 amavis[8850]: (08850-03) prolong_timer after DATA
received - timer res