Menu
▾
▴
RE: [AMaViS-user] RE: How to clean /var/spool/amavis directory automatically
|
From: <lko...@un...> - 2005-12-31 12:33:03
|
Hello Gary, Mark, This is what postconf message_size_limit says: # postconf message_size_limit message_size_limit =3D 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: = <rk...@un...> -> <het...@my...> Received: = SIZE=3D85704 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 = <het...@my...>; Sun, 25 Dec 2005 22:35:21 +0200 (IST) Dec 25 22:35:21 mail amavis[27727]: (27727-04) Checking: = <rk...@un...> -> <het...@my...> 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=3D<het...@my...>, orig_to=3D<het...@my...>, = relay=3D127.0.0.1[127.0.0.1], delay=3D634, status=3Ddeferred (host = 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=3D27727-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=3Den_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: ama...@li... = [mailto:ama...@li...] On Behalf Of Gary V Sent: Wednesday, December 28, 2005 6:51 PM To: ama...@li... 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=3Ddeferred" messages = at Dec 22 04:24:01 and this message repeated every 16 min. > not only for av...@ma... user but also for other users: > ----------------------------------------------------------------- > Dec 22 04:24:01 mail postfix/pipe[24644]: 054301BB9B: = to=3D<av...@ma...>, relay=3Dcyrus, delay=3D231660, = status=3Ddefer > red (temporary failure) > Dec 22 04:24:01 mail postfix/pipe[24641]: 49FB41F5F9: = to=3D<av...@ma...>, relay=3Dcyrus, delay=3D142821, = status=3Ddefer > red (temporary failure) > Dec 22 04:24:01 mail postfix/pipe[24644]: 9D4321F5CA: = to=3D<av...@ma...>, relay=3Dcyrus, delay=3D230213, = status=3Ddefer > 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=3D<kb...@24...>, relay=3Dnone, delay=3D202768, status=3Ddeferred = (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=3D<sta...@un...>, relay=3Dnone, delay=3D202450, = status=3Ddeferred ( > connect to linux.uovs.ac.za[196.21.181.2]: Connection timed out) > Dec 22 04:24:31 mail postfix/smtp[24639]: 8F64F1C4EE: = to=3D<kb...@24...>, relay=3Dnone, delay=3D202451, status=3Ddeferred = (connect t > o 24.on.cc[66.246.195.41]: Connection timed out) > Dec 22 04:24:31 mail postfix/smtp[24640]: E771C1B44E: = to=3D<sta...@un...>, relay=3Dnone, delay=3D202770, = status=3Ddeferred ( > 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=3D7637&alloc_id=3D16865&op=3Dclick _______________________________________________ AMaViS-user mailing list AMa...@li... https://lists.sourceforge.net/lists/listinfo/amavis-user AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3 AMaViS-HowTos:http://www.amavis.org/howto/ |