Mark Martinec --> dkim-milter-discuss (2007-12-13 21:31:50 +0100):
> Search the log for all events associated with this smtp session,
> including the logged 'connect'. Then check timestamps - perhaps
> dkim-milter took long to respond and Postfix gave up waiting
> (although it would normally say so, but perhaps unix socket behaves
> differently than inet socket in this respect, I haven't tried).

While dkim-milter responded to this particular SMTP session within a
second, I just noticed that each time this problem happens (i.e.
dkim-milter fails with `"X-DKIM" header add failed'), there are two
additional open connections from other MTAs which are not yet handled
by dkim-milter - they both time out after dkim-milter fails:

Dec 13 18:38:15 grouper postfix/smtpd[1471]: connect from 
lists-outbound.sourceforge.net[66.35.250.225]
Dec 13 18:38:15 grouper postfix/smtpd[19583]: connect from 
lists-outbound.sourceforge.net[66.35.250.225]
Dec 13 18:38:16 grouper postfix/smtpd[1471]: 12D8824C82: 
client=lists-outbound.sourceforge.net[66.35.250.225]
Dec 13 18:38:16 grouper postfix/cleanup[15386]: 12D8824C82: message-id=<[EMAIL 
PROTECTED]>
Dec 13 18:38:16 grouper postfix/smtpd[19583]: 9D3A824C84: 
client=lists-outbound.sourceforge.net[66.35.250.225]
Dec 13 18:38:17 grouper postfix/cleanup[16795]: 9D3A824C84: message-id=<[EMAIL 
PROTECTED]>
[...]
Dec 13 18:43:04 grouper postfix/smtpd[23256]: connect from 
russian-caravan.cloud9.net[168.100.1.4]
Dec 13 18:43:04 grouper postfix/smtpd[23256]: D651024C85: 
client=russian-caravan.cloud9.net[168.100.1.4]
Dec 13 18:43:05 grouper postfix/cleanup[4541]: D651024C85: message-id=<[EMAIL 
PROTECTED]>
Dec 13 18:43:05 grouper dkim-milter[4895]: D651024C85 "X-DKIM" header add failed
Dec 13 18:43:05 grouper postfix/cleanup[4541]: warning: milter 
unix:/sockets/dkfilter/dkimvrfy: can't read SMFIC_BODYEOB reply packet header: 
Undefined error: 0
Dec 13 18:43:05 grouper postfix/cleanup[4541]: D651024C85: milter-reject: 
END-OF-MESSAGE from russian-caravan.cloud9.net[168.100.1.4]: 4.7.1 Service 
unavailable - try again later; [...]
Dec 13 18:43:05 grouper postfix/smtpd[23256]: disconnect from 
russian-caravan.cloud9.net[168.100.1.4]
[...]
Dec 13 18:43:16 grouper postfix/cleanup[15386]: warning: milter 
unix:/sockets/dkfilter/dkimvrfy: can't read SMFIC_BODYEOB reply packet header: 
Operation timed out
Dec 13 18:43:16 grouper postfix/cleanup[15386]: 12D8824C82: milter-reject: 
END-OF-MESSAGE from lists-outbound.sourceforge.net[66.35.250.225]: 4.7.1 
Service unavailable - try again later; [...]
Dec 13 18:43:16 grouper postfix/smtpd[1471]: disconnect from 
lists-outbound.sourceforge.net[66.35.250.225]
Dec 13 18:43:17 grouper postfix/cleanup[16795]: warning: milter 
unix:/sockets/dkfilter/dkimvrfy: can't read SMFIC_BODYEOB reply packet header: 
Operation timed out
Dec 13 18:43:17 grouper postfix/cleanup[16795]: 9D3A824C84: milter-reject: 
END-OF-MESSAGE from lists-outbound.sourceforge.net[66.35.250.225]: 4.7.1 
Service unavailable - try again later; [...]
Dec 13 18:43:17 grouper postfix/smtpd[19583]: disconnect from 
lists-outbound.sourceforge.net[66.35.250.225]

However, as Tony wrote, this probably belongs to the Postfix ML...


> If you manage to reproduce the problem, capturing a milter session
> with tcpdump (full size packets, binary) could be of help.

I'm using unix domain sockets - AFAIK it's not possible to capture a
session in this case, is it?


Regards, Jukka

-- 
bashian roulette:
$ ((RANDOM%6)) || rm -rf ~

-------------------------------------------------------------------------
SF.Net email is sponsored by:
Check out the new SourceForge.net Marketplace.
It's the best place to buy or sell services
for just about anything Open Source.
http://ad.doubleclick.net/clk;164216239;13503038;w?http://sf.net/marketplace
_______________________________________________
dkim-milter-discuss mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/dkim-milter-discuss

Reply via email to