Investigating a quarantined email's score?

[Jon_Starr]

Hi everyone,

I've just had a case of email from a specific sender being quarantined with extremely high scores (20+).

In the users quarantine I have the following:


MailID: meta60014414852124807.mime
Date: 2012-08-13 5:26:21 pm
Sender: xx@xx.co.uk
Subject: RE: xxxxx [AX-AX]
Size(KB): 453.474
Category: SPAM
Detail: 20.6


Right, so as we all know that releasing the email strips the spam header I thought I'd go spelunking in the logs. Opening the meta60014414852124807.mime file gives me Message-ID: <A22DA453DE86D14AAAE52430DFFB5D0F35BE72E3@XXEXCHANGE1.XXdomain.local>'

So a grep in mail.log shows:


Aug 13 17:26:10 untangle spamd[27605]: spamd: connection from localhost [127.0.0.1] at port 3816
Aug 13 17:26:10 untangle spamd[27605]: spamd: setuid to spamc succeeded
Aug 13 17:26:10 untangle spamd[27605]: spamd: checking message <A22DA453DE86D14AAAE52430DFFB5D0F35BE72E3@XXEXCHANGE1.XXdomain.local> for spamc:10001
Aug 13 17:26:21 untangle spamd[27605]: Can't open /var/log/FuzzyOcr.log for writing, check permissions at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 426.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 428.
Aug 13 17:26:21 untangle spamd[27605]: seek() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 429.
Aug 13 17:26:21 untangle spamd[27605]: print() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 430.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 431.
Aug 13 17:26:21 untangle spamd[27605]: Can't open /var/log/FuzzyOcr.log for writing, check permissions at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 426.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 428.
Aug 13 17:26:21 untangle spamd[27605]: seek() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 429.
Aug 13 17:26:21 untangle spamd[27605]: print() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 430.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 431.
Aug 13 17:26:21 untangle spamd[27605]: Can't open /var/log/FuzzyOcr.log for writing, check permissions at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 426.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 428.
Aug 13 17:26:21 untangle spamd[27605]: seek() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 429.
Aug 13 17:26:21 untangle spamd[27605]: print() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 430.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 431.
Aug 13 17:26:21 untangle spamd[27605]: Can't open /var/log/FuzzyOcr.log for writing, check permissions at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 426.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 428.
Aug 13 17:26:21 untangle spamd[27605]: seek() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 429.
Aug 13 17:26:21 untangle spamd[27605]: print() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 430.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 431.
Aug 13 17:26:21 untangle spamd[27605]: Can't open /var/log/FuzzyOcr.log for writing, check permissions at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 426.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 428.
Aug 13 17:26:21 untangle spamd[27605]: seek() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 429.
Aug 13 17:26:21 untangle spamd[27605]: print() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 430.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 431.
Aug 13 17:26:21 untangle spamd[27605]: Can't open /var/log/FuzzyOcr.log for writing, check permissions at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 426.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 428.
Aug 13 17:26:21 untangle spamd[27605]: seek() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 429.
Aug 13 17:26:21 untangle spamd[27605]: print() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 430.
Aug 13 17:26:21 untangle spamd[27605]: flock() on closed filehandle LOGFILE at /usr/share/perl5/Mail/SpamAssassin/Plugin/FuzzyOcr.pm line 431.
Aug 13 17:26:21 untangle spamd[27605]: spamd: identified spam (20.6/5.0) for spamc:10001 in 11.4 seconds, 464359 bytes.
Aug 13 17:26:21 untangle spamd[27605]: spamd: result: Y 20 - AWL,BAYES_00,FUZZY_OCR,HTML_IMAGE_RATIO_08,HTML_MESSAGE scantime=11.4,size=464359,user=spamc,uid=10001,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=3816,mid=<A22DA453DE86D14AAAE52430DFFB5D0F35BE72E3@XXEXCHANGE1.XXdomain.local>,bayes=0.000000,autolearn=no
Aug 13 17:26:21 untangle spamd[8135]: prefork: child states: I


That looks like the message, but I'm not sure WTH is going on. It gave it a massive score because FuzzyOCR crashed?? (the mime file is chock full of encoded, legitimate, images)

Any other log files I can/should check?

Cheers,

Jon


Edit:

Some more pertinent info. The emails are all about detailed financial discussions so are chock full of terms that may seem Nigerian email'ish but as it has the 'BAYES_00' tag I guess that had no contribution to the score?

Also, I've checked the perms on fuzzyocr.log. It was 644 owned by root. So unless fuzzyOCR isn't running under root I can't see how that's the actual issue.

[Jon_Starr]

Ok, I've found a really old bug for FuzzyOCR and applied the suggested permissions fix just in case:

http://forums.untangle.com/spam-bloc...g-through.html
http://bugzilla.untangle.com/show_bug.cgi?id=6305

But this box was originally a fresh install of 9.2.1. Is that bug still current? Also, it was for email NOT being detected as spam whereas my problem is the opposite.

[dmorris]

That file should be chowned to spamc:root.

[Jon_Starr]

Thanks for the quick response.

I've changed the ownership from root:root to spamc:root


Does the rest make sense to you? Was it just corrupt permissions on that log file causing the incorrect scoring?

[dmorris]

What does "incorrect scoring" mean? You don't think those matches sum to 20?
FUZZY_OCR hit is worth 9 points alone I think, so just that alone would probably get it over the threshold.
If your question is why is FUZZY_OCR matching, the answer is likely in that log (that wasn't written)

When you view that log make sure you view it and not edit it or it will change the permissions.

[Jon_Starr]

Ah, thank you. I had it in my head that those were fatal messages from FuzzyOCR and the FUZZY_OCR had been added because it hadn't successfully run.

The images are just corporate decoration, I hadn't even considered they might generate a hit!

I'll wait for another exchange of messages between the two senders and then examine the log which should hopefully be working now.


I've been using the 'tail', 'cat', 'find' and 'grep' commands to view and search through the logs. All of those commands should be safe for viewing things right?