On 5/7/2010 3:59 AM, d h wrote: > > > >> If you want to turn off amavisd-new (hopefully temporarily), >> comment out any content_filter statements in the postfix main.cf. >> >> You haven't yet shown us any evidence that anything is broken. > > I disabled Amavis more than a full workday, every e-mail had been > > delivered without any problem. I enabled Amavis again this morning > > and after 2 hours, the problem popped up again. So Amavis has to > > be causing the problem, but I don't know why though. > > > >> This shows postfix passing the mail to amavisd-new after a ~35 >> minute wait in the queue. Other than the long delay before >> the mail gets to amavisd-new, this looks fairly normal. >> >> Track down the amavisd-new ID 19799-01-2 to see what it did >> with the message. > > > The long delay is caused by the command line virus scanner, Mcafee > > is taking a long time. I want to replace this by ClamAV, but I have > > to solve this problem first. > > > > This is the result if I track down the amavis-new ID: > > > > May 4 18:09:50 amavis[54714]: (54714-08-2) LMTP::10024 > /var/amavis/tmp/amavis-20100504T161946-54714:<exter...@mailaddress.com> -> > <inter...@mailaddress.com> SIZE=167658 Received: from frontdoor > ([127.0.0.1]) by localhost ( . [127.0.0.1]) (amavisd-new, port 10024) with > LMTP for<inter...@mailaddress.com>; Tue, 4 May 2010 18:09:50 +0200 (CEST) > May 4 18:09:50 amavis[54714]: (54714-08-2) smtp connection cache, dt: 0.0, > state: 0 > May 4 18:09:50 amavis[54714]: (54714-08-2) smtp connection cache, dt: 0.0 > -> enabling > May 4 18:09:50 amavis[54714]: (54714-08-2) Checking: Hc2ZWpPHDZsL INTERNET > [188.66.17.8]<exter...@mailaddress.com> -> <inter...@mailaddress.com> > May 4 18:09:51 amavis[54714]: (54714-08-2) p013 1 Content-Type: > multipart/related > May 4 18:09:51 amavis[54714]: (54714-08-2) p014 1/1 Content-Type: > multipart/alternative > May 4 18:09:51 amavis[54714]: (54714-08-2) p001 1/1/1 Content-Type: > text/plain, size: 64 B, name: > May 4 18:09:51 amavis[54714]: (54714-08-2) p002 1/1/2 Content-Type: > text/html, size: 28160 B, name: > May 4 18:09:51 amavis[54714]: (54714-08-2) p003 1/2 Content-Type: > image/gif, size: 807 B, name: 00.gif > May 4 18:09:51 amavis[54714]: (54714-08-2) p004 1/3 Content-Type: > image/gif, size: 2351 B, name: 01.gif > May 4 18:09:51 amavis[54714]: (54714-08-2) p005 1/4 Content-Type: > image/jpeg, size: 69062 B, name: 02.jpg > May 4 18:09:51 amavis[54714]: (54714-08-2) p006 1/5 Content-Type: > image/jpeg, size: 3393 B, name: 03.jpg > May 4 18:09:51 amavis[54714]: (54714-08-2) p007 1/6 Content-Type: > image/gif, size: 596 B, name: 04.gif > May 4 18:09:51 amavis[54714]: (54714-08-2) p008 1/7 Content-Type: > image/jpeg, size: 2558 B, name: 05.jpg > May 4 18:09:51 amavis[54714]: (54714-08-2) p009 1/8 Content-Type: > image/jpeg, size: 3174 B, name: 06.jpg > May 4 18:09:51 amavis[54714]: (54714-08-2) p010 1/9 Content-Type: > image/jpeg, size: 3395 B, name: 07.jpg > May 4 18:09:51 amavis[54714]: (54714-08-2) p011 1/10 Content-Type: > image/jpeg, size: 3074 B, name: 08.jpg > May 4 18:09:51 amavis[54714]: (54714-08-2) p012 1/11 Content-Type: > image/jpeg, size: 3233 B, name: 09.jpg > May 4 18:11:14 amavis[54714]: (54714-08-2) smtp resp to NOOP (idle 113.5 > s): 220 you.got.mail ESMTP Postfix > May 4 18:11:14 amavis[54714]: (54714-08-2) Negative SMTP resp. to DATA: > 250 2.1.5 Ok > May 4 18:11:14 amavis[54714]: (54714-08-2) FWD via > SMTP:<exter...@mailaddress.com> -> <inter...@mailaddress.com>, 250 2.1.0 > Ok, id=54714-08-2, from MTA([127.0.0.1]:10025): 250 2.1.0 Ok > May 4 18:11:14 amavis[54714]: (54714-08-2) Passed CLEAN, INTERNET > [188.66.17.8] [188.66.17.8]<exter...@mailaddress.com> -> > <inter...@mailaddress.com>, Message-ID:<52ae9470d960ee100ea35a43d169891e@ > mailAddress.com>, mail_id: Hc2ZWpPHDZsL, Hits: 1.847, size: 167658, > queued_as: 250 2.1.0 Ok, 83493 ms > May 4 18:11:14 postfix/lmtp[55852]: BF7A54AE4A: > to=<inter...@mailaddress.com>, relay=127.0.0.1[127.0.0.1]:10024, conn_use=2, > delay=241, delays=3.3/154/0/83, dsn=2.1.0, status=sent (250 2.1.0 Ok, > id=54714-08-2, from MTA([127.0.0.1]:10025): 250 2.1.0 Ok) > May 4 18:11:14 amavis[54714]: (54714-08-2) TIMING [total 83503 ms] - SMTP > pre-DATA-flush: 4 (0%)0, SMTP DATA: 144 (0%)0, check_init: 2 (0%)0, > digest_hdr: 1 (0%)0, digest_body_dkim: 3 (0%)0, gen_mail_id: 3 (0%)0, > mime_decode: 64 (0%)0, get-file-type12: 121 (0%)0, decompose_part: 3 (0%)0, > parts_decode: 1 (0%)0, check_header: 3 (0%)0, AV-scan-1: 79713 (95%)96, > spam-wb-list: 12 (0%)96, SA parse: 29 (0%)96, SA check: 3328 (4%)100, > update_cache: 8 (0%)100, decide_mail_destiny: 2 (0%)100, fwd-connect: 9 > (0%)100, fwd-mail-from: 3 (0%)100, fwd-rcpt-to: 31 (0%)100, fwd-data-cmd: 1 > (0%)100, fwd-end-chkpnt: 1 (0%)100, prepare-dsn: 1 (0%)100, main_log_entry: 8 > (0%)100, update_snmp: 3 (0%)100, SMTP pre-response: 1 (0%)100, SMTP response: > 2 (0%)100, unlink-12-files: 2 (0%)100, rundown: 1 (0%)100 > May 4 18:28:27 amavis[54714]: (54714-08-2) loaded policy bank "INTERNET" > > Every failed delivery has got a log entry "Negative SMTP resp. > to DATA: 250 2.1.5 Ok" I tried to google what it means, but > could not find anything useful.
That looks as if the SMTP conversation has gotten out of sync. While that /shouldn't/ lead to data loss, I guess it's possible. Maybe disabling connection caching in both amavisd-new and postfix will help? I would suggest upgrading your amavisd-new and your postfix to the latest versions, and then examine the configuration carefully to make sure it isn't borked somewhere. -- Noel Jones ------------------------------------------------------------------------------ _______________________________________________ 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/
