On Mon, 21 Mar 2016, Michael Fischer v. Mollard wrote:
-- 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.
Hmm. I read that differently. My take (perhaps wrong)
is that 29079 was started by 29077 (since ...7 died when you kill ...9).
Once pids wrap it is hard to guess correctly ...
Some clever use of ps (perhaps ps -f) *before killing anything*
might give more clue.
Is there any other sign of (this) process 29074 in the log ?
It wasn't in the exiwhat output, so I'd guess it had finished.
Next time it happens, can you use fuser to see which process
is holding the lock/locked file ?
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/
--
## 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/
