Amavis Not Marking Mail as Spam

Question

Level 1

110 points

Amavis Not Marking Mail as Spam

Hi,

I've been going round and round with this for weeks now and despite following everyone's advice, I cannot get the mail server to mark spam, as spam.

We've setup two local users, junk and not junk and have fed thousands of messages into the junk folder. We've then manually ran the learn junkmail script and it seems to finish ok.

Amavis.conf is set with the following:

$sa tag_leveldeflt = -999; # add spam info headers if at, or above that level
$sa tag2_leveldeflt = 1.0; # add 'spam detected' headers at that level

Junk messages come in with the following headers:

Return-Path: <Elfinn-3537347@LMXMEDIA.COM>
Received: from murder ([unix socket])
by goliath.xxxxxxx.net (Cyrus v2.2.12-OS X 10.4.8) with LMTPA;
Wed, 25 Jun 2008 12:00:13 +0100
X-Sieve: CMU Sieve 2.2
Received: from localhost (localhost.localdomain [127.0.0.1])
by goliath. xxxxxxx.net (Postfix) with ESMTP id C8CFD404F55
for <simon@xxxxxxx.com>; Wed, 25 Jun 2008 12:00:11 +0100 (BST)
Received: from goliath. xxxxxxx.net ([127.0.0.1])
by localhost (localhost [127.0.0.1]) (amavisd-new, port 10024) with ESMTP
id 08193-03 for <simon@ xxxxxxx.com>; Wed, 25 Jun 2008 11:59:51 +0100 (BST)
Received: from 76-14-167-131.wsac.wavecable.com (76-14-167-131.wsac.wavecable.com [76.14.167.131])
by goliath. xxxxxxx.net (Postfix) with ESMTP id ECC9C404F45
for <simon@ xxxxxxx.com>; Wed, 25 Jun 2008 11:59:50 +0100 (BST)
To: simon@ xxxxxxx.com
Subject: Make money this way
From: Elfinn <Elfinn-3537347@LMXMEDIA.COM>
Content-Type: text/plain; format=flowed; delsp=yes; charset=koi8-r
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Date: Fri, 25 Jul 2008 04:00:16 -0700
Message-ID: <kr.jjtzkwdhscqbag@suicide-1dceb94>
User-Agent: Opera Mail/9.50 (Win32)
X-Virus-Scanned: by amavisd-new at xxxxxxx.net

There doesn't seem to be a log file for amavis although there is a folder filled with stuff at /var/amavis

It's infurating not being able to get this to work! Would anyone be able to help please?

Thanks in advance,

Simon

G5, Mac OS X (10.4.11)

Posted on Jun 26, 2008 2:52 AM

Reply

Answer 1

Simon Morley Author

Level 1

110 points

Jul 1, 2008 12:31 AM in response to Simon Morley

Is there anyone that can help or at least point us in the right direction? We're getting pretty desperate about this!

Reply

Answer 2

Jul 1, 2008 6:45 AM in response to Simon Morley

Hello Simon,

the configuration details you'vo provided are not very helpful,
however I reckon the line
+X-Virus-Scanned: by amavisd-new at xxxxxxx.net+
actually means that the header was inserted by YOUR mail server, since
that is what
#$sa tag_leveldeflt=-999+
results in: Adding the X-Virus-Scanned header to all local mail.
And thus we see the amavis is infact working.

Why it doesn't tag mails as spam is yet another story.
To narrow down the problem I'd suggest to send yourself a GTUBE mail
(see http://spamassassin.apache.org/gtube/). This MUST be marked as spam by your server.
If not some diving into /var/log/mail.log and /var/log/system.log will be required.

Reply

Answer 3

davidh

Level 4

1,896 points

Jul 1, 2008 9:56 AM in response to Herr Lazaro

In relation specifically to the spamassassin training you've been trying to do, there's also a bug in Apple's default spam-training in 10.4 server, which might not be fixed as of 10.4.8

see http://osx.topicdesk.com/content/view/37/58/

But to manually fix it yourself, see (and be sure you understand)
http://www.afp548.com/forum/viewtopic.php?forum=26&showtopic=9245&mode=&onlytopi c=&show=10

As well, if you update your amavis(d)-new, (See the topicdesk.com site and if you use the material, please, do make a contribution. I have no affiliation with the site, FYI),
you can get a bit more granular with the amavisd.conf

eg:
$sa tag_leveldeflt = -999; # add spam info headers if at, or above that level
$sa tag2_leveldeflt = 2.1; # add 'spam detected' headers at that level
$sa kill_leveldeflt = 5.5; # triggers spam evasive actions (e.g. blocks mail)

I'm not suggesting those settings are good for you, adjust as necessary

Reply

Answer 4

Simon Morley Author

Level 1

110 points

Jul 1, 2008 9:57 AM in response to Herr Lazaro

Hi,

Thanks a lot for answering.

Sent myself a message with that gtube thingy and it is still not marked...

Mail.log / system.log don't show anything interesting.

Would any more configuration files help this?

Simon

Reply

Answer 5

Simon Morley Author

Level 1

110 points

Jul 1, 2008 10:06 AM in response to davidh

My amavis config file has the following:

$sa tag_leveldeflt = -999; # add spam info headers if at, or above that level
$sa tag2_leveldeflt = 1.0; # add 'spam detected' headers at that level
$sa kill_leveldeflt = 22.0;

Tried to remove the .spamassassin folder /var/amavis and replacing with a sym link to one in clamav but nothing happens and it's not marked.

Simon

Reply

Answer 6

Jul 2, 2008 4:06 AM in response to Simon Morley

Simon Morley wrote:
Hi,

Thanks a lot for answering.

Sent myself a message with that gtube thingy and it is still not marked...

Mail.log / system.log don't show anything interesting.

Increase the verbosity of logging to maximum with SA and try GTUBE again.
Check if there are any additional SMTP-Headers like X-Spam_Score or X-SPAM-Status in the mail.
There should be logentries reading something like

Date mail amavis\[process-id\]: message

in /var/log/system.log. Examine them.
If there aren't any, your configuration probably is totally broken. Places to look
/etc/postfix/master.cf # check for an entry labeled 'smtp-amavis'
/etc/postfix/main.cf # look for an entry 'content_filter = smtp-amavis:[127.0.0.1]:10024'
and finally
/etc/amavisd.conf

Reply

Answer 7

Simon Morley Author

Level 1

110 points

Jul 2, 2008 4:26 AM in response to Herr Lazaro

Hi There, thanks for the help with this.

Running with amavis in debug mode I think and have made log level debug in sa.

Grep for amavis in mail.log / system.log shows nothing.

Amavis.log shows this:

query_keys: simon@bobsuruncle.com, simon@, bobsuruncle.com, .bobsuruncle.com, .com, .
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup_hash(simon@bobsuruncle.com), no matches
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup_acl(simon@bobsuruncle.com), no match
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup (local_domains) => undef, "simon@bobsuruncle.com" does not match
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) query_keys: simon@bobsuruncle.com, simon@, bobsuruncle.com, .bobsuruncle.com, .com, .
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup_hash(simon@bobsuruncle.com), no matches
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup (bypass viruschecks) => undef, "simon@bobsuruncle.com" does not match
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) query_keys: simon@bobsuruncle.com, simon@, bobsuruncle.com, .bobsuruncle.com, .com, .
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup_hash(simon@bobsuruncle.com), no matches
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup (bypass spamchecks) => undef, "simon@bobsuruncle.com" does not match
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup: (scalar) matches, result="-999"
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup (spam taglevel) => true, "simon@bobsuruncle.com" matches, result="-999", matching_key="(constant:-999)"
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup: (scalar) matches, result="1"
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) lookup (spam tag2level) => true, "simon@bobsuruncle.com" matches, result="1", matching_key="(constant:1)"
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) headers CLUSTERING: NEW CLUSTER <simon@bobsuruncle.com>: hits=-0.383, tag=0, tag2=0, subj=0, subj_u=0, local=0, bl=
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) header: X-Virus-Scanned: by amavisd-new at bobsuruncle.net\n
Jul 2 12:19:53 goliath.bobsuruncle.net /usr/bin/amavisd[3875]: (03875-01) headers CLUSTERING: done all 1 recips in one go

Thanks again, hope this is more helpful than before.

Simon

Message was edited by: Simon Morley

Reply

Answer 8

pterobyte

Level 6

11,104 points

Jul 2, 2008 6:34 AM in response to Simon Morley

Do you use virtual domains or local host aliases? If yes make sure in amavisd.conf @local domainsmaps lists all domains or alternatively is set to:
@local domainsmaps = ( 1 );

HTH,
Alex

Reply

Answer 9

Jul 2, 2008 6:34 AM in response to Simon Morley

Looks like amavis gets properly involved (and adding 'X-Virus-Scanned:' headers) but analysis at all is performed.
Smells like your /etc/amavisd.conf disables all content checks.

If you have the file /etc/amavisd.conf.original on your server, it might be a good idea to start all over with a copy of that file.

Sorry I can't give more precise hint, but if you look at /etc/amavisd.conf you'll find ther are dozens of possibilities for errors.

Reply

Answer 10

Simon Morley Author

Level 1

110 points

Jul 2, 2008 6:48 AM in response to pterobyte

Hi,

Virtual hosting is not enabled.

I've put that line in and reloaded amavis, but we're seeing this now which wasn't happening earlier and don't know if its serious...

goliath:/etc Admin$ sudo amavisd reload debug
No PID file /var/amavis/amavisd.pid, can't reload the process
Jul 2 14:47:34 goliath.bobsuruncle.net [6153]: at the END handler: invoking DESTROY methods
goliath:/etc Admin$ sudo amavisd stop debug
No PID file /var/amavis/amavisd.pid, can't stop the process
Jul 2 14:47:40 goliath.bobsuruncle.net [6154]: at the END handler: invoking DESTROY methods
goliath:/etc Admin$ sudo amavisd start debug
goliath:/etc Admin$

Thanks a lot,

Simon

Reply

Answer 11

Simon Morley Author

Level 1

110 points

Jul 2, 2008 7:04 AM in response to Herr Lazaro

Hi,

Sadly don't have the original however we have one called amavisd.conf.personal which is not something I recognise but have moved it to amavisd.conf and restarted but still nothing...

Where would I be able to locate an original copy of the configuration file?

Thanks,

Simon

Reply

Answer 12

Simon Morley Author

Level 1

110 points

Jul 2, 2008 7:11 AM in response to Simon Morley

On moving to that other configuration file the log looks different:

Jul 2 15:08:28 goliath.bobsuruncle.net /usr/bin/amavisd[6691]: SpamControl: initializing Mail::SpamAssassin
Jul 2 15:08:29 goliath.bobsuruncle.net /usr/bin/amavisd[6691]: SpamControl: done
Jul 2 15:08:32 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: starting. /usr/bin/amavisd at goliath.bobsuruncle.net amavisd-new-2.2.0 (20041102), Unicode aware
Jul 2 15:08:32 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: user=, EUID: 0 (0); group=, EGID: 0 20 80 5 29 4 3 2 1 0 (0 20 80 5 29 4 3 2 1 0)
Jul 2 15:08:32 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: Perl version 5.008006
Jul 2 15:08:33 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: Net::Server: 2008/07/02-15:08:33 Amavis (type Net::Server::PreForkSimple) starting! pid(6687)
Jul 2 15:08:33 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: Net::Server: Binding to UNIX socket file /var/amavis/amavisd.sock using SOCK_STREAM
Jul 2 15:08:33 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1
Jul 2 15:08:33 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: Net::Server: 2008/07/02-15:08:33 Can't connect to TCP port 10024 on 127.0.0.1 [Address already in use]\n at line 86 in file /System/Library/Perl/Extras/5.8.6/Net/Server/Proto/TCP.pm
Jul 2 15:08:33 goliath.bobsuruncle.net /usr/bin/amavisd[6687]: Net::Server: 2008/07/02-15:08:33 Server closing!
Jul 2 15:09:06 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) ESMTP::10024 /var/amavis/amavis-20080702T150906-06692: <simon@bobsuruncle.com> -> <simon@bobsuruncle.com> Received: SIZE=1110 from goliath.bobsuruncle.net ([127.0.0.1]) by localhost (goliath.bobsuruncle.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 06692-01 for <simon@bobsuruncle.com>; Wed, 2 Jul 2008 15:09:06 +0100 (BST)
Jul 2 15:09:06 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) Checking: [10.0.1.55] <simon@bobsuruncle.com> -> <simon@bobsuruncle.com>
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) p001 1 Content-Type: text/plain, size: 445 B, name:
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) local delivery: <simon@bobsuruncle.com> -> <spam-quarantine>, mbx=/var/virusmails/spam-0815ce848b6b1dcd58ac397055b01353-20080702-150906-06692 -01.gz
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) SPAM, <simon@bobsuruncle.com> -> <simon@bobsuruncle.com>, Yes, hits=995.484 tag=-999 tag2=1 kill=22 tests=ALL_TRUSTED, AWL, BAYES_00, GTUBE, quarantine spam-0815ce848b6b1dcd58ac397055b01353-20080702-150906-06692-01 (spam-quarantine)
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) FWD via SMTP: [127.0.0.1]:10025 <simon@bobsuruncle.com> -> <simon@bobsuruncle.com>
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) Passed, <simon@bobsuruncle.com> -> <simon@bobsuruncle.com>, quarantine spam-0815ce848b6b1dcd58ac397055b01353-20080702-150906-06692-01, Message-ID: <4E1761CE-6213-4B8B-AC33-E2CFE9C1F6B6@bobsuruncle.com>, Hits: 995.484
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) Passed SPAM, <simon@bobsuruncle.com> -> <simon@bobsuruncle.com>, Hits: 995.484, tag=-999, tag2=1, kill=22, 0/Y/Y/Y
Jul 2 15:09:07 goliath.bobsuruncle.net /usr/bin/amavisd[6692]: (06692-01) TIMING [total 1063 ms] - SMTP EHLO: 50 (5%), SMTP pre-MAIL: 3 (0%), mkdir tempdir: 1 (0%), create email.txt: 2 (0%), SMTP pre-DATA-flush: 14 (1%), SMTP DATA: 1 (0%), body_hash: 2 (0%), mkdir parts: 4 (0%), mime_decode: 42 (4%), get-file-type1: 28 (3%), decompose_part: 2 (0%), parts_decode: 0 (0%), spam-wb-list: 12 (1%), SA msg read: 2 (0%), SA parse: 10 (1%), SA check: 656 (62%), update_cache: 1 (0%), write-header: 31 (3%), save-to-local-mailbox: 3 (0%), post-do_spam: 3 (0%), fwd-connect: 59 (6%), fwd-mail-from: 3 (0%), fwd-rcpt-to: 4 (0%), write-header: 7 (1%), fwd-data: 1 (0%), fwd-data-end: 26 (2%), fwd-rundown: 3 (0%), main logentry: 16 (2%), update_snmp: 0 (0%), unlink-1-files: 75 (7%), rundown: 1 (0%)

I know that's probably a little hard to read!

Simon

Reply

Answer 13

pterobyte

Level 6

11,104 points

Jul 2, 2008 7:12 AM in response to Simon Morley

This is how you should stop and start amavisd after making changes on OS X Server:

sudo /bin/launchctl unload /System/Library/LaunchDaemons/org.amavis.amavisd.plist

sudo /bin/launchctl load /System/Library/LaunchDaemons/org.amavis.amavisd.plist

Reply

Answer 14

Jul 2, 2008 7:17 AM in response to Simon Morley

Looks as if its working now!

You may need to adjust your thresholds now to reasonable values but I think thats it.

Reply

Answer 15

Simon Morley Author

Level 1

110 points

Jul 2, 2008 7:23 AM in response to pterobyte

Thanks,

Just rebooted the server and now it's marking as spam correctly, with the scores etc.

Not actually sure what changed...

If we have our junkmail and notjunkmail boxes, should we be using the learn junk mail apple script and shouldn't this be done automatically? Do I need to set a cron to do so?

Thanks,

Simon

Reply