On Tue, March 10, 2020 10:27 am, Wietse Venema wrote:
> This is Postfix logging while SENDING email through an after-queue
> content filter (which has serious congestion, but that is not the problem
> in $SUBJECT).
>
> To come back to $SUBJECT, if you have user clients timing out, then
> you should be looking at Postfix logging while RECEIVING email from the
> client.
Wietse, thanks
oops, sorry.. I guess it the first 'section', for completeness, included
whole progress
noticed (unrelated I think) issue, user has both a_tld.com as well as
a_tld.com.au, from the log, he seems to use both, .com.au in sasl auth
# grep C099F42B0143 /var/log/maillog
Mar 10 00:10:49 geko postfix/smtpd[9483]: C099F42B0143:
client=unknown[119.42.117.134], sasl_method=PLAIN,
sasl_username=bb@a_tld.com.au
Mar 10 00:10:50 geko postfix/cleanup[9389]: C099F42B0143:
message-id=<5262b5f4-18d5-b7fb-b09a-be37f1d61b9e@a_tld.com>
Mar 10 00:12:38 geko opendkim[1322]: C099F42B0143: DKIM-Signature field
added (s=default, d=a_tld.com)
Mar 10 00:12:39 geko opendmarc[1295]: C099F42B0143: SPF(mailfrom):
bb@a_tld.com fail
Mar 10 00:12:39 geko opendmarc[1295]: C099F42B0143: a_tld.com fail
Mar 10 00:12:39 geko postfix/qmgr[1857]: C099F42B0143:
from=<bb@a_tld.com>, size=240046, nrcpt=1 (queue active)
Mar 10 00:12:42 geko amavis[4998]: (04998-13) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [119.42.117.134]:58287
[119.42.117.134] <bb@a_tld.com> -> <recipient@mt_tld.com>, Queue-ID:
C099F42B0143, Message-ID:
<5262b5f4-18d5-b7fb-b09a-be37f1d61b9e@a_tld.com>, mail_id: qJth6ESNbOwS,
Hits: 0.222, size: 240858, queued_as: 145BB42B0149, 2796 ms
Mar 10 00:12:42 geko postfix/smtp[9497]: C099F42B0143:
to=<recipient@mt_tld.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=113,
delays=111/0.01/0.01/2.8, 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 145BB42B0149)
Mar 10 00:12:42 geko postfix/qmgr[1857]: C099F42B0143: removed
# grep 145BB42B0149 /var/log/maillog
Mar 10 00:12:42 geko postfix/smtpd[9501]: 145BB42B0149:
client=localhost[127.0.0.1]
Mar 10 00:12:42 geko postfix/cleanup[9389]: 145BB42B0149:
message-id=<5262b5f4-18d5-b7fb-b09a-be37f1d61b9e@a_tld.com>
Mar 10 00:12:42 geko postfix/qmgr[1857]: 145BB42B0149:
from=<bb@a_tld.com>, size=241161, nrcpt=1 (queue active)
Mar 10 00:12:42 geko amavis[4998]: (04998-13) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [119.42.117.134]:58287
[119.42.117.134] <bb@a_tld.com> -> <recipient@mt_tld.com>, Queue-ID:
C099F42B0143, Message-ID:
<5262b5f4-18d5-b7fb-b09a-be37f1d61b9e@a_tld.com>, mail_id: qJth6ESNbOwS,
Hits: 0.222, size: 240858, queued_as: 145BB42B0149, 2796 ms
Mar 10 00:12:42 geko postfix/smtp[9497]: C099F42B0143:
to=<recipient@mt_tld.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=113,
delays=111/0.01/0.01/2.8, 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 145BB42B0149)
Mar 10 00:12:46 geko postfix/smtp[9502]: 145BB42B0149:
to=<recipient@mt_tld.com>, relay=aspmx.l.google.com[172.217.194.26]:25,
delay=4, delays=0.01/0.02/1.9/2, dsn=2.0.0, status=sent (250 2.0.0 OK
1583759565 i6si12263894pjk.13 - gsmtp)
Mar 10 00:12:46 geko postfix/qmgr[1857]: 145BB42B0149: removed
# grep 1707542B0143 /var/log/maillog
Mar 10 00:13:13 geko postfix/smtpd[9491]: 1707542B0143:
client=unknown[119.42.117.134], sasl_method=PLAIN,
sasl_username=bb@a_tld.com.au
Mar 10 00:13:16 geko postfix/cleanup[9389]: 1707542B0143:
message-id=<e2c64788-c8b8-13e9-6c1c-3ad8f1d4a34d@a_tld.com>
Mar 10 00:14:07 geko opendkim[1322]: 1707542B0143: DKIM-Signature field
added (s=default, d=a_tld.com)
Mar 10 00:14:08 geko opendmarc[1295]: 1707542B0143: SPF(mailfrom):
bb@a_tld.com fail
Mar 10 00:14:08 geko opendmarc[1295]: 1707542B0143: a_tld.com fail
Mar 10 00:14:08 geko postfix/qmgr[1857]: 1707542B0143:
from=<bb@a_tld.com>, size=239372, nrcpt=1 (queue active)
Mar 10 00:14:09 geko amavis[4927]: (04927-14) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [119.42.117.134]:58356
[119.42.117.134] <bb@a_tld.com> -> <recipient@mt_tld.com>, Queue-ID:
1707542B0143, Message-ID:
<e2c64788-c8b8-13e9-6c1c-3ad8f1d4a34d@a_tld.com>, mail_id: Gkn3suP0kf4K,
Hits: 2.714, size: 240145, queued_as: 175C542B0146, 1052 ms
Mar 10 00:14:09 geko postfix/smtp[9497]: 1707542B0143:
to=<recipient@mt_tld.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=57,
delays=55/0/0.01/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 175C542B0146)
Mar 10 00:14:09 geko postfix/qmgr[1857]: 1707542B0143: removed
# grep 175C542B0146 /var/log/maillog
Mar 10 00:14:09 geko postfix/smtpd[9501]: 175C542B0146:
client=localhost[127.0.0.1]
Mar 10 00:14:09 geko postfix/cleanup[9389]: 175C542B0146:
message-id=<e2c64788-c8b8-13e9-6c1c-3ad8f1d4a34d@a_tld.com>
Mar 10 00:14:09 geko postfix/qmgr[1857]: 175C542B0146:
from=<bb@a_tld.com>, size=240448, nrcpt=1 (queue active)
Mar 10 00:14:09 geko amavis[4927]: (04927-14) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [119.42.117.134]:58356
[119.42.117.134] <bb@a_tld.com> -> <recipient@mt_tld.com>, Queue-ID:
1707542B0143, Message-ID:
<e2c64788-c8b8-13e9-6c1c-3ad8f1d4a34d@a_tld.com>, mail_id: Gkn3suP0kf4K,
Hits: 2.714, size: 240145, queued_as: 175C542B0146, 1052 ms
Mar 10 00:14:09 geko postfix/smtp[9497]: 1707542B0143:
to=<recipient@mt_tld.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=57,
delays=55/0/0.01/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 175C542B0146)
Mar 10 00:14:12 geko postfix/smtp[9502]: 175C542B0146:
to=<recipient@mt_tld.com>, relay=aspmx.l.google.com[172.217.194.26]:25,
delay=3.6, delays=0.01/0.01/1.6/1.9, dsn=2.0.0, status=sent (250 2.0.0 OK
1583759652 y21si12154012pfm.184 - gsmtp)
Mar 10 00:14:12 geko postfix/qmgr[1857]: 175C542B0146: removed
# grep 57DB841A85FC /var/log/maillog
Mar 10 00:19:50 geko postfix/smtpd[9693]: 57DB841A85FC:
client=unknown[119.42.117.134], sasl_method=PLAIN,
sasl_username=bb@a_tld.com.au
Mar 10 00:19:51 geko postfix/cleanup[9698]: 57DB841A85FC:
message-id=<047f74f8-c3b0-15c7-98b8-6df16a0115ac@a_tld.com>
Mar 10 00:20:14 geko opendkim[1322]: 57DB841A85FC: DKIM-Signature field
added (s=default, d=a_tld.com)
Mar 10 00:20:14 geko opendmarc[1295]: 57DB841A85FC: SPF(mailfrom):
bb@a_tld.com fail
Mar 10 00:20:14 geko opendmarc[1295]: 57DB841A85FC: a_tld.com fail
Mar 10 00:20:14 geko postfix/qmgr[1857]: 57DB841A85FC:
from=<bb@a_tld.com>, size=156097, nrcpt=1 (queue active)
Mar 10 00:20:16 geko amavis[4998]: (04998-15) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [119.42.117.134]:58409
[119.42.117.134] <bb@a_tld.com> -> <recipient@mt_tld.com>, Queue-ID:
57DB841A85FC, Message-ID:
<047f74f8-c3b0-15c7-98b8-6df16a0115ac@a_tld.com>, mail_id: saXIzyV4Xh2B,
Hits: 0.12, size: 156800, queued_as: E6C8E41A8691, 1084 ms
Mar 10 00:20:16 geko postfix/smtp[9769]: 57DB841A85FC:
to=<recipient@mt_tld.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=26,
delays=25/0.02/0.01/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 E6C8E41A8691)
Mar 10 00:20:16 geko postfix/qmgr[1857]: 57DB841A85FC: removed
# grep E6C8E41A8691 /var/log/maillog
Mar 10 00:20:15 geko postfix/smtpd[9772]: E6C8E41A8691:
client=localhost[127.0.0.1]
Mar 10 00:20:15 geko postfix/cleanup[9708]: E6C8E41A8691:
message-id=<047f74f8-c3b0-15c7-98b8-6df16a0115ac@a_tld.com>
Mar 10 00:20:15 geko postfix/qmgr[1857]: E6C8E41A8691:
from=<bb@a_tld.com>, size=157103, nrcpt=1 (queue active)
Mar 10 00:20:16 geko amavis[4998]: (04998-15) Passed CLEAN
{RelayedOutbound}, ORIGINATING LOCAL [119.42.117.134]:58409
[119.42.117.134] <bb@a_tld.com> -> <recipient@mt_tld.com>, Queue-ID:
57DB841A85FC, Message-ID:
<047f74f8-c3b0-15c7-98b8-6df16a0115ac@a_tld.com>, mail_id: saXIzyV4Xh2B,
Hits: 0.12, size: 156800, queued_as: E6C8E41A8691, 1084 ms
Mar 10 00:20:16 geko postfix/smtp[9769]: 57DB841A85FC:
to=<recipient@mt_tld.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=26,
delays=25/0.02/0.01/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 E6C8E41A8691)
Mar 10 00:20:19 geko postfix/smtp[9773]: E6C8E41A8691:
to=<recipient@mt_tld.com>, relay=aspmx.l.google.com[74.125.130.27]:25,
delay=3.5, delays=0.06/0.04/1.9/1.6, dsn=2.0.0, status=sent (250 2.0.0 OK
1583760019 f26si12249799pfn.45 - gsmtp)
Mar 10 00:20:19 geko postfix/qmgr[1857]: E6C8E41A8691: removed
