I've been running SA 3.04 / ClamAV 0.86.2 /qmail-scanner 1.25st for about 2
months now. Things have been working perfectly. I wrote my own stats parsing
script to dump things into a database so I can break down stats based on
domains, spammers, etc...(I have two mail servers acting as load balancing...a
3rd server is where the SQL db sits)
Today, we added a new client to our filtering system, and this client is
receiving email from one address that seemed like a duplicate mysql insert at
first to me, but after investigating further, the mails were actually listed in
/var/spool/qmailscan/mailstats.csv. These are the lines in question in
mailstats.csv:
8357:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
8358:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
8359:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
8360:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
8361:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
8362:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
8363:Wed, 14 Sep 2005 14:06:54 EDT Clear:RC:0(207.198.18.5):SA:1(5.6/5.0):
5.683338 10027 [EMAIL PROTECTED] [EMAIL PROTECTED] Utica
Homeowners will soon offer Identity Theft Coverage! <[EMAIL PROTECTED]>
unig45.gif:5863 1126721210.30212-0.MAILER-02:1109
That's just an sample from mailstats.csv. As it says, SA deems it spam at 5.6
points, and tags it and passes it along (I think). However, a few things
confuse me with this. First of all, multiple entries under the same exact
timestamp seems odd to me. Every piece of data in each line is identical. This
doesn't seem normal, or correct. Secondly, there is NO record of the sender's
email address in /var/spool/qmailscan/qmail-queue.log OR /var/log/maillog. It
only appears in mailstats.csv. Furthermore, when adding the blacklist_from
preference for this domain in my SQL database, I still see entries from this
user in mailstats.csv with the score of 5.6, obviously ignoring my blacklist.
Also, the 5.0 is telling as well, as I have a required_hits preference for this
domain set to 4.0. Scanning through mailstats.csv shows that I have even more
entries which set 5.0 as the bar for spam, incorrectly:
4278:Wed, 14 Sep 2005 09:41:25 EDT
SA:SPAM-DELETE:RC:0(222.108.160.49):SA:1(21.1/5.0): 0 1385 [EMAIL
PROTECTED] [EMAIL PROTECTED] Solid Funding hassle free <[EMAIL
PROTECTED]> MAILER-02112670527972228950-unpacked:1385
4279:Wed, 14 Sep 2005 09:41:25 EDT
SA:SPAM-DELETE:RC:0(222.108.160.49):SA:1(21.1/5.0): 0 1385 [EMAIL
PROTECTED] [EMAIL PROTECTED] Solid Funding hassle free <[EMAIL
PROTECTED]> MAILER-02112670527972228950-unpacked:1385
However, there ARE lines that display correct information:
4298:Wed, 14 Sep 2005 09:41:58 EDT
SA:SPAM-DELETE:RC:0(216.195.74.34):SA:1(10.8/4.0): 0 3658 [EMAIL
PROTECTED] [EMAIL PROTECTED] Undeliverable Mail <[EMAIL PROTECTED]>
MAILER-02112670531272229114-unpacked:3658
4309:Wed, 14 Sep 2005 09:42:16 EDT
Clear:RC:0(209.51.158.242):SA:0(-0.6/4.0): 5.509505 3384 [EMAIL
PROTECTED] [EMAIL PROTECTED] Automatic message from SafestMail
(c2FmZXN0bWFpbF9yZXBseQ==-OTkzMDE4MDE1) <[EMAIL PROTECTED]>
1126705331.29238-0.MAILER-02:2226
Note the 4.0.
I'm so confused...I can't seem to find the reason why it isn't logging to
qmail-queue.log for certain messages. There IS a correlation, however, between
when it doesn't log to qmail-queue.log, and when it uses a base score of 5.0
instead of the sql-deemed 4.0. IT seems both of those conditions occur together
on these 'problem' messages.
Can anyone shed some light on this for me? Thank you so much
Matthew Yette
Senior Engineer (NOC/Operations)
M.A. Polce Consulting
