-- Am 03/20/16 19:54:35 +0100 schrieb Heiko Schlittermann:
Hi,
Michael Fischer v. Mollard <[email protected]> (Sa 19 Mär 2016
19:41:39 CET):
Hello,
I've a strange problem with the connection timeout on an Exim 4.86:
[…]
Ignoring that the strange behavior of the receiving side (I explicitly
killed the client, so it closed the connection as seen in the logs) I'd
expect that the sending exim quit the connection after final_timeout
(not explicitly given, so it should be 10 minutes). Is there an
explanation why the sending exim is not closing the connection? Could
this be a regression as I've never seen that before?
I do not see any indication that some process is exceeding it's timeout.
The only thing I see is, that a process (probably the queue runner)
can't lock the spool file, because it's locked already. The last log
line shows a forceful closed connection, but we've no idea if this is
the same process as started just after the messages came in.
You may add the +pid log_selector to get an idea about the processes
(not) handling a message.
Hello,
another example:
# exiwhat
[…]
29077 delivering 1ai1bZ-0007Yw-Qf: waiting for a remote delivery subprocess
to finish
29079 delivering 1ai1bZ-0007Yw-Qf to XXX [XXX] (XXX)
# kill 29079
# exigrep 1ai1bZ-0007Yw-Qf /var/log/exim4/mainlog
2016-03-21 16:18:54 [29074] 1ai1bZ-0007Yw-Qf <= XXX H=XXX [XXX] P=smtp
S=17032 id=XXX
2016-03-21 16:26:04 [30608] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 16:51:49 [3046] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 16:54:17 [3424] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 17:03:11 [4875] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 17:08:48 [5951] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 17:21:35 [9861] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 17:26:05 [11602] 1ai1bZ-0007Yw-Qf Spool file is locked (another
process is handling this message)
2016-03-21 17:33:49 [29077] 1ai1bZ-0007Yw-Qf == XXX R=dnslookup
T=T_local_smtp defer (-1): smtp transport process returned non-zero status
0x000f: terminated by signal 15
2016-03-21 17:37:13 [16247] 1ai1bZ-0007Yw-Qf => XXX R=dnslookup
T=T_local_smtp S=17197 H=XXX X=TLS1.2… CV=no C="250 OK
id=1ai2pL-0001mF-Hs" QT=1h18m20s DT=2s
2016-03-21 17:37:13 [16247] 1ai1bZ-0007Yw-Qf Completed
So if I'm not getting something terribly wrong the delevering process 29079
which is started by the receiving process 29074 exist for about seventyfive
minutes until I killed it manually. After that a queue runner picked it up
and delivered it smoothly. What I'd expect (and strangely enough find in
the same logfile) would be something like:
2016-03-21 12:06:01 [6616] 1ahxer-0001ii-CZ <= XXX H=XXX P=esmtps X=TLS1.0
CV=no S=6481 id=XXX
2016-03-21 12:16:02 [6639] 1ahxer-0001ii-CZ SMTP timeout after end of data
(6636 bytes written): Connection timed out
2016-03-21 12:16:03 [6624] 1ahxer-0001ii-CZ => XXX R=dnslookup
T=T_local_smtp S=6636 H=XXX
2016-03-21 12:16:03 [6624] 1ahxer-0001ii-CZ Completed
Regards
Michael
--
## List details at https://lists.exim.org/mailman/listinfo/exim-users
## Exim details at http://www.exim.org/
## Please use the Wiki with this list - http://wiki.exim.org/
