Jukka Salmi --> dkim-milter-discuss (2008-01-15 11:40:39 +0100):
[...]
> This is still with dkim-milter 2.4.0 and Postfix 2.4.5 on NetBSD/i386
> 3.1, BTW.
>
> So far the problem always happens more or less like this:
>
> - a remote MTA connects to my local MTA (mx1)
> - another remote MTA connects to mx1
> - a third remote MTA connects to mx1
> - the message from the third MTA is rejected, dkim-milter logs
> "X-DKIM" header add failed
> and the MTA logs
> can't read SMFIC_BODYEOB reply packet header:
> Undefined error: 0
> - the messages from first and second MTA are rejected, the MTA logs
> can't read SMFIC_BODYEOB reply packet header:
> Operation timed out
> - the remote systems either deliver the message to my backup MTA (mx2)
> which forwards it to mx1, or they try again some time later to mx1
> which succeeds this time
>
> A complete MTA [1]log is available (I garbled some email adresses...),
> as is a tcpdump [2]record of about the same period and some [3]notes
> listing the MTA log <--> TCP session mappings.
>
> More context of the MTA log and tcpdump session record is available
> on request. I put online what I thought is relevant, but of course I
> might have missed some things...
Yesterday I saw the problem again, but the order of events was slightly
different:
- A remote MTA (sf.net) connects to my MTA (mx1).
- The same remote MTA (sf.net) opens a second connection to mx1 and
tries to deliver a message with the same message id as in the first
(still open) connection.
- After 5 minutes (which is my Postfix milter_content_timeout setting)
both connections are rejected:
postfix/cleanup[6973]: warning: milter inet:localhost:1026:
can't read SMFIC_BODYEOB reply packet header:
Operation timed out
postfix/cleanup[6973]: CDE4C24C7D: milter-reject:
END-OF-MESSAGE from [...]: 4.7.1 Service unavailable - [...]
- Some minutes later another remote MTA (cloud9.net) connects to mx1.
The message is rejected imediately:
postfix/cleanup[14447]: warning: milter inet:localhost:1026:
can't read SMFIC_BODYEOB reply packet header: Undefined error: 0
postfix/cleanup[14447]: 39EA224C7B: milter-reject:
END-OF-MESSAGE from [...]: 4.7.1 Service unavailable - [...]
dkim-milter[9162]: 39EA224C7B "X-DKIM" header add failed
- The cloud9.net MTA connects to my backup MTA which runs exactly the
same software versions (dkim-milter, Postfix, OS) as mx1, and delivers
the message successfully.
- After this there are two deliveries of DKIM signed messages to mx1,
both of them successful.
- Now the sf.net MTA connects again twice and tries to deliver the
previously rejected messages.
- Another MTA (soekris.com) connects, but its message is immediately
rejected, as cloud9.net's message was (see above), and dkim-milter
logs its usual "X-DKIM header add failed".
- mx1 times out both connections from sf.net as before.
- Some minutes later sf.net tries again, and this time succeeds.
Two hours after Postfix times out a milter connection I see a TCP
keep-alive packet from dkim-milter to the port Postfix used, which is
answered with a TCP reset. I'm not sure how to interpret this, but I
guess dkim-milter is still waiting for input...
A slightly garbled MTA [4]log, a tcpdump [5]record and some [6]notes
are available, and all of this with more context on request.
Help is still appreciated!
TIA, Jukka
> [1] http://salmi.ch/~jukka/dkim-milter/maillog
> [2] http://salmi.ch/~jukka/dkim-milter/miltersniff.39902-40249.gz
> [3] http://salmi.ch/~jukka/dkim-milter/notes.txt
[4] http://salmi.ch/~jukka/dkim-milter/maillog1
[5] http://salmi.ch/~jukka/dkim-milter/miltersniff.1.gz
[6] http://salmi.ch/~jukka/dkim-milter/notes1.txt
--
bashian roulette:
$ ((RANDOM%6)) || rm -rf ~
-------------------------------------------------------------------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2008.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
dkim-milter-discuss mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/dkim-milter-discuss
