I'm writing a milter using pymilter-0.9.3, which interfaces to
libmilter1.0.1 (from sendmail 8.14.3) and running under postfix-2.6.5.
This is on Ubuntu jaunty (I have built the newer pymilter and postfix
versions in a PPA. The same postfix behaviour was observed with the
stock postfix 2.5.x package).
However, it seems that under some circumstances, postfix and libmilter
will fail to inter-operate in a couple of ways.
My milter doesn't care about "RCPT TO", and hence doesn't define an
envrcpt() function in the pymilter class. This leads pymilter/libmilter
to negotiate an SMFIP value of 0x4a790. I can confirm this value from
both libmilter and postfix logs. This decodes to:
Set:
SMFIP_NOBODY, SMFIP_NR_HDR, SMFIP_NOUNKNOWN, SMFIP_NODATA, SMFIP_SKIP,
SMFIP_NR_HELO, SMFIP_NR_RCPT, SMFIP_NR_EOH
Not set:
SMFIP_NOCONNECT, SMFIP_NOHELO, SMFIP_NOMAIL, SMFIP_NORCPT, SMFIP_NOHDRS,
SMFIP_NOEOH, SMFIP_RCPT_REJ, SMFIP_NR_CONN, SMFIP_NR_MAIL,
SMFIP_NR_DATA, SMFIP_NR_UNKN, SMFIP_NR_BODY, SMFIP_HDR_LEADSPC
In particular, note that SMFIP_NORCPT is NOT set, although SMFIP_NR_RCPT is.
I dumped the communication between postfix and the milter using
wireshark. Ignoring "D" commands to define macros, I see C
(SMFIC_CONNECT), H (SMFIC_HELO), M (SMFIC_MAIL), L (SMFIC_HEADER), N
(SMFIC_EOH), E (SMFIC_BODYEOB). I see the same thing from libmilter's
debug output.
The problem here is that there's no R (SMFIC_RCPT) command at all,
despite the message have non-rejected recipients on the postfix side,
and despite SMFIP_NORCPT NOT being set in the negotiated flags.
This appears to be a bug in postfix. I can't see why this is happening
from the postfix source; src/milter/milter*.c doesn't seem to have
anything that would skip sending this command. The only thing I can
think of is that the output vstream/vbuf isn't being flushed out
correctly due to SMFIP_NR_RCPT being set. Note that I do see a few lines
in the postfix log that confirm postfix is attempting to send this command:
Sep 9 23:16:11 severn postfix/smtpd[18705]: event: SMFIC_RCPT; macros:
{rcpt_addr}=swar...@wwwdotorg.org {rcpt_host}=severn
.wwwdotorg.org {rcpt_mailer}=local
Sep 9 23:16:11 severn postfix/smtpd[18705]: skipping reply for event
SMFIC_RCPT from milter inet:2092
The second of these only happens after the command (request) in question
is queued into the vstream/vbuf by postfix. It should only skip waiting
for the reply, not sending the command/request.
I wouldn't care about this, except that libmilter has some "state"
validation code, which only allows a "transition" from a given command
type to specific other command types. The transition from SMFIC_MAIL to
SMFIC_HEADER without SMFIC_RCPT in-between is deemed illegal.
Consequently, libmilter calls the abort callback. However, this doesn't
seem to do anything useful, such as send an error back to postfix, drop
the socket, etc. Instead, libmilter simply never sends anything back,
leaving postfix to time out communicating with the milter. Specifically,
the postfix logs say:
Sep 9 23:16:21 severn postfix/cleanup[18710]: warning: milter
inet:2092: can't read SMFIC_BODYEOB reply packet header: Conn
ection timed out
Sep 9 23:16:21 severn postfix/cleanup[18710]: CBC29E45B7:
milter-reject: END-OF-MESSAGE from unknown[99.99.99.1]: 4.7.1 Ser
vice unavailable - try again later; from=<swar...@wwwdotorg.org>
to=<swar...@wwwdotorg.org> proto=ESMTP helo=<esk.wwwdotorg.
org>
This seems like a bug in libmilter; the milter protocol allows
SMFIP_NORCPT to be set, which should request skipping the SMFIC_RCPT
message). However, if that is done, libmilter will reject the transition.
Does anyone have any clues what's up? It seems a little unlikely that
nobody ever written a milter that doesn't care about RCPTs. I feel I've
got to be missing something!
To work around this, I simply defined a stub envrcpt() function in my
pymilter class. This causes an SMFIP value of 0x42790 to be negotiated,
which is the same as before except SMFIP_NR_RCPT is not set. In turn,
this causes postfix to send the SMFIC_RCPT command to the milter, and
everything works OK.
Any help greatly appreciated!
