>
 > After 1 minutes of processing mail my amavis stops accepting connections
 > nanny reports this
 >
 > PID 08733: A             0:02:08 =========:=========:=========:=====>
 > PID 19839: 19839-10      0:03:46 =========:=========:=========:=====>
 > PID 27980: A             0:03:29 =========:=========:=========:=====>
 > PID 27991: 27991-06      0:03:38 =========:=========:=========:=====>
 > PID 28006: 28006-02      0:04:13 =========:=========:=========:=====>
 >
 >
 > after some timeout one process restarts
 >
 > PID 08733: 08733-08      0:00:06 ======
 > PID 09957: A             0:04:01 =========:=========:=========:=====>
 > PID 10240: A             0:03:33 =========:=========:=========:=====>
 > PID 11276: A             0:01:14 =========:=========:=========:=====>
 > PID 27991: A             0:04:11 =========:=========:=========:=====>
 >
 >
 > I have set log level 5, and i can not see any warning or error
 >
 > this server worked without any error for a year now
 >
 > a tried with amavisd-2.3.3 - perl 5.8.0
 > and 2.4.2 perl 5.8.8
 >
 > postfix 2.0.16 rhel 3
 >
 > thanks
 > friiz

Hi!


after running amavisd debug it stops while trying to send mail to 
postfix smtpd

Jan 18 16:57:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) response to RCPT TO for <[EMAIL PROTECTED]>: "250

Ok"
Jan 18 16:57:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) prolong_timer after fwd-rcpt-to: remaining time =

480 s
Jan 18 16:57:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) response to DATA: "354 End data with

<CR><LF>.<CR><LF>"
Jan 18 16:57:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) write_header: 0, Amavis::Out=HASH(0xa5131c8)
Jan 18 16:57:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) prolong_timer after fwd-data: remaining time =

480 s


mail flow breaks here and waits until a timeout


Jan 18 17:02:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) prolong_timer after fwd-data-end: remaining time

= 181 s
Jan 18 17:02:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) response to data end: "421 Error: timeout

exceeded"
Jan 18 17:02:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) prolong_timer after fwd-rundown-1: remaining time

= 181 s
Jan 18 17:02:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) WARN: sending SMTP QUIT command failed: 000
Jan 18 17:02:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) FWD via SMTP: <[EMAIL PROTECTED]> ->

<[EMAIL PROTECTED]>, 421 4.6.0 Failed, id=19175-01, from 
MTA([127.0.0.1]:10025): 421 Error: timeout exceeded
Use of uninitialized value in string ne at /usr/local/sbin/amavisd line 
7586, <GEN7> line 626.
Jan 18 17:02:33 fqdn.host.name /usr/local/sbin/amavisd[19175]: 
(19175-01) prolong_timer after forwarding: remaining time =

181 s




from the postfix logs

Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type M len 0 data
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 55 data 
Received:
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 56 data 
?by linux.
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 62 data 
?for <frii
Jan 18 16:57:33 linux postfix/smtpd[19310]: > fqdn.host.name[127.0.0.1]: 
354 End data with <CR><LF>.<CR><LF>
Jan 18 16:57:33 linux postfix/smtpd[19310]: vstream_fflush_some: fd 14 
flush 380
Jan 18 16:57:33 linux postfix/smtpd[19310]: vstream_fflush_some: fd 13 
flush 37
Jan 18 16:57:33 linux postfix/smtpd[19310]: vstream_buf_get_ready: fd 13 
got 905
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 45 data 
Received:
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 70 data 
  by localh
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 47 data 
  with ESMT
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 38 data 
  Thu, 18 J
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 50 data 
Received:
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 56 data 
?by linux.
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 62 data 
?for <frii
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 41 data 
Message-ID
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 37 data 
Date: Thu,
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 30 data 
From: frii
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 50 data 
User-Agent
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 17 data 
MIME-Versi
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 20 data 
To: friiz@
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 24 data 
Subject: [
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 30 data 
Content-Ty
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 48 data 
  boundary=
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 42 data 
X-Virus-Sc
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 58 data 
X-Spam-Sta
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 59 data 
  tests=[AL
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 19 data 
X-Spam-Sco
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 18 data 
X-Spam-Lev
Jan 18 16:57:33 linux postfix/smtpd[19310]: rec_put: type N len 0 data


and there is no other sign of smtpd[19310] until timeout

doing an strace -p 19310 here
show a select(....) function call


Jan 18 17:02:33 linux postfix/smtpd[19310]: > fqdn.host.name[127.0.0.1]: 
421 Error: timeout exceeded
Jan 18 17:02:33 linux postfix/smtpd[19310]: vstream_fflush_some: fd 13 
flush 29
Jan 18 17:02:33 linux postfix/smtpd[19310]: timeout after DATA from 
fqdn.host.name[127.0.0.1]
Jan 18 17:02:33 linux postfix/smtpd[19310]: vstream_fflush_some: fd 13 
flush 0
Jan 18 17:02:33 linux postfix/smtpd[19310]: vstream_fflush_some: fd 14 
flush 905
Jan 18 17:02:33 linux postfix/smtpd[19310]: disconnect from 
fqdn.host.name[127.0.0.1]
Jan 18 17:02:33 linux postfix/smtpd[19310]: vstream_fflush_some: fd 13 
flush 0
Jan 18 17:02:33 linux postfix/smtpd[19310]: master_notify: status 1
Jan 18 17:02:33 linux postfix/smtpd[19310]: connection closed
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_request_timer: set 
0x8055b40 0x0 100
Jan 18 17:02:33 linux postfix/smtpd[19310]: watchdog_stop: 0x9045350
Jan 18 17:02:33 linux postfix/smtpd[19310]: watchdog_start: 0x9045350
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_loop: select_delay 0
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_loop: timer 0x8060c40 
0x9046548
Jan 18 17:02:33 linux postfix/smtpd[19310]: rewrite stream disconnect
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_disable_readwrite: fd 15
Jan 18 17:02:33 linux postfix/cleanup[18967]: 3778637C3C5: 
message-id=<[EMAIL PROTECTED]>
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_cancel_timer: 
0x8060c40 0x9046548 -1
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_loop: timer 0x8060c40 
0x8ff3f00
Jan 18 17:02:33 linux postfix/smtpd[19310]: proxymap stream disconnect
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_disable_readwrite: fd 9
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_cancel_timer: 
0x8060c40 0x8ff3f00 -1
Jan 18 17:02:33 linux postfix/smtpd[19310]: watchdog_stop: 0x9045350
Jan 18 17:02:33 linux postfix/smtpd[19310]: watchdog_start: 0x9045350
Jan 18 17:02:33 linux postfix/smtpd[19310]: event_loop: select_delay 100

anybody?


thanks
friiz


-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your
opinions on IT & business topics through brief surveys - and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
AMaViS-user mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/amavis-user
AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3
AMaViS-HowTos:http://www.amavis.org/howto/

Reply via email to