Mailscanner + spamassassin + clamav package

[marcelloc]

run saupdate on console to be sure spamassassin rules are fine/up-to-date.

In one server I forgot to check it and got no messages marked as spam.

[FiSHswe]

Hi Marcelloc!
i've never been able to make Mailscanner start  :(
This is what i keep gettin' in log, any ideas?

php: /pkg_edit.php: The command '/usr/local/etc/rc.d/mailscanner start' returned exit code '1', the output was 'Starting mailscanner. eval: /usr/local/sbin/mailscanner: not found /usr/local/etc/rc.d/mailscanner: WARNING: failed to start mailscanner'

[marcelloc]

@FiSHswe:

i've never been able to make Mailscanner start  :(

Did you tried to check and save all config tabs on it's gui?

[FiSHswe]

Yep, Done that!
I have tried to uninstall and reinstall several times and still the same error in log.

When i try to run sa-update i get "command not found"
freshclam gives me "ERROR: Can't create temporary directory /var/db/clamav/clamav-3294ff160111fb6d1625622676d2d9c9
Hint: The database directory must be writable for UID 106 or GID 106"

ps ax | grep -i mailscanner
259  0  S+    0:00.00 grep -i mailscanner

running spamassassin –lint gives me "spamassassin: Command not found

Dont recall that i ever uninstalled any old version of mailscanner.
Whats the proper way to do a total manual cleanup of mailscanner?

[marcelloc]

@FiSHswe:

When i try to run sa-update i get "command not found"

weird

@FiSHswe:

freshclam gives me "ERROR: Can't create temporary directory /var/db/clamav/clamav-3294ff160111fb6d1625622676d2d9c9
Hint: The database directory must be writable for UID 106 or GID 106"

try to fix this missing dir/permission

[fabiana]

Hi

First I want to say thanks for this cool Package. The only problem we have is, that I think the Option Antivirus -> "Allow Pssword-Protected archives" is ignored. If I set this in the config File it works, but in the GUI it's ignored.

Thanks.
Fabian

[marcelloc]

@fabiana:

I think the Option Antivirus -> "Allow Pssword-Protected archives" is ignored. If I set this in the config File it works, but in the GUI it's ignored.

Thanks for your feedback fabiana,

I've pushed a fix for it.

reinstall the package in 15 minutes or manually fix /usr/local/pkg/mailscanner_antivirus.xml following this

https://github.com/bsdperimeter/pfsense-packages/commit/2d121b3b6fe79e301daf57b6a1060675a8886023

att,
Marcello Coutinho

[fabiana]

Hi

Thanks, I just reinstalled the package. But now I get in /var/log/system.log:

Jan 22 09:52:48 legatech root: /usr/local/etc/rc.d/clamav-clamd: WARNING: failed to start clamav_clamd

If I try to start "/usr/local/etc/rc.d/clamav-clamd start" I get:

Starting clamav_clamd.
ERROR: Can't open /var/log/clamav/clamd.log in append mode (check permissions!).
ERROR: Can't initialize the internal logger
/usr/local/etc/rc.d/clamav-clamd: WARNING: failed to start clamav_clamd

Then I "touch /var/log/clamav/clamd.log", "chown postfix:clamav clamd.log", "chmod 777 clamd.log" (could be more restrictive I guess) and try to start I get:

Starting clamav_clamd.

ERROR: LOCAL: Socket file /var/run/clamav/clamd.sock could not be bound: Permission denied
/usr/local/etc/rc.d/clamav-clamd: WARNING: failed to start clamav_clamd

chmod 777 /var/run/clamav fixed the problem. But also here, maybe it should be more restrictive.

And after reinstall, I miss "/usr/local/etc/rc.d/mailscanner", in the "services" Tab, I can't start the mailscanner…HELP! :)

Ok, I extracted the file from the .tbz and mailscanner finally works. postfix and mailscanner services don't start automatically after reboot, but I can start them manually in Status -> Services, then everything is fine.

Regards,
Fabian

[jeppunen]

I have managed to get spamassasin to work with my Pfsense. I had to do manually some chown changes but now spam gets blocked as supposed. Great packake.

But I have a problem with delay. The delay is about 30-50 seconds for every message. Which settings I should check first to get delay to 1-15 seconds?

Cheers!

[marcelloc]

It depends, what hardware are you using for mail scanner?

[jeppunen]

@marcelloc:

It depends, what hardware are you using for mail scanner?

The hardware is HP Proliant DL360 G4 Server, with 4G RAM, RAID1 74Gb HDD, 2 x XEON so there is guite a powerfull hardware. I found one mail that went throught the process from the maillog:

Mar 20 16:48:27 pfsense postfix/smtpd[45773]: connect from newsletter.nebula.fi[217.149.57.249]
Mar 20 16:48:27 pfsense postfix/smtpd[45773]: warning: connect to private/anvil: No such file or directory
Mar 20 16:48:28 pfsense postfix/smtpd[45773]: warning: connect to private/anvil: No such file or directory
Mar 20 16:48:28 pfsense postfix/smtpd[45773]: warning: problem talking to server private/anvil: No such file or directory
Mar 20 16:48:28 pfsense postfix/smtpd[45773]: 6AB8262CEED: client=newsletter.nebula.fi[217.149.57.249]
Mar 20 16:48:28 pfsense postfix/cleanup[45923]: 6AB8262CEED: hold: header From: Jerkka Tuote Oy jerkkatuote@jerkkatuote.fifrom newsletter.nebula.fi[217.149.57.249]; from= errors@mailerrs.hosting.fito=<posti@<em>ocxxxxxxxxx.fi> proto=ESMTP helo= <newsletter.nebula.fi>Mar 20 16:48:28 pfsense postfix/cleanup[45923]: 6AB8262CEED: message-id=20130320144826.E824280104@newsletter.nebula.fi
Mar 20 16:48:28 pfsense postfix/smtpd[45773]: warning: connect to private/anvil: No such file or directory
Mar 20 16:48:29 pfsense MailScanner[56797]: New Batch: Scanning 1 messages, 290323 bytes
Mar 20 16:48:29 pfsense postfix/smtpd[45773]: warning: connect to private/anvil: No such file or directory
Mar 20 16:48:29 pfsense postfix/smtpd[45773]: warning: problem talking to server private/anvil: No such file or directory
Mar 20 16:48:29 pfsense postfix/smtpd[45773]: disconnect from newsletter.nebula.fi[217.149.57.249]
Mar 20 16:48:29 pfsense MailScanner[56797]: Virus and Content Scanning: Starting
Mar 20 16:49:03 pfsense MailScanner[56797]: Spam Checks: Starting Mar 20 16:49:03 pfsense MailScanner[56797]: Expired 4 records from the SpamAssassin cache
Mar 20 16:49:03 pfsense MailScanner[56797]: Message 6AB8262CEED.A4789 from 217.149.57.249 (errors@mailerrs.hosting.fi) to ocxxxxxxxxx.fi is too big for spam checks (290323 > 200000 bytes)
Mar 20 16:49:03 pfsense MailScanner[56797]: Requeue: 6AB8262CEED.A4789 to 94AE862CEFE
Mar 20 16:49:03 pfsense MailScanner[56797]: Uninfected: Delivered 1 messages
Mar 20 16:49:03 pfsense postfix/qmgr[30137]: 94AE862CEFE: from=errors@mailerrs.hosting.fi, size=289619, nrcpt=1 (queue active)
Mar 20 16:49:03 pfsense MailScanner[56797]: Deleted 1 messages from processing-database
Mar 20 16:49:03 pfsense postfix/smtp[19548]: 94AE862CEFE: to=<posti@<em>ocxxxxxxxxx.fi .fi>, relay=62.216.102.245[62.216.102.245]:25, delay=36, delays=36/0.01/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D349B7FE54)
Mar 20 16:49:03 pfsense postfix/qmgr[30137]: 94AE862CEFE: removed

So there is 30 second delay from virus scanning to spam check:

Is this an artificial delay controlled via some config or is it a problem?

Thanx for your answer Marcello, you have done a great job with this package :)</posti@<em>/errors@mailerrs.hosting.fi</newsletter.nebula.fi></posti@<em>/errors@mailerrs.hosting.fi/jerkkatuote@jerkkatuote.fi

[jeppunen]

@jeppunen:

Mar 20 16:48:29 pfsense MailScanner[56797]: Virus and Content Scanning: Starting
Mar 20 16:49:03 pfsense MailScanner[56797]: Spam Checks: Starting

Here is the more detailed version (with debug on) of the similar message log:

Mar 21 07:32:16 pfsense MailScanner[60965]: New Batch: Scanning 1 messages, 4334 bytes
Mar 21 07:32:16 pfsense MailScanner[60965]: Created attachment dirs for 1 messages
Mar 21 07:32:16 pfsense MailScanner[60965]: Completed checking by /usr/bin/file
Mar 21 07:32:16 pfsense MailScanner[60965]: Virus and Content Scanning: Starting
Mar 21 07:32:16 pfsense MailScanner[60965]: Commencing scanning by clamav…
Mar 21 07:32:44 pfsense MailScanner[60965]: Completed scanning by clamav
Mar 21 07:32:44 pfsense MailScanner[60965]: Spam Checks: Starting
Mar 21 07:32:44 pfsense MailScanner[60965]: Expired 2 records from the SpamAssassin cache
Mar 21 07:32:52 pfsense MailScanner[60965]: SpamAssassin returned 0
Mar 21 07:32:52 pfsense MailScanner[60965]: Requeue: 099E562CFE2.A127A to 0A1B662CFE4
Mar 21 07:32:52 pfsense MailScanner[60965]: About to deliver 1 messages
Mar 21 07:32:52 pfsense MailScanner[60965]: Uninfected: Delivered 1 messages

It seems that clamav takes quite a lot time to complete, but why is that? The hardware should be powerful enough to handle the scanning in couple of seconds. What could be wrong?

[jeppunen]

Ok, to resolve my slow scanning problen, I'm trying to get to the starting point and I have removed all packages (Postfix, Mailscanner, HAVP) and deleted all the files I could find that are related to mailscanner or postfix and PERL. Then I have reinstalled postfix and mailscanner (nothing else packages).

Commands I executed and came out clear:

ps ax | grep -i mailscanner:
11207  ??  S      0:01.13 MailScanner: waiting for messages (perl5.12.4)
14283  ??  S      0:00.75 MailScanner: waiting for messages (perl5.12.4)
14518  ??  S      0:00.77 MailScanner: waiting for messages (perl5.12.4)

/usr/local/bin/sa-update
/usr/local/bin/spamassassin –lint

But:
/usr/local/bin/freshclam gives error:

ERROR: Parse error at line 20: Unknown option MilterSocket
ERROR: Can't open/parse the config file /usr/local/etc/freshclam.conf

Mail is flowing through the scanner but in the maillog there is error:

Mar 22 12:24:25 pfsense MailScanner[50143]: Virus and Content Scanning: Starting
Mar 22 12:24:25 pfsense MailScanner[50143]: ERROR: Can't open file or directory
Mar 22 12:24:25 pfsense MailScanner[50143]: Spam Checks: Starting

Are these errors related and how can I resolve the MilterSocket error?

Cheers!

[jeppunen]

@jeppunen:

Mar 22 12:24:25 pfsense MailScanner[50143]: Virus and Content Scanning: Starting
Mar 22 12:24:25 pfsense MailScanner[50143]: ERROR: Can't open file or directory
Mar 22 12:24:25 pfsense MailScanner[50143]: Spam Checks: Starting

Are these errors related and how can I resolve the MilterSocket error?

Yes, they were! Virus Scanner did not complete, because it did not found any database. I fixed the MilterSocker error just by uncommenting the row from the /usr/local/etc/freshclam.conf (plus few other lines gave me an error) and I had to add line "DatabaseMirror db.fi.clamav.net" to the freshclam.conf.

After this freshclam downloaded latest database and now I see nice results, only 10 seconds of scanning time and this is fine by me:

Mar 22 13:38:56 pfsense MailScanner[14670]: Virus and Content Scanning: Starting
Mar 22 13:39:06 pfsense MailScanner[14670]: Spam Checks: Starting

So problem solved, hope my few past posts helps someone else also to debug their slow scanning problem.

But one question still remains; is the clamav better to use or clamd? Am I correct if I say that clamd is a service and clamav has to start each time to do the scanning? At least in my enviroment clamav takes about 15-20 seconds to pass the message and with clamd it is only about 5 seconds. So I'm currently going with the clamd.

[cymesa]

I have a fresh install of pfSense 2.0.3 with lasted Postfix 2.10.0, after spending a good time setting up the whole system and Postfix, I installed the Mailscanner 4.84.5_3 and then Squid 3.1.20. But Mailscanner not start, this is the error:
############################################################################
php: /pkg_edit.php: The command '/usr/local/etc/rc.d/mailscanner start' returned exit code '1', the output was 'Starting mailscanner. Can't load '/usr/local/lib/perl5/site_perl/5.12.4/mach/auto/Filesys/Df/Df.so' for module Filesys::Df: /usr/local/lib/perl5/site_perl/5.12.4/mach/auto/Filesys/Df/Df.so: Undefined symbol "PL_stack_max" at /usr/local/lib/perl5/5.12.4/mach/DynaLoader.pm line 200. at /usr/local/sbin/mailscanner line 91 Compilation failed in require at /usr/local/sbin/mailscanner line 91. BEGIN failed–compilation aborted at /usr/local/sbin/mailscanner line 91. /usr/local/etc/rc.d/mailscanner: WARNING: failed to start mailscanner'
#############################################################################
I removed the Mailscanner and I installed again with the same result.
My pkg_info | grep perl show:
p5-DBI-1.616_1
p5-Error-0.17016
p5-MIME-Tools-5.502,2
perl-5.12.4_3
perl-threaded-5.12.4_4
What should I do? And thank you very much for your excellent work.
Cy

[marcelloc]

@cymesa:

What should I do? And thank you very much for your excellent work.

Change first line of mailscanner package to match perl version your using.

Or try to uninstall all perl versions and then install mailscanner package.

[cymesa]

Thanks for the early response, I really appreciate it.
The problem was in the installation of squid3 and mailscanner, both programs install different versions of perl and clamav respectively. Installing in this order:
squid3
postfix
mailscanner
They're working well, now I'm configure and testing.
Excellent work marcelloc, good health! and good luck! my friend.
Att.
Cy

[dsy]

Hello

The mailscanner service does not start on my pfsense 2.1RC0 (buid may 31):

Jun 4 08:40:51	postfix/postfix-script[97787]: fatal: the Postfix mail system is already running
Jun 4 08:40:49	php: : The command '/usr/local/etc/rc.d/mailscanner stop' returned exit code '1', the output was 'mailscanner not running? (check /var/run/MailScanner.pid).'
Jun 4 08:40:29	php: : Starting MailScanner
Jun 4 08:40:29	root: /usr/pbi/mailscanner-i386/etc/rc.d/clamav-clamd: WARNING: failed precmd routine for clamav_clamd
Jun 4 08:40:29	root: /usr/pbi/mailscanner-i386/etc/rc.d/clamav-clamd: WARNING: /var/db/clamav is not a directory.
Jun 4 08:40:29	php: : Starting clamav-clamd daemon
Jun 4 08:40:29	php: : No clamav database found, running freshclam in background.
Jun 4 08:40:29	check_reload_status: Syncing firewall
Jun 4 08:40:06	php: : Starting MailScanner

But postfix forwarder service seems to work fine:

Jun 4 08:36:50	php: : sync_package_postfix called with via_rpc=no
Jun 4 08:36:50	php: : sync_package_postfix called with via_rpc=no
Jun 4 08:36:50	php: : sync_package_postfix called with via_rpc=no
Jun 4 08:36:50	php: : sync_package_postfix called with via_rpc=no
Jun 4 08:36:50	php: : Postfix setup completed
Jun 4 08:36:50	php: : Reloading/starting postfix
Jun 4 08:36:49	php: : Writing rc_file
Jun 4 08:36:47	php: : Writing out configuration
Jun 4 08:36:47	php: : The command '/usr/local/sbin/postfix reload' returned exit code '1', the output was '/usr/pbi/postfix-i386/sbin/postconf: warning: /usr/pbi/postfix-i386/etc/postfix/master.cf: unused parameter: user=postfix'
Jun 4 08:36:47	postfix/postfix-script[6805]: fatal: the Postfix mail system is not running
Jun 4 08:36:47	syslogd: kernel boot file is /boot/kernel/kernel
Jun 4 08:36:47	syslogd: exiting on signal 15
Jun 4 08:36:45	php: : sync_package_postfix called with via_rpc=no

Packages versions:
-mailscanner = 4.84.5_3 pkg v.0.2.2
-postfix forwarder = 2.10.0 pkg v.2.3.5
-squid3 = 3.1.20 pkg 2.0.6
-perl = 5.12.4_4

Postfix antispam parameters:
-use third part antispam = checked
-message hold mode = manual
-software = mailscanner

Parameters in /usr/pbi/mailscanner-i386/etc:
-clamd.conf: User = postfix
-freshclam.conf: Databaseowner = postfix
-MailScanner.conf: Run As User = postfix

Thanks

[zlyzwy]

Hi Marcelloc,

I just found the mailscanner service can't startup at boot time. The postfix and other services are totally no problem. Only mailscanner service status is 'stopped' in service tab. I've tried to restart it many times… It never works...
Here is my startup log:

Jun 19 20:20:07	kernel: VMware memory control driver initialized
Jun 19 20:20:07	php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 19 20:20:07	postfix/postfix-script[18716]: fatal: the Postfix mail system is already running
Jun 19 20:20:04	php: : Restarting dccifd
Jun 19 20:19:27	php: : Restarting clamav-clamd daemon
Jun 19 20:19:25	check_reload_status: Syncing firewall
Jun 19 20:19:21	php: : Restarting dccifd
Jun 19 20:18:45	php: : Restarting clamav-clamd daemon
Jun 19 20:18:42	check_reload_status: Syncing firewall
Jun 19 20:18:38	php: : Restarting dccifd
Jun 19 20:18:02	php: : Restarting clamav-clamd daemon
Jun 19 20:17:59	check_reload_status: Syncing firewall
Jun 19 20:17:54	php: : Restarting dccifd
Jun 19 20:17:18	php: : Restarting clamav-clamd daemon
Jun 19 20:17:16	check_reload_status: Syncing firewall
Jun 19 20:17:12	php: : Restarting dccifd
Jun 19 20:16:35	php: : Restarting clamav-clamd daemon
Jun 19 20:16:34	check_reload_status: Syncing firewall
Jun 19 20:16:29	php: : Restarting dccifd
Jun 19 20:15:52	php: : Restarting clamav-clamd daemon
Jun 19 20:15:50	check_reload_status: Syncing firewall
Jun 19 20:15:45	php: : Restarting dccifd
Jun 19 20:13:18	php: : Restarting clamav-clamd daemon
Jun 19 20:13:17	check_reload_status: Syncing firewall
Jun 19 20:13:15	php: : Restarting dccifd
Jun 19 20:12:39	root: /usr/local/etc/rc.d/clamav-clamd: WARNING: failed to start clamav_clamd
Jun 19 20:12:39	check_reload_status: Syncing firewall
Jun 19 20:12:38	php: : Restarting clamav-clamd daemon
Jun 19 20:12:27	php: : Starting dccifd
Jun 19 20:12:27	php: : Starting clamav-clamd daemon
Jun 19 20:12:26	check_reload_status: Syncing firewall
Jun 19 20:12:20	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:19	apinger: rrdtool respawning too fast, waiting 300s.
Jun 19 20:12:17	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:15	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:12	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:10	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:07	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:05	postfix/postfix-script[53596]: fatal: mail system startup failed
Jun 19 20:12:04	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:04	postfix/master[46800]: fatal: daemon initialization failure
Jun 19 20:12:03	postfix/master[46887]: fatal: open lock file pid/master.pid: unable to set exclusive lock: Resource temporarily unavailable
Jun 19 20:12:02	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:12:01	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 19 20:11:58	php: : Postfix setup completed
Jun 19 20:11:57	php: : Reloading/starting postfix
Jun 19 20:11:56	php: : Writing rc_file
Jun 19 20:11:54	php: : Writing out configuration
Jun 19 20:11:54	php: : The command '/usr/local/sbin/postfix reload' returned exit code '1', the output was '/usr/local/sbin/postconf: warning: /usr/local/etc/postfix/master.cf: unused parameter: user=postfix'
Jun 19 20:11:54	postfix/postfix-script[34252]: fatal: the Postfix mail system is not running
Jun 19 20:11:53	syslogd: kernel boot file is /boot/kernel/kernel
Jun 19 20:11:53	syslogd: exiting on signal 15
Jun 19 20:11:52	check_reload_status: Syncing firewall
Jun 19 20:11:48	php: : Postfix setup completed
Jun 19 20:11:48	postfix/postfix-script[35685]: fatal: the Postfix mail system is not running
Jun 19 20:11:47	php: : Reloading/starting postfix
Jun 19 20:11:46	php: : Writing rc_file
Jun 19 20:11:44	php: : Writing out configuration
Jun 19 20:11:44	php: : The command '/usr/local/sbin/postfix reload' returned exit code '1', the output was '/usr/local/sbin/postconf: warning: /usr/local/etc/postfix/master.cf: unused parameter: user=postfix'
Jun 19 20:11:44	postfix/postfix-script[9249]: fatal: the Postfix mail system is not running
Jun 19 20:11:43	syslogd: kernel boot file is /boot/kernel/kernel
Jun 19 20:11:43	syslogd: exiting on signal 15
Jun 19 20:11:39	php: : Postfix setup completed
Jun 19 20:11:39	postfix/postfix-script[42277]: fatal: the Postfix mail system is not running
Jun 19 20:11:39	php: : Reloading/starting postfix
Jun 19 20:11:38	php: : Writing rc_file
Jun 19 20:11:36	php: : Writing out configuration
Jun 19 20:11:36	php: : The command '/usr/local/sbin/postfix reload' returned exit code '1', the output was '/usr/local/sbin/postconf: warning: /usr/local/etc/postfix/master.cf: unused parameter: user=postfix'
Jun 19 20:11:36	postfix/postfix-script[39102]: fatal: the Postfix mail system is not running

I am running 2.0.3-RELEASE (i386) in a vm machine. It was working fine until I reboot it yesterday…

Thanks for any help in advance...
Zlyzwy

[expert_az]

Hello,

i'm getting this error on my /var/log/maillog file

Clamd::ERROR:: UNKNOWN CLAMD RETURN ./lstat() failed: Permission denied. ERROR :: /var/spool/MailScanner/incoming/5559

anyway fix this issue?seems permisssion error ,i did some search /usr/local/etc/MailScanner/MailScanner.conf.

But this file do not retain changes after first MailScanner save from web gui.