Hello Gary, Mark, This is what postconf message_size_limit says: # postconf message_size_limit message_size_limit = 10240000
set of amavisd log entries for the TROUBLE message: **************************** # grep '27727-04' mail-20051227 Dec 25 22:35:21 mail amavis[27727]: (27727-04) ESMTP::10024 /var/spool/amavis/amavis-20051225T222829-27727: <[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]> Received: SIZE=85704 from mydomain.com ([127.0.0.1]) by localhost (mydomain.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 27727-04 for <[EMAIL PROTECTED]>; Sun, 25 Dec 2005 22:35:21 +0200 (IST) Dec 25 22:35:21 mail amavis[27727]: (27727-04) Checking: <[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]> Dec 25 22:45:48 mail amavis[27727]: (27727-04) TROUBLE in check_mail: decoding2-get-file-types FAILED: timed out Dec 25 22:45:48 mail amavis[27727]: (27727-04) PRESERVING EVIDENCE in /var/spool/amavis/amavis-20051225T222829-27727 Dec 25 22:45:48 mail amavis[27727]: (27727-04) TIMING [total 627447 ms] - SMTP EHLO: 1 (0%), SMTP pre-MAIL: 0 (0%), SMTP pre-DATA-flush: 3 (0%), SMTP DATA: 46 (0%), body hash: 1 (0%), mime_decode: 31 (0%), rundown: 627363 (100%) Dec 25 20:45:53 mail postfix/smtp[27886]: EB945D7B0A: to=<[EMAIL PROTECTED]>, orig_to=<[EMAIL PROTECTED]>, relay=127.0.0.1[127.0.0.1], delay=634, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=27727-04, decoding2-get-file-types FAILED: timed out (in reply to end of DATA command)) The output of 'amavisd debug': ******************** mail:/var/spool/amavis # su vscan mail:/var/spool/amavis # /usr/sbin/amavisd debug Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: starting. amavisd at mail.mydomain.com amavisd-new-20030616-p9, Unicode aware, LC_CTYPE=en_US.UTF-8 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Perl version 5.008003 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Amavis::Conf 1.15 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Archive::Tar 1.08 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Archive::Zip 1.14 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Compress::Zlib 1.33 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Convert::TNEF 0.17 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Convert::UUlib 1.0 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module DB_File 1.808 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module MIME::Entity 5.404 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module MIME::Parser 5.406 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module MIME::Tools 5.411 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Mail::Header 1.60 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Mail::Internet 1.60 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Mail::SpamAssassin 2.64 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Net::Cmd 2.24 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Net::DNS 0.46 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Net::SMTP 2.26 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Net::Server 0.87 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Time::HiRes 1.52 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Module Unix::Syslog 0.100 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found myself: /usr/sbin/amavisd -c /etc/amavisd.conf Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Lookup::SQL code NOT loaded Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Lookup::LDAP code NOT loaded Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: AMCL-in protocol code loaded Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: SMTP-in protocol code loaded Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: ANTI-VIRUS code loaded Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: ANTI-SPAM code loaded Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Net::Server: 2005/12/31-14:14:38 Amavis (type Net::Server::PreForkSimple) starting! pid(15231) Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Net::Server: Binding to UNIX socket file /var/spool/amavis/amavisd.sock using SOCK_STREAM Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Net::Server: Setting gid to "101 101" Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Net::Server: Setting uid to "65" Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Net::Server: Setting up serialization via flock Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $file at /usr/bin/file Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $arc at /usr/bin/arc Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $gzip at /usr/bin/gzip Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $bzip2 at /usr/bin/bzip2 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No $lzop, not using it Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $lha at /usr/bin/lha Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $unarj at /usr/bin/unarj Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $uncompress at /usr/bin/gzip -d Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No $unfreeze, not using it Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $unrar at /usr/bin/unrar Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $zoo at /usr/bin/zoo Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found $cpio at /usr/bin/cpio Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Using internal av scanner code for (primary) Clam Antivirus-clamd Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: KasperskyLab AVP - aveclient Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: KasperskyLab AntiViral Toolkit Pro (AVP) Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: KasperskyLab AVPDaemonClient Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: H+BEDV AntiVir or CentralCommand Vexira Antivirus Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: Command AntiVirus for Linux Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: Symantec CarrierScan via Symantec CommandLineScanner Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: Symantec AntiVirus Scan Engine Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: drweb - DrWeb Antivirus Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: F-Secure Antivirus Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: CAI InoculateIT Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: MkS_Vir for Linux (beta) Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: MkS_Vir daemon Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: ESET Software NOD32 Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: ESET Software NOD32 - Client/Server Version Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: Norman Virus Control v5 / Linux Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: Panda Antivirus for Linux Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: NAI McAfee AntiVirus (uvscan) Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: VirusBuster Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: CyberSoft VFind Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: Ikarus AntiVirus for Linux Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No primary av scanner: BitDefender Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: Found secondary av scanner Clam Antivirus - clamscan at /usr/bin/clamscan Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No secondary av scanner: FRISK F-Prot Antivirus Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No secondary av scanner: Trend Micro FileScanner Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: No secondary av scanner: KasperskyLab kavscanner Dec 31 14:14:38 mail.mydomain.com amavisd[15231]: SpamControl: initializing Mail::SpamAssassin Dec 31 14:14:39 mail.mydomain.com amavisd[15231]: SpamControl: done Dec 31 14:14:39 mail.mydomain.com amavisd[15231]: Net::Server: Beginning prefork (2 processes) Dec 31 14:14:39 mail.mydomain.com amavisd[15231]: Net::Server: Starting "2" children Dec 31 14:14:39 mail.mydomain.com amavisd[15232]: Net::Server: Child Preforked (15232) Dec 31 14:14:39 mail.mydomain.com amavisd[15231]: Net::Server: Parent ready for children. Dec 31 14:14:39 mail.mydomain.com amavisd[15233]: Net::Server: Child Preforked (15233) ------------------------------- Sorry I don't have any preserved evidence at: /var/spool/amavis/amavis-20051225T222829-27727/email.txt I've deleted this folder along with many other folders residing at /var/spool/amavis and taken GB of the FS at the time of the problem discovered. Could you conclude something on the amavisd problem I had from the information presented above? Could I do something to prevent these kind of problems happening again in the future? Best Regards, Leon Kolchinsky -----Original Message----- From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED] On Behalf Of Gary V Sent: Wednesday, December 28, 2005 6:51 PM To: amavis-user@lists.sourceforge.net Subject: Re: [AMaViS-user] RE: How to clean /var/spool/amavis directory automatically lkolchin wrote: > Hi, > I've run (find /var/spool/amavis -type d -name 'amavis-*' -prune -mmin +30 > -exec rm -rf {} \; > Restarted amavisd-new, clamAV and postfix, and it seems to work OK now, > But I want to avoid this in the future and find the cause of that bug. > These are the versions installed on my server: > amavisd-new-20030616p9-3.6 Tue Sep 6 16:46:59 2005 > spamassassin-2.64-3.2 Tue Sep 6 16:46:51 2005 > perl-spamassassin-2.64-3.2 Tue Sep 6 16:46:30 2005 > As far as I can see I've started to get "status=deferred" messages at Dec 22 > 04:24:01 and this message repeated every 16 min. > not only for [EMAIL PROTECTED] user but also for other users: > ----------------------------------------------------------------- > Dec 22 04:24:01 mail postfix/pipe[24644]: 054301BB9B: to=<[EMAIL PROTECTED]>, > relay=cyrus, delay=231660, status=defer > red (temporary failure) > Dec 22 04:24:01 mail postfix/pipe[24641]: 49FB41F5F9: to=<[EMAIL PROTECTED]>, > relay=cyrus, delay=142821, status=defer > red (temporary failure) > Dec 22 04:24:01 mail postfix/pipe[24644]: 9D4321F5CA: to=<[EMAIL PROTECTED]>, > relay=cyrus, delay=230213, status=defer > red (temporary failure) The above appears to be a problem with cyrus (or the user's mailbox? Dunno). > Dec 22 04:24:31 mail postfix/smtp[24635]: connect to 24.on.cc[66.246.195.41]: > Connection timed out (port 25) > Dec 22 04:24:31 mail postfix/smtp[24635]: 2DD121F5CB: to=<[EMAIL PROTECTED]>, > relay=none, delay=202768, status=deferred (connect t > o 24.on.cc[66.246.195.41]: Connection timed out) > Dec 22 04:24:31 mail postfix/smtp[24637]: connect to > linux.uovs.ac.za[196.21.181.2]: Connection timed out (port 25) > Dec 22 04:24:31 mail postfix/smtp[24639]: connect to 24.on.cc[66.246.195.41]: > Connection timed out (port 25) > Dec 22 04:24:31 mail postfix/smtp[24640]: connect to > linux.uovs.ac.za[196.21.181.2]: Connection timed out (port 25) > Dec 22 04:24:31 mail postfix/smtp[24637]: 801141F5E5: to=<[EMAIL PROTECTED]>, > relay=none, delay=202450, status=deferred ( > connect to linux.uovs.ac.za[196.21.181.2]: Connection timed out) > Dec 22 04:24:31 mail postfix/smtp[24639]: 8F64F1C4EE: to=<[EMAIL PROTECTED]>, > relay=none, delay=202451, status=deferred (connect t > o 24.on.cc[66.246.195.41]: Connection timed out) > Dec 22 04:24:31 mail postfix/smtp[24640]: E771C1B44E: to=<[EMAIL PROTECTED]>, > relay=none, delay=202770, status=deferred ( > connect to linux.uovs.ac.za[196.21.181.2]: Connection timed out) > ------------------------------------------------------------------- The above appear to be normal undeliverable DSNs, not a problem. > It seems that some users got this message and some got their mail as they > should. What message are you referring to? > I see "TROUBLE" message on Dec 25 22:45:48 (See below): > ---------------------------------------------------------------- > Dec 25 22:45:48 mail amavis[27727]: (27727-04) TROUBLE in check_mail: > decoding2-get-file-types FAILED: timed out > Dec 25 22:45:48 mail amavis[27727]: (27727-04) PRESERVING EVIDENCE in > /var/spool/amavis/amavis-20051225T222829-27727 > Dec 25 22:45:48 mail amavis[27727]: (27727-04) TIMING [total 627447 ms] - > SMTP EHLO: 1 (0%), SMTP pre-MAIL: 0 (0%), SMTP pre- > DATA-flush: 3 (0%), SMTP DATA: 46 (0%), body hash: 1 (0%), mime_decode: 31 > (0%), rundown: 627363 (100%) This is where the amavisd-new problem is. Don't know what the cause is. What does 'postconf message_size_limit' say? Maybe you should show the output of 'amavisd debug' so we can see what versions of external programs you are using. Maybe it would be of some use to see the entire set of amavisd log entries for this particular message. grep '27727-04' /var/log/maillog (for example) It may be of use to also look at the preserved evidence: /var/spool/amavis/amavis-20051225T222829-27727/email.txt to see if it tells any stories. > Dec 25 22:45:49 mail postfix/smtpd[28010]: too many errors after RCPT from > bzq-224-205.red.bezeqint.net[212.179.224.205] > Dec 25 22:45:49 mail postfix/smtpd[28010]: disconnect from > bzq-224-205.red.bezeqint.net[212.179.224.205] > Dec 25 22:45:50 mail postfix/smtpd[28010]: connect from > mr1.haifa.ac.il[132.74.1.39] The above log entries are unrelated to any of this, and are normal. > Any thoughts/suggestions? > Regards, > Leon Gary V ------------------------------------------------------- This SF.net email is sponsored by: Splunk Inc. Do you grep through log files for problems? Stop! Download the new AJAX search engine that makes searching your log files as easy as surfing the web. DOWNLOAD SPLUNK! http://ads.osdn.com/?ad_id=7637&alloc_id=16865&op=click _______________________________________________ AMaViS-user mailing list AMaViS-user@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/amavis-user AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3 AMaViS-HowTos:http://www.amavis.org/howto/ ------------------------------------------------------- This SF.net email is sponsored by: Splunk Inc. Do you grep through log files for problems? Stop! Download the new AJAX search engine that makes searching your log files as easy as surfing the web. DOWNLOAD SPLUNK! http://ads.osdn.com/?ad_idv37&alloc_id865&op=click _______________________________________________ AMaViS-user mailing list AMaViS-user@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/amavis-user AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3 AMaViS-HowTos:http://www.amavis.org/howto/
