dear postfix users,
i'm running postfix version 3.2.0 with postscreen, amavis-new, spamassassin.
recently I added postfwd 1.39 as a check policy service.
implementation in main.cf see below at the end of the mail
if you need the output of postconf or master.cf then please let me know ...
I added the call to postfwd in the 'end of data' restrictions as I
wanted to implement a per user rate limit on the recipients and needed
access to the recipients_count value
anyway I was thinking that every incoming message postfix receives will
get send to postfwd for further inspections?
If I look at the logs I see an incoming message but postfix doesn't make
a call to postfwd
Feb 28 09:43:24 cx20 postfix/smtpd[21629]: connect from
66-220-155-139.mail-mail.facebook.com[66.220.155.139]
Feb 28 09:43:26 cx20 postfix/smtpd[21629]: 12CBD1A2103:
client=66-220-155-139.mail-mail.facebook.com[66.220.155.139]
Feb 28 09:43:26 cx20 postfix/cleanup[21634]: 12CBD1A2103:
message-id=<e544362c3b3411e9a3e9000af7a31f7a-56a3d580@16860d3ba1b877551b445f11478159af827fd52ba8d9c2d502552d56df823a7f>
Feb 28 09:43:26 cx20 postfix/qmgr[20440]: 12CBD1A2103:
from=<notificat...@facebookmail.com>, size=30387, nrcpt=1 (queue active)
Feb 28 09:43:27 cx20 postfix/smtpd[21637]: connect from
localhost.beckspaced.com[127.0.0.1]
Feb 28 09:43:27 cx20 postfix/smtpd[21637]: B8C4E1A212C:
client=localhost.beckspaced.com[127.0.0.1]
Feb 28 09:43:27 cx20 postfix/cleanup[21634]: B8C4E1A212C:
message-id=<e544362c3b3411e9a3e9000af7a31f7a-56a3d580@16860d3ba1b877551b445f11478159af827fd52ba8d9c2d502552d56df823a7f>
Feb 28 09:43:27 cx20 postfix/qmgr[20440]: B8C4E1A212C:
from=<notificat...@facebookmail.com>, size=30922, nrcpt=1 (queue active)
Feb 28 09:43:27 cx20 postfix/smtpd[21637]: disconnect from
localhost.beckspaced.com[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1
commands=5
Feb 28 09:43:27 cx20 amavis[21448]: (21448-08) Passed CLEAN
{RelayedInbound}, EXTERNAL [66.220.155.139]:36612 [66.220.155.139]
<notificat...@facebookmail.com> -> <he...@haadyaodivers.com>, Queue-ID:
12CBD1A2103, Message-ID:
<e544362c3b3411e9a3e9000af7a31f7a-56a3d580@16860d3ba1b877551b445f11478159af8
Feb 28 09:43:27 cx20 postfix/smtp[21635]: 12CBD1A2103:
to=<he...@haadyaodivers.com>, relay=127.0.0.1[127.0.0.1]:10024,
delay=1.9, delays=0.62/0/0/1.2, dsn=2.0.0, status=sent (250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as B8C4E1A212C)
Feb 28 09:43:27 cx20 postfix/qmgr[20440]: 12CBD1A2103: removed
Feb 28 09:43:28 cx20 postfix/lmtp[21639]: B8C4E1A212C:
to=<he...@haadyaodivers.com>, relay=localhost[127.0.0.1]:24, delay=0.42,
delays=0.01/0/0/0.41, dsn=2.0.0, status=sent (215 Recipient
<he...@haadyaodivers.com> OK)
Feb 28 09:43:28 cx20 postfix/qmgr[20440]: B8C4E1A212C: removed
here's another incoming email from a sasl auth client sending an email
without a call to postfwd?
Feb 28 09:18:43 cx20 postfix/submission/smtpd[20459]: connect from
p2E55E28D.dip0.t-ipconnect.de[46.85.226.141]
Feb 28 09:18:43 cx20 postfix/submission/smtpd[20459]: 7A2241A1D5C:
client=p2E55E28D.dip0.t-ipconnect.de[46.85.226.141], sasl_method=LOGIN,
sasl_username=a.te...@temizbau.de
Feb 28 09:18:43 cx20 postfix/cleanup[21012]: 7A2241A1D5C:
message-id=<!&!AAAAAAAAAAAYAAAAAAAAAEnhNOn03i9GoForv9mz8wbCgAAAEAAAAHyZc3aRiF1JmmnHWYiGKzABAAAAAA==@temizbau.de>
Feb 28 09:18:44 cx20 postfix/qmgr[20440]: 7A2241A1D5C:
from=<a.te...@temizbau.de>, size=417159, nrcpt=2 (queue active)
Feb 28 09:18:45 cx20 postfix/smtpd[21015]: connect from
localhost.beckspaced.com[127.0.0.1]
Feb 28 09:18:45 cx20 postfix/smtpd[21015]: 9CA0F1A2103:
client=localhost.beckspaced.com[127.0.0.1]
Feb 28 09:18:45 cx20 postfix/cleanup[21012]: 9CA0F1A2103:
message-id=<!&!AAAAAAAAAAAYAAAAAAAAAEnhNOn03i9GoForv9mz8wbCgAAAEAAAAHyZc3aRiF1JmmnHWYiGKzABAAAAAA==@temizbau.de>
Feb 28 09:18:45 cx20 postfix/qmgr[20440]: 9CA0F1A2103:
from=<a.te...@temizbau.de>, size=417519, nrcpt=2 (queue active)
Feb 28 09:18:45 cx20 postfix/smtpd[21015]: disconnect from
localhost.beckspaced.com[127.0.0.1] ehlo=1 mail=1 rcpt=2 data=1 quit=1
commands=6
Feb 28 09:18:45 cx20 amavis[19732]: (19732-18) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [46.85.226.141]:60690
[46.85.226.141] <a.te...@temizbau.de> ->
<regina.ko...@ibbraendlein.de>,<pascha.automa...@t-online.de>, Queue-ID:
7A2241A1D5C, Message-ID: <!&!AAAAAAAAAAAYAAAAAAAAAEnhNOn03i9GoForv9
Feb 28 09:18:45 cx20 postfix/smtp[21013]: 7A2241A1D5C:
to=<regina.ko...@ibbraendlein.de>, relay=127.0.0.1[127.0.0.1]:10026,
delay=2.2, delays=0.67/0/0.01/1.6, dsn=2.0.0, status=sent (250 2.0.0
from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 9CA0F1A2103)
Feb 28 09:18:45 cx20 postfix/smtp[21013]: 7A2241A1D5C:
to=<pascha.automa...@t-online.de>, relay=127.0.0.1[127.0.0.1]:10026,
delay=2.2, delays=0.67/0/0.01/1.6, dsn=2.0.0, status=sent (250 2.0.0
from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 9CA0F1A2103)
Feb 28 09:18:45 cx20 postfix/qmgr[20440]: 7A2241A1D5C: removed
Feb 28 09:18:46 cx20 postfix/smtp[21136]: 9CA0F1A2103:
to=<regina.ko...@ibbraendlein.de>,
relay=mx01.kundenserver.de[217.72.192.67]:25, delay=0.39,
delays=0.07/0/0.11/0.21, dsn=2.0.0, status=sent (250 Requested mail
action okay, completed: id=1MsGo0-1hIRgN3ikE-00tmMH)
Feb 28 09:18:46 cx20 postfix/smtp[21135]: 9CA0F1A2103:
to=<pascha.automa...@t-online.de>,
relay=mx03.t-online.de[194.25.134.73]:25, delay=0.54,
delays=0.07/0/0.11/0.36, dsn=2.0.0, status=sent (250 2.0.0 Message
accepted.)
Feb 28 09:18:46 cx20 postfix/qmgr[20440]: 9CA0F1A2103: removed
here's another sasl auth client email this time with a call to postfwd
Feb 28 09:16:27 cx20 postfix/submission/smtpd[21018]: connect from
200116b82af149000550be497acc878c.dip.versatel-1u1.de[2001:16b8:2af1:4900:550:be49:7acc:878c]
Feb 28 09:16:28 cx20 postfix/submission/smtpd[21018]: 135D81A2103:
client=200116b82af149000550be497acc878c.dip.versatel-1u1.de[2001:16b8:2af1:4900:550:be49:7acc:878c],
sasl_method=LOGIN, sasl_username=nadine.muehlba...@steigerwaldbahn.com
Feb 28 09:16:28 cx20 postfix/cleanup[21012]: 135D81A2103:
message-id=<012701d4cf3d$e772eb90$b658c2b0$@steigerwaldbahn.com>
Feb 28 09:16:28 cx20 postfwd[27680]: 2019/02/28-09:16:28 CONNECT TCP
Peer: "[127.0.0.1]:33684" Local: "[127.0.0.1]:10040"
Feb 28 09:16:28 cx20 postfwd[27680]: [CLEANUP] needed 0.00 seconds for
rate cleanup of 0 out of 18 cached items after cleanup time 600s
Feb 28 09:16:28 cx20 postfix/qmgr[20440]: 135D81A2103:
from=<nadine.muehlba...@steigerwaldbahn.com>, size=10284, nrcpt=1 (queue
active)
Feb 28 09:16:29 cx20 postfix/smtpd[21015]: connect from
localhost.beckspaced.com[127.0.0.1]
Feb 28 09:16:29 cx20 postfix/smtpd[21015]: 388B61A2131:
client=localhost.beckspaced.com[127.0.0.1]
Feb 28 09:16:29 cx20 postfix/cleanup[21012]: 388B61A2131:
message-id=<012701d4cf3d$e772eb90$b658c2b0$@steigerwaldbahn.com>
Feb 28 09:16:29 cx20 postfix/qmgr[20440]: 388B61A2131:
from=<nadine.muehlba...@steigerwaldbahn.com>, size=10740, nrcpt=1 (queue
active)
Feb 28 09:16:29 cx20 postfix/smtpd[21015]: disconnect from
localhost.beckspaced.com[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1
commands=5
Feb 28 09:16:29 cx20 postfix/lmtp[21017]: connect to localhost[::1]:24:
Connection refused
Feb 28 09:16:29 cx20 amavis[19732]: (19732-16) Passed CLEAN
{RelayedInternal}, ORIGINATING LOCAL
[2001:16b8:2af1:4900:550:be49:7acc:878c]:55763
[2001:16b8:2af1:4900:550:be49:7acc:878c]
<nadine.muehlba...@steigerwaldbahn.com> ->
<dietmar.parakeni...@steigerwaldbahn.com>, Queue-ID: 135D81A2103, Messag
Feb 28 09:16:29 cx20 postfix/smtp[21013]: 135D81A2103:
to=<dietmar.parakeni...@steigerwaldbahn.com>,
relay=127.0.0.1[127.0.0.1]:10026, delay=1.2, delays=0.14/0/0/1.1,
dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250
2.0.0 Ok: queued as 388B61A2131)
Feb 28 09:16:29 cx20 postfix/qmgr[20440]: 135D81A2103: removed
Feb 28 09:16:29 cx20 postfix/lmtp[21017]: 388B61A2131:
to=<dietmar.parakeni...@steigerwaldbahn.com>,
relay=localhost[127.0.0.1]:24, delay=0.32, delays=0.01/0/0/0.31,
dsn=2.0.0, status=sent (215 Recipient
<dietmar.parakeni...@steigerwaldbahn.com> OK)
Feb 28 09:16:29 cx20 postfix/qmgr[20440]: 388B61A2131: removed
here's another log from another server where postfix authenticates as
sasl user to the main postfix server
also here postfwd gets called by postfix
Feb 28 03:01:48 cx20 postfix/submission/smtpd[12525]: connect from
cx40.beckspaced.com[2a01:4f8:c17:3bec::2]
Feb 28 03:01:48 cx20 postfix/submission/smtpd[12525]: A5BD51A1ED7:
client=cx40.beckspaced.com[2a01:4f8:c17:3bec::2], sasl_method=LOGIN,
sasl_username=relay-cli...@beckspaced.com
Feb 28 03:01:48 cx20 postfix/cleanup[12987]: A5BD51A1ED7:
message-id=<20190228020148.8469d2e0...@cx40.beckspaced.com>
Feb 28 03:01:48 cx20 postfwd[27680]: 2019/02/28-03:01:48 CONNECT TCP
Peer: "[127.0.0.1]:58022" Local: "[127.0.0.1]:10040"
Feb 28 03:01:48 cx20 postfix/qmgr[26951]: A5BD51A1ED7:
from=<r...@beckspaced.com>, size=36177, nrcpt=1 (queue active)
Feb 28 03:01:48 cx20 postfix/submission/smtpd[12525]: disconnect from
cx40.beckspaced.com[2a01:4f8:c17:3bec::2] ehlo=2 starttls=1 auth=1
mail=1 rcpt=1 data=1 quit=1 commands=8
Feb 28 03:01:48 cx20 postfix/smtpd[12992]: connect from
localhost.beckspaced.com[127.0.0.1]
Feb 28 03:01:48 cx20 postfix/smtpd[12992]: C58641A2118:
client=localhost.beckspaced.com[127.0.0.1]
Feb 28 03:01:48 cx20 postfix/cleanup[12987]: C58641A2118:
message-id=<20190228020148.8469d2e0...@cx40.beckspaced.com>
Feb 28 03:01:48 cx20 postfix/qmgr[26951]: C58641A2118:
from=<r...@beckspaced.com>, size=37411, nrcpt=1 (queue active)
Feb 28 03:01:48 cx20 postfix/smtpd[12992]: disconnect from
localhost.beckspaced.com[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1
commands=5
Feb 28 03:01:48 cx20 amavis[12145]: (12145-08) Passed CLEAN
{RelayedInternal}, ORIGINATING/MYNETS LOCAL [2a01:4f8:c17:3bec::2]:50820
[2a01:4f8:c17:3bec::2] <r...@beckspaced.com> -> <ad...@beckspaced.com>,
Queue-ID: A5BD51A1ED7, Message-ID:
<20190228020148.8469d2e0...@cx40.beckspaced.com>, mail_id: n
Feb 28 03:01:48 cx20 postfix/smtp[12988]: A5BD51A1ED7:
to=<ad...@beckspaced.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=0.16,
delays=0.02/0/0.01/0.13, dsn=2.0.0, status=sent (250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as C58641A2118)
Feb 28 03:01:48 cx20 postfix/qmgr[26951]: A5BD51A1ED7: removed
Feb 28 03:01:49 cx20 postfix/lmtp[12994]: C58641A2118:
to=<ad...@beckspaced.com>, relay=localhost[127.0.0.1]:24, delay=0.58,
delays=0.01/0/0/0.56, dsn=2.0.0, status=sent (215 Recipient
<ad...@beckspaced.com> OK)
Feb 28 03:01:49 cx20 postfix/qmgr[26951]: C58641A2118: removed
So according to the logs sometimes postfix forwards to policy service
postfwd?
Sometimes postfix doesn't? or doesn't it get logged every time?
Or am I understanding something wrong?
I somebody could shed some light on this topic I would be more than
grateful ;)
thanks & greetings
Becki
snippet main.cf
===============
...
smtpd_sender_restrictions = warn_if_reject reject_unknown_sender_domain
smtpd_recipient_restrictions = permit_mynetworks,
permit_sasl_authenticated,
reject_non_fqdn_recipient,
reject_non_fqdn_sender,
reject_unknown_recipient_domain,
reject_unauth_destination,
check_helo_access hash:/etc/postfix/helo_access,
check_client_access hash:/etc/postfix/client_access,
check_sender_access hash:/etc/postfix/access,
check_recipient_access hash:/etc/postfix/recipient_accept,
check_recipient_access hash:/etc/postfix/recipient_reject,
check_recipient_access
hash:/etc/postfix/roleaccount_exceptions,
permit
smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:10040
...
=====================