What is Postfix telling me?

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

What is Postfix telling me?

James B. Byrne
Starting shortly after midnight 20180906 our maillog file began to
record this sort of message pair every six minutes or so.

Sep  6 12:36:42 mx31 postgrey[85107]: action=pass, reason=client AWL,
client_name=malton22-1176258451.sdsl.bell.ca,
client_address=70.28.71.147, sender=[hidden email],
recipient=[hidden email]

Sep  6 12:36:48 mx31 postfix-p25/smtpd[66636]: proxy-reject:
END-OF-MESSAGE: 451 4.5.0 Error in processing, id=29937-07, quar+notif
FAILED: mail_dispatch: no recognized protocol name: -2 at
/usr/local/sbin/amavisd line 9638.; from=<[hidden email]>
to=<[hidden email]> proto=ESMTP helo=<airportcargo.ca>

We are not getting the error message for any other domain and we do
not get it for every message from airportcargo.ca.  For example:

Sep  6 15:06:21 mx31 postgrey[85107]: action=pass, reason=client AWL,
client_name=toroondcmxzomta01.bellnexxia.net,
client_address=67.69.168.80, sender=[hidden email],
recipient=[hidden email]

Sep  6 15:06:21 mx31 policyd-spf[68870]: prepend X-Comment: SPF
skipped for whitelisted relay domain - client-ip=67.69.168.80;
helo=toroondcmxzomta01-srv.bellnexxia.net;
envelope-from=[hidden email]; receiver=<UNKNOWN>

Sep  6 15:06:22 mx31 postfix/qmgr[79845]: E64931EBF7:
from=<[hidden email]>, size=3786, nrcpt=1 (queue active)
Sep  6 15:06:22 mx31 postfix-p25/smtpd[64693]: proxy-accept:
END-OF-MESSAGE: 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0
Ok: queued as E64931EBF7; from=<[hidden email]>
to=<[hidden email]> proto=ESMTP
helo=<toroondcmxzomta01-srv.bellnexxia.net>


Since SPF appears to figure in the successful receipt I checked the
DNS RR:

drill airportcargo.ca txt

;; ANSWER SECTION:
airportcargo.ca. 11072 IN TXT
"v=spf1 a mx include:mail.airportcargo.ca include:airportcargo.ca
include:home.zetwork.ca ~all"

drill airportcargo.ca mx

;; ANSWER SECTION:
airportcargo.ca. 4552 IN MX 30 lastmx.spamexperts.net.
airportcargo.ca. 4552 IN MX 20 fallbackmx.spamexperts.eu.
airportcargo.ca. 4552 IN MX 10 mx.spamexperts.com.

But this only tells me that any SPF failure for airportcargo.ca
messages should be treated as a softfail.  Our policyd-spf.conf has
these options set:

HELO_reject = Fail - Reject on HELO Fail
Mail_From_reject = Fail
Domain_Whitelist = bellnexxia.net,lcbo.com

Which, to me, indicates that mail arriving via bellnexxia.net is not
checked for SPF compliance or at least messages delivered by that
route do not fail regardless of the SPF settings for the sender's
domain.

If someone could clue me in as to what is happening then I would be
most grateful.

--
***          e-Mail is NOT a SECURE channel          ***
        Do NOT transmit sensitive data via e-Mail
 Do NOT open attachments nor follow links sent by e-Mail

James B. Byrne                mailto:[hidden email]
Harte & Lyne Limited          http://www.harte-lyne.ca
9 Brockley Drive              vox: +1 905 561 1241
Hamilton, Ontario             fax: +1 905 561 0757
Canada  L8E 3C3

Reply | Threaded
Open this post in threaded view
|

Re: What is Postfix telling me?

Bastian Blank-3
On Thu, Sep 06, 2018 at 05:04:43PM -0400, James B. Byrne wrote:
> Sep  6 12:36:42 mx31 postgrey[85107]: action=pass, reason=client AWL,
> client_name=malton22-1176258451.sdsl.bell.ca,
> client_address=70.28.71.147, sender=[hidden email],
> recipient=[hidden email]

This is from postgrey, which is not postfix.  Disable it if you don't
understand what is does.

> Sep  6 12:36:48 mx31 postfix-p25/smtpd[66636]: proxy-reject:
> END-OF-MESSAGE: 451 4.5.0 Error in processing, id=29937-07, quar+notif
> FAILED: mail_dispatch: no recognized protocol name: -2 at
> /usr/local/sbin/amavisd line 9638.; from=<[hidden email]>
> to=<[hidden email]> proto=ESMTP helo=<airportcargo.ca>

This is a postfix log message, but providing the output of an amavis.
You missconfigured it, search for -2.  Disable if you don't understand
what it does.

> If someone could clue me in as to what is happening then I would be
> most grateful.

Check your complete log.  Read
http://www.postfix.org/DEBUG_README.html#mail

Regards,
Bastian

--
It is more rational to sacrifice one life than six.
                -- Spock, "The Galileo Seven", stardate 2822.3