David B?rgin:
> Me:
> > I?m running a milter that may perform rejection (SMFIS_REJECT) at the
> > milter HELO stage. This condition appears in the system log as follows:
> >
> > Jan 04 13:50:07 mail postfix/smtpd[149922]: connect from
> > unknown[156.0.64.217]
> > Jan 04 13:50:07 mail spf-milter[147333]: mail.mydomain.org (helo): fail
> > Jan 04 13:50:07 mail spf-milter[147333]: rejected message from sender
> > "mail.mydomain.org"
> > Jan 04 13:50:07 mail postfix/smtpd[149922]: NOQUEUE: milter-reject: HELO
> > from unknown[156.0.64.217]: 550 5.7.23 SPF validation failed; proto=SMTP
> > helo=<mail.mydomain.org>
> > Jan 04 13:50:07 mail postfix/smtpd[149922]: NOQUEUE: milter-reject: MAIL
> > from unknown[156.0.64.217]: 550 5.7.23 SPF validation failed; from=<>
> > proto=SMTP helo=<mail.mydomain.org>
> > Jan 04 13:50:08 mail postfix/smtpd[149922]: lost connection after MAIL from
> > unknown[156.0.64.217]
> > Jan 04 13:50:08 mail postfix/smtpd[149922]: disconnect from
> > unknown[156.0.64.217] helo=1 mail=0/1 commands=1/2
> >
> > ? Why does Postfix log ?milter-reject? twice?
> > ? Why does it also log milter rejection for the MAIL stage, when the
> > client was rejected already at the HELO stage?
>
> Perhaps it?s related to this?
> http://www.postfix.org/SMTPD_ACCESS_README.html#timing
Nope.
As documented Milters are not affected by smtpd_delay_reject settings.
As documented smtpd_delay_reject affects smtpd_mumble_restrictions.
In the logging:
milter-reject: HELO from unknown[156.0.64.217]: 550 5.7.23 SPF
validation failed
That is the response to the HELO command, as in
client: HELO mail.mydomain.org
server: 550 5.7.23 SPF validation failed
And a little later:
client: MAIL FROM:<>
server: 550 5.7.23 SPF validation failed
Wietse.