From: Thomas E. <Tho...@th...> - 2014-07-09 09:21:51
|
enable 'ConTimeOutDebug' assp will write the connection states in to files in the debug folder. Thomas Von: Colin <col...@gm...> An: Ass...@li... Datum: 08.07.2014 17:04 Betreff: Re: [Assp-test] Timeout issues Apologies for replying to self, turns out the log lines are out of sync by a second so my greps weren't showing it up. The MTA is indeeed showing "SMTP data timeout (message abandoned) on connection from" so I'll change my report. The connection is being opened to the MTA but it looks like ASSP is not passing the message to the MTA after scanning it and getting "message ok". The result is then either the MTA or ASSP timing out, I think the timeouts are set to the same so either one could kick in first - that explains difference between the last two logs. On 08/07/2014 15:50, Colin wrote: > Hi Folks, > > I've given up on the list accepting messages from my main account. SF > didn't respond to my request for help either. > > I have had an ongoing issue for a good few weeks now where its seems > like ASSP accepts a message but does not pass it on to the MTA. It > talks to the remote host and goes through the motions. There is no > evidence at all in the MTA logs that ASSP has even opened a connection > to it for the message concerned. When I originally spotted the > problem, ASSP didn't output anything for the message past "message ok". > > One of the recent revisions changed that and now ASSP reports a > timeout, but I have seen it reported in two different ways - logs below. > > Example 1 - no timeout reported by ASSP > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> info: found > message size announcement: 13.54 kByte > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> [SMTP Reply] 250 OK > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [SMTP Reply] 250 > Accepted > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [SMTP Reply] 354 > Enter message, ending with "." on a line by itself > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> info: found known > good HELO 'mout1.freenet.de' - weight is -2 > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> Message-Score: > added -40 for KnownGoodHelo, total score for this message is now -40 > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> Message-Score: > added -15 (pbwValencePB) for In Penalty White Box, total score for > this message is now -55 > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> Message-Score: > added -5 for 195.4.92 in griplist (0.00), total score for this message > is now -60 > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [scoring] SPF: none > ip=1.1.1.1 mailfrom=se...@do...d > <mailto:mailfrom=se...@do...d> helo=mout1.freenet.de > > 2014-06-25 11:14:28 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> Whitelisted sender > address: se...@do...d <mailto:se...@do...d> for recipient > rec...@do...d <mailto:rec...@do...d> > > 2014-06-25 11:14:29 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [Plugin] calling > plugin ASSP_AFC > > 2014-06-25 11:14:29 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> whitelisted (no bad > attachments) > > 2014-06-25 11:14:29 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [Plugin] calling > plugin ASSP_DCC > > 2014-06-25 11:14:29 m1-91268-01851 [Worker_5] [TLS-in] [TLS-out] > [MessageOK] 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> message ok [Fwd Re > Test] > > > Example 2 - ASSP reported its own timeout > > 2014-06-30 17:42:49 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> [SMTP Reply] 250 OK > > 2014-06-30 17:42:50 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [SMTP Reply] 250 > Accepted > > 2014-06-30 17:42:50 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [SMTP Reply] 354 > Enter message, ending with "." on a line by itself > > 2014-06-30 17:42:50 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> Whitelisted sender > address: se...@do...d <mailto:se...@do...d> for recipient > rec...@do...d <mailto:rec...@do...d> > > 2014-06-30 17:42:50 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [Plugin] calling > plugin ASSP_AFC > > 2014-06-30 17:42:50 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> whitelisted (no bad > attachments) > > 2014-06-30 17:42:50 m1-46569-09929 [Worker_4] [TLS-out] [MessageOK] > 1.1.1.1 <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> message ok [SUBJECT] > > 2014-06-30 18:03:04 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> Connection idle for > 360 secs - timeout > > 2014-06-30 18:03:04 m1-46569-09929 [Worker_4] [TLS-out] 1.1.1.1 > <se...@do...d <mailto:se...@do...d>> to: > rec...@do...d <mailto:rec...@do...d> [SMTP Status] 451 > Connection timeout, try later > > > Example 3 - ASSP claims the MTA reports a timeout yet there is not a > single log from the MTA indicating this. > > 2014-07-08 13:30:31 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> info: found message size announcement: > 5.53 kByte > > 2014-07-08 13:30:33 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> [SMTP Reply] 250 OK > > 2014-07-08 13:30:35 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d [SMTP Reply] 250 > Accepted > > 2014-07-08 13:30:39 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d [SMTP Reply] 354 > Enter message, ending with "." on a line by itself > > 2014-07-08 13:30:40 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d Whitelisted > sender address: se...@do...d for recipient rec...@do...d > > 2014-07-08 13:30:40 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > [Noprocessing] 1.1.1.1 <se...@do...d> to: rec...@do...d > info: found valid MSGID signature in [References:] - accept mail > > 2014-07-08 13:30:40 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d DKIM-Signature found > > 2014-07-08 13:30:42 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d info: removed > MSGID-signature from [References:] > > 2014-07-08 13:30:42 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d info: removed > MSGID-signature from [In-Reply-To:] > > 2014-07-08 13:30:42 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d info: removed > MSGID-signature from header > > 2014-07-08 13:30:42 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d [Plugin] calling > plugin ASSP_AFC > > 2014-07-08 13:30:42 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d message proxied > without processing (no bad attachments) > > 2014-07-08 13:30:42 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > [MessageOK] 1.1.1.1 <se...@do...d> to: rec...@do...d > message ok - (noprocessing and whitelisted - found valid Message-ID > signature) - [URGENT NEW BOOKING] > > 2014-07-08 13:37:24 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > [MessageOK] 1.1.1.1 <se...@do...d> to: rec...@do...d info: > got reply '421 mail.smtphost.co.uk SMTP incoming data timeout - > closing connection.' - message is rejeted by the server host 127.0.0.1 > > 2014-07-08 13:37:24 m1-22631-13843 [Worker_7] [TLS-in] [TLS-out] > 1.1.1.1 <se...@do...d> to: rec...@do...d [SMTP Status] 421 > mail.smtphost.co.uk SMTP incoming data timeout - closing connection. > > 2014-07-08 13:37:27 [Worker_7] Disconnected: session:7FD282862A58 > 1.1.1.1 - processing time 421 seconds > > > ------------------------------------------------------------------------------ Open source business process management suite built on Java and Eclipse Turn processes into business applications with Bonita BPM Community Edition Quickly connect people, data, and systems into organized workflows Winner of BOSSIE, CODIE, OW2 and Gartner awards http://p.sf.net/sfu/Bonitasoft _______________________________________________ Assp-test mailing list Ass...@li... https://lists.sourceforge.net/lists/listinfo/assp-test DISCLAIMER: ******************************************************* This email and any files transmitted with it may be confidential, legally privileged and protected in law and are intended solely for the use of the individual to whom it is addressed. This email was multiple times scanned for viruses. There should be no known virus in this email! ******************************************************* |