hi all... great tutorial on virtual postfix tutorial ... it all works great and mail gets delivered and scanned .... Only even now and then a message appears in mail.log and amavisd.log like: Code: Apr 14 10:09:57 adam amavisd-new[18705]: (18705-07) lookup_sql: 2013, Lost connection to MySQL server during query Apr 14 10:09:57 adam amavisd-new[18705]: (18705-07) NOTICE: Disconnected from SQL server Apr 14 10:09:57 adam amavisd-new[18705]: (18705-07) TROUBLE in check_mail: creating_partsdir FAILED: DBD::mysql::st execute failed: Lost connection to MySQL server during query at (eval 41) line 238, <GEN16> line 2855. Apr 14 10:09:57 adam amavisd-new[18705]: (18705-07) PRESERVING EVIDENCE in /var/lib/amavis/amavis-20060413T084946-18705 this particular mail got in the mailq and when i requed it, it got delivered. Any ideas what this can be?
You can tryto remove all the proxy: strings in /etc/postfix/main.cf, e.g. replace Code: virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf with Code: virtual_mailbox_domains = mysql:/etc/postfix/mysql-virtual_domains.cf and do the same for all other lines with proxy: Restart Postfix afterwards.
If you use proxy:, then Postfix uses only one persistent MySQL connection; if you don't use it, Postfix creates a new connection everytime.
this morning i again saw the error message again Code: Apr 20 08:59:23 adam amavisd-new[2374]: (02374-04) lookup_sql: 2013, Lost connection to MySQL server during query Apr 20 08:59:23 adam amavisd-new[2374]: (02374-04) NOTICE: Disconnected from SQL server Apr 20 08:59:23 adam amavisd-new[2374]: (02374-04) TROUBLE in check_mail: creating_partsdir FAILED: DBD::mysql::st execute failed: Lost connection to MySQL adam during query at (eval 41) line 238, <GEN16> line 2833. Apr 20 08:59:23 adam amavisd-new[2374]: (02374-04) PRESERVING EVIDENCE in /var/lib/amavis/amavis-20060419T160329-02374 this mail also appears in the mailq, and i have to requeue it..... any ideas?
alright... thanks... i will go and try to gather some information with amavisd.... will keep you posted
i figured out a little bit what the cause is, I haven't got a very busy mailserver and it mostly happens in the night, due the 'inactivitiy' of amavisd it loses the connection to the database. When i restart amavisd it is solved. so i can solve this by a cron restart of amavisd, but for now i'm happy as it is
Were there any other people with this problem? How did you figure out that amavis was dropping it's connection to the database and not re-establishing it? I followed the tutorial and I'm ending up with this when I try to send: Code: Jul 29 00:29:16 localhost amavis[11979]: (11961-01) run_command: child process [11979] failed to exec /usr/bin/file /var/lib/amavis/amavis-20060729T002916-11961/parts/part-00001: Can't close main::stdin: Bad file descriptor at /usr/sbin/amavisd-new line 1131. Jul 29 00:29:16 localhost amavis[11961]: (11961-01) TROUBLE in check_mail: decoding2-get-file-types FAILED: 'file' utility (/usr/bin/file) failed, status=1 (256 ) at /usr/sbin/amavisd-new line 3853. Jul 29 00:29:16 localhost amavis[11961]: (11961-01) PRESERVING EVIDENCE in /var/lib/amavis/amavis-20060729T002916-11961 Jul 29 00:29:16 localhost postfix/smtp[11977]: 7386A9B0C14: to=<email>, relay=127.0.0.1[127.0.0.1], delay=0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=11961-01, decoding2-get-file-types FAILED: 'file' utility (/usr/bin/file) failed, status=1 (256 ) at /usr/sbin/amavisd-new line 3853. (in reply to end of DATA command))
Actually the solution was to make mysql use a tcp port by commenting out the skip-networking line in /etc/mysql/my.cnf For some reason smptd absolutely couldn't access mysql otherwise. (Reboot the server?! This isn't windows! lol) Beyond that, amavis was still having problems: These errors were found in the syslog. Jul 29 16:14:33 localhost amavis[16341]: (16092-07) run_command: child process [16341] failed to exec /usr/bin/file /var/lib/amavis/amavis-20060729T161433-16092/parts/part-00001: Can't close main::stdin: Bad file descriptor at /usr/sbin/amavisd-new line 1131. Jul 29 16:14:33 localhost amavis[16092]: (16092-07) TROUBLE in check_mail: decoding2-get-file-types FAILED: 'file' utility (/usr/bin/file) failed, status=1 (256 ) at /usr/sbin/amavisd-new line 3853. So a friend and I traced it down as far as we could and ultimately filed a debian bug report. http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=380409 I should add to that bug report all the amavis info I suppose: Code: Jul 30 09:05:26 localhost amavis[2535]: Perl version 5.008004 Jul 30 09:05:26 localhost amavis[2535]: Module Amavis::Conf 1.15 Jul 30 09:05:26 localhost amavis[2535]: Module Archive::Tar 1.29 Jul 30 09:05:26 localhost amavis[2535]: Module Archive::Zip 1.16 Jul 30 09:05:26 localhost amavis[2535]: Module Compress::Zlib 1.42 Jul 30 09:05:26 localhost amavis[2535]: Module Convert::TNEF 0.17 Jul 30 09:05:26 localhost amavis[2535]: Module Convert::UUlib 1.06 Jul 30 09:05:26 localhost amavis[2535]: Module DBI 1.51 Jul 30 09:05:26 localhost amavis[2535]: Module MIME::Entity 5.420 Jul 30 09:05:26 localhost amavis[2535]: Module MIME::Parser 5.420 Jul 30 09:05:26 localhost amavis[2535]: Module MIME::Tools 5.420 Jul 30 09:05:26 localhost amavis[2535]: Module Mail::Header 1.74 Jul 30 09:05:26 localhost amavis[2535]: Module Mail::Internet 1.74 Jul 30 09:05:26 localhost amavis[2535]: Module Net::Cmd 2.26 Jul 30 09:05:26 localhost amavis[2535]: Module Net::SMTP 2.29 Jul 30 09:05:26 localhost amavis[2535]: Module Net::Server 0.94 Jul 30 09:05:26 localhost amavis[2535]: Module Time::HiRes 1.87 Jul 30 09:05:26 localhost amavis[2535]: Module Unix::Syslog 0.99 Jul 30 09:05:26 localhost amavis[2536]: Found $file at /usr/bin/file Jul 30 09:05:26 localhost amavis[2536]: No $arc, not using it Jul 30 09:05:26 localhost amavis[2536]: Found $gzip at /bin/gzip Jul 30 09:05:26 localhost amavis[2536]: Found $bzip2 at /usr/bin/bzip2 Jul 30 09:05:26 localhost amavis[2536]: No $lzop, not using it Jul 30 09:05:26 localhost amavis[2536]: No $lha, not using it Jul 30 09:05:26 localhost amavis[2536]: Found $unarj at /usr/bin/arj Jul 30 09:05:26 localhost amavis[2536]: Found $uncompress at /bin/uncompress Jul 30 09:05:26 localhost amavis[2536]: No $unfreeze, not using it Jul 30 09:05:26 localhost amavis[2536]: No $unrar, not using it Jul 30 09:05:26 localhost amavis[2536]: Found $zoo at /usr/bin/zoo Jul 30 09:05:26 localhost amavis[2536]: Found $cpio at /bin/cpio Jul 30 09:05:26 localhost amavis[2536]: Using internal av scanner code for (primary) Clam Antivirus-clamd Jul 30 09:05:26 localhost amavis[2536]: Found secondary av scanner Clam Antivirus - clamscan at /usr/bin/clamscan For the time being I've commented out the amavis line in /etc/postfix/main.cf to disable it and so far everything seems to be working. (minus virus scanning) In all honesty, I've never had amavis work 100% correctly on any machine I've used it. I'd be interested in hearing alternative ways to get clamav scanning.
I may have found the solution here: http://www.freespamfilter.org/forum/viewtopic.php?p=1342&sid=9284826f3bda10e476c0a9f23c0947ee Downgrade Net::Server to 0.90. I'm about to try it as soon as I figure out how to do that with cpan. I'll post my results. Update: It worked! amavisd-new-20030616-p10 REQUIRES Net::Server 0.90 and not something newer. Onto the next error: Jul 30 10:06:07 localhost amavis[5072]: (05072-01) Clam Antivirus-clamd FAILED - unknown status: /var/lib/amavis/amavis-20060730T100607-05072/parts: lstat() failed. ERROR\n Jul 30 10:06:07 localhost amavis[5072]: (05072-01) WARN: all primary virus scanners failed, considering backups
Are you sure you followed the tutorial as close as possible? It has always worked for me exactly as described there. It seems as if clamd isn't running. You can check with Code: ps aux Start it, if necessary.
I believe I followed it very closely and I've gone through it several times double checking but it's certainly possible I've missed something. clamav is running and I do get a different error if I shut it down. I'm not too concerned since the backup scanner is working but I'm going to try and trouble shoot it a bit more tonight. A couple of questions for you though... I had to change a line in /etc/default/spamassassin. I can't remember the variable off the top of my head but I had to change it from 0 to 1 for spamd to start. Did I miss this from the tutorial? I'm also not seeing the spamassassin header in received emails. I do see the amavis header. Should I see a spamassassin header? I was assuming it would write the score. It almost seems as if email isn't getting filtered through SA.
Update: clamav problem fixed The solution to my clamav-daemon error was to add a line to the bottom of /etc/clamav/clamd.conf: AllowSupplementaryGroups Now I need to go re-read the tutorial and see if that was missing or if I messed up.
