PMG 7.1-2 Mails von einigen Sender z.B. Amazon werden mehrfach ans Postfach geliefert.,

UCR

UCR

Member
Proxmox Subscriber
Jun 17, 2022
30
1
8
Hi,
ich bekomme von wenigen Absendern z.b. Amazon eine Mail mehrfach ins Postfach gestellt.
Wo sollte man anfangen den Fehler zu suchen?
Gruß Uwe

Im Log sieht das für eine solche Mail wie folgt aus:
Code: 
Jun 15 14:28:07 mail postfix/smtpd[1140092]: connect from a1-125.smtp-out.eu-west-1.amazonses.com[54.240.1.125]
Jun 15 14:28:07 mail postfix/smtpd[1140092]: Anonymous TLS connection established from a1-125.smtp-out.eu-west-1.amazonses.com[54.240.1.125]: TLSv1.2 with cipher ECDHE-RSA-AES128-SHA256 (128/128 bits)
Jun 15 14:28:07 mail postfix/smtpd[1140092]: CC5B982410: client=a1-125.smtp-out.eu-west-1.amazonses.com[54.240.1.125]
Jun 15 14:28:07 mail postfix/cleanup[1140136]: CC5B982410: message-id=<010201816755bbef-3952c704-1b84-4e39-a243-a83c6941763d-000000@eu-west-1.amazonses.com>
Jun 15 14:28:07 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 14:28:28 mail postfix/smtpd[1140092]: disconnect from a1-125.smtp-out.eu-west-1.amazonses.com[54.240.1.125] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Jun 15 14:38:07 mail postfix/lmtp[1140137]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=600, delays=0.18/0/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 14:51:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 15:01:40 mail postfix/lmtp[1141324]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=2013, delays=1413/0.06/0.03/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 15:36:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 15:46:40 mail postfix/lmtp[1143520]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=4713, delays=4112/0/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 16:56:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 17:06:40 mail postfix/lmtp[1144422]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=9513, delays=8913/0.01/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 18:16:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 18:26:40 mail postfix/lmtp[1145088]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=14313, delays=13713/0/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 19:36:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 19:46:40 mail postfix/lmtp[1145764]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=19113, delays=18513/0.01/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 20:56:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 21:06:40 mail postfix/lmtp[1146354]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=23913, delays=23313/0.01/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 22:16:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 22:26:40 mail postfix/lmtp[1146989]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=28713, delays=28113/0/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 15 23:36:40 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 15 23:46:40 mail postfix/lmtp[1147604]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=33513, delays=32913/0.01/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 00:56:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 01:06:41 mail postfix/lmtp[1148264]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=38314, delays=37714/0.01/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 02:16:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 02:26:41 mail postfix/lmtp[1148833]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=43114, delays=42514/0/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 03:13:02 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 03:23:02 mail postfix/lmtp[1149265]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=46495, delays=45895/0.01/0/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 04:31:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 04:41:41 mail postfix/lmtp[1150181]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=51214, delays=50614/0.03/0.06/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 05:51:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 06:01:41 mail postfix/lmtp[1150763]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=56014, delays=55414/0.03/0.06/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 07:11:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 07:21:41 mail postfix/lmtp[1151510]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=60813, delays=60213/0.04/0.06/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 08:31:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 08:41:41 mail postfix/lmtp[1152167]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=65614, delays=65014/0.01/0.05/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 09:51:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 10:01:41 mail postfix/lmtp[1152809]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=70414, delays=69814/0.03/0.05/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 11:11:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 11:21:41 mail postfix/lmtp[1153474]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=75214, delays=74614/0.04/0.06/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 12:31:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 12:41:41 mail postfix/lmtp[1154130]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=80014, delays=79414/0.03/0.06/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 13:51:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 14:01:41 mail postfix/lmtp[1154769]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=84814, delays=84214/0.01/0.04/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 15:11:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 15:21:41 mail postfix/lmtp[1155456]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=89614, delays=89014/0.03/0.05/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 15:26:22 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 15:36:22 mail postfix/lmtp[1155608]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=90495, delays=89895/0.07/0.34/600, dsn=4.4.2, status=deferred (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 16:46:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 16:56:42 mail postfix/error[1156289]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=none, delay=95314, delays=94714/600/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 18:06:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 18:16:41 mail postfix/error[1156903]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=none, delay=100114, delays=99514/600/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 19:26:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 19:36:41 mail postfix/error[1157533]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=none, delay=104914, delays=104314/600/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 20:46:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 20:56:41 mail postfix/error[1158084]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=none, delay=109714, delays=109114/600/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 22:06:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 22:16:41 mail postfix/error[1158688]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=none, delay=114514, delays=113914/600/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
Jun 16 23:26:41 mail postfix/qmgr[1405]: CC5B982410: from=<202206151228007e474858d9a84206b7155a9ba430p0eu-C17P22CTYH2JZA@bounces.amazon.de>, size=55950, nrcpt=1 (queue active)
Jun 16 23:36:41 mail postfix/error[1159316]: CC5B982410: to=<name1.name2@mymailserverone.de>, relay=none, delay=119314, delays=118714/600/0/0.02, dsn=4.4.2, status=deferred (delivery temporarily suspended: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
 
Sind die Logs von einem PMG System?

falls ja - was sagt das journal zum pmg-smtp-filter service?
(`journalctl -u pmg-smtp-filter`)
 
Ja, das ist ein PMG System Log.
Ich habe heute von amazon die gleiche Mail 3 mal bekommen um 04:49, 05:15, 06:18, 07:50
Das Journal nach amazon gefiltert von heute sieht so aus: journalctl -u pmg-smtp-filter | grep amazon
Jun 19 23:37:03 mail pmg-smtp-filter[26759]: A1F5F62AF96FF4303E: new mail message-id=<010201817d44d5b5-919f6db5-af20-41a3-aadc-72dac268756f-000000@eu-west-1.amazonses.com> Jun 20 00:27:03 mail pmg-smtp-filter[27030]: A1F3A62AFA2B7480E0: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 00:27:03 mail pmg-smtp-filter[27366]: A1F5962AFA2B75A7AB: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 00:27:03 mail pmg-smtp-filter[27378]: A1F6862AFA2B7BDADA: new mail message-id=<0102018177974d3d-123f0590-78c1-4282-823a-e39b0e1c1eda-000000@eu-west-1.amazonses.com> Jun 20 00:47:03 mail pmg-smtp-filter[27519]: A1F9762AFA7675FFEB: new mail message-id=<010201817e207e06-1f588949-dab4-4144-a3a4-5d00b72aa1ed-000000@eu-west-1.amazonses.com> Jun 20 00:57:03 mail pmg-smtp-filter[27382]: A0D4862AFA9BF49364: new mail message-id=<010201817d44d5b5-919f6db5-af20-41a3-aadc-72dac268756f-000000@eu-west-1.amazonses.com> Jun 20 01:17:03 mail pmg-smtp-filter[28058]: A0D4862AFAE6F58F86: new mail message-id=<010201817e207e06-1f588949-dab4-4144-a3a4-5d00b72aa1ed-000000@eu-west-1.amazonses.com> Jun 20 01:46:57 mail pmg-smtp-filter[28058]: A014A62AFB571B0E1E: new mail message-id=<010201817e5ca8a7-57f799c1-3003-4fe9-bc85-ffc52e9ec73d-000000@eu-west-1.amazonses.com> Jun 20 01:47:03 mail pmg-smtp-filter[28397]: A1F7562AFB577C4623: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 01:47:03 mail pmg-smtp-filter[28404]: A1F7662AFB577D3321: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 02:07:03 mail pmg-smtp-filter[28412]: A1F8D62AFBA27639F6: new mail message-id=<010201817e5ca8a7-57f799c1-3003-4fe9-bc85-ffc52e9ec73d-000000@eu-west-1.amazonses.com> Jun 20 02:12:03 mail pmg-smtp-filter[28404]: A014A62AFBB53593EE: new mail message-id=<010201817d44d5b5-919f6db5-af20-41a3-aadc-72dac268756f-000000@eu-west-1.amazonses.com> Jun 20 02:17:03 mail pmg-smtp-filter[28594]: A1F6462AFBC7F346F2: new mail message-id=<010201817e207e06-1f588949-dab4-4144-a3a4-5d00b72aa1ed-000000@eu-west-1.amazonses.com> Jun 20 02:52:03 mail pmg-smtp-filter[28652]: A1F7562AFC4B35FE60: new mail message-id=<010201817e5ca8a7-57f799c1-3003-4fe9-bc85-ffc52e9ec73d-000000@eu-west-1.amazonses.com> Jun 20 03:07:03 mail pmg-smtp-filter[28994]: A1F6462AFC837571ED: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 03:07:03 mail pmg-smtp-filter[29002]: A1F7A62AFC83764376: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 03:07:03 mail pmg-smtp-filter[29010]: A1F9762AFC8378B331: new mail message-id=<0102018177974d3d-123f0590-78c1-4282-823a-e39b0e1c1eda-000000@eu-west-1.amazonses.com> Jun 20 03:32:03 mail pmg-smtp-filter[29010]: A1F6462AFCE133E0EE: new mail message-id=<010201817d44d5b5-919f6db5-af20-41a3-aadc-72dac268756f-000000@eu-west-1.amazonses.com> Jun 20 03:37:03 mail pmg-smtp-filter[29006]: A1F6862AFCF3F6B642: new mail message-id=<010201817e207e06-1f588949-dab4-4144-a3a4-5d00b72aa1ed-000000@eu-west-1.amazonses.com> Jun 20 04:12:03 mail pmg-smtp-filter[29216]: A1F6462AFD7733AC19: new mail message-id=<010201817e5ca8a7-57f799c1-3003-4fe9-bc85-ffc52e9ec73d-000000@eu-west-1.amazonses.com> Jun 20 04:27:03 mail pmg-smtp-filter[29567]: A1F7662AFDAF750E8A: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 04:27:03 mail pmg-smtp-filter[29575]: A1F8D62AFDAF75DCE1: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 04:27:03 mail pmg-smtp-filter[29583]: A1FA162AFDAF77BC6E: new mail message-id=<0102018177974d3d-123f0590-78c1-4282-823a-e39b0e1c1eda-000000@eu-west-1.amazonses.com> Jun 20 04:48:49 mail pmg-smtp-filter[29583]: A0D4862AFE01156661: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 04:48:49 mail pmg-smtp-filter[29722]: A1F6462AFE01163556: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 04:48:49 mail pmg-smtp-filter[29730]: A1F7A62AFE011770EB: new mail message-id=<010201817e207e06-1f588949-dab4-4144-a3a4-5d00b72aa1ed-000000@eu-west-1.amazonses.com> Jun 20 04:48:49 mail pmg-smtp-filter[29738]: A1FA362AFE011A8920: new mail message-id=<010201817247abe3-8513eb78-3761-43a8-a1c7-7bcff4c917cd-000000@eu-west-1.amazonses.com> Jun 20 05:07:03 mail pmg-smtp-filter[29575]: A014A62AFE45744C6C: new mail message-id=<010201817f0e0fd7-7c557c2c-716b-47f3-a9aa-34277bff89a0-000000@eu-west-1.amazonses.com> Jun 20 05:37:03 mail pmg-smtp-filter[29960]: A014A62AFEB5F4B472: new mail message-id=<010201817f0e0fd7-7c557c2c-716b-47f3-a9aa-34277bff89a0-000000@eu-west-1.amazonses.com> Jun 20 06:07:03 mail pmg-smtp-filter[30303]: A1F6862AFF267582C4: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 06:07:03 mail pmg-smtp-filter[30311]: A1F7662AFF267651B0: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 06:07:03 mail pmg-smtp-filter[30315]: A1F7A62AFF26777BCA: new mail message-id=<010201817e5ca8a7-57f799c1-3003-4fe9-bc85-ffc52e9ec73d-000000@eu-west-1.amazonses.com> Jun 20 06:10:07 mail pmg-smtp-filter[29575]: A014A62AFF31F207BB: new mail message-id=<0102018177974d3d-123f0590-78c1-4282-823a-e39b0e1c1eda-000000@eu-west-1.amazonses.com> Jun 20 06:10:07 mail pmg-smtp-filter[30349]: A0D4862AFF31F3C45F: new mail message-id=<010201817247abe3-8513eb78-3761-43a8-a1c7-7bcff4c917cd-000000@eu-west-1.amazonses.com> Jun 20 06:37:03 mail pmg-smtp-filter[30503]: A014A62AFF96F5B946: new mail message-id=<010201817f0e0fd7-7c557c2c-716b-47f3-a9aa-34277bff89a0-000000@eu-west-1.amazonses.com> Jun 20 07:27:03 mail pmg-smtp-filter[30503]: A1F7662B00527471C3: new mail message-id=<0102018174857b79-ea8a71fb-58b5-4fc7-9f54-08ba17120c62-000000@eu-west-1.amazonses.com> Jun 20 07:27:03 mail pmg-smtp-filter[31005]: A1F7A62B0052752FB6: new mail message-id=<01020181761edadd-00e2e4a3-65f1-4418-97e4-4884eb6080f4-000000@eu-west-1.amazonses.com> Jun 20 07:27:03 mail pmg-smtp-filter[31013]: A1F8D62B0052763982: new mail message-id=<010201817e5ca8a7-57f799c1-3003-4fe9-bc85-ffc52e9ec73d-000000@eu-west-1.amazonses.com> Jun 20 07:57:03 mail pmg-smtp-filter[31013]: A014A62B00C2F49E20: new mail message-id=<010201817f0e0fd7-7c557c2c-716b-47f3-a9aa-34277bff89a0-000000@eu-west-1.amazonses.com> Jun 20 08:44:27 mail pmg-smtp-filter[31293]: A0D4862B0174BAB160: new mail message-id=<010201817fdae408-70b9527f-ba25-45e2-98b0-68b753222b12-000000@eu-west-1.amazonses.com> Jun 20 09:50:28 mail pmg-smtp-filter[31293]: A1F7A62B026C424B64: new mail message-id=<010201818017538a-abca127f-c5aa-447f-a3e5-b7fbebcd8ee4-000000@eu-west-1.amazonses.com> Jun 20 09:50:28 mail pmg-smtp-filter[32384]: A1F8D62B026C4ED71F: new mail message-id=<010201818017565c-d116009e-1baa-4dfe-bd45-da68facc464b-000000@eu-west-1.amazonses.com> Jun 20 09:52:24 mail pmg-smtp-filter[35586]: A1F9762B027385B86C: new mail message-id=<01020181801931a0-c669c195-f4ba-422e-9e3b-1ae6f1637a62-000000@eu-west-1.amazonses.com> Jun 20 09:52:24 mail pmg-smtp-filter[35679]: A1FAE62B027388249A: new mail message-id=<01020181801931a3-abc49bbf-ff58-4ddb-903f-7e87a9aab090-000000@eu-west-1.amazonses.com> Jun 20 09:53:22 mail pmg-smtp-filter[35685]: A0D4862B027728B7FF: new mail message-id=<01020181801a14a1-e5cfe6cf-6520-4029-89d3-a02b07b4beae-000000@eu-west-1.amazonses.com> Jun 20 09:57:22 mail pmg-smtp-filter[35685]: A0D4862B02862050CE: new mail message-id=<01020181801dbbd3-2b2e7e8a-9178-4291-9672-1b8210688f50-000000@eu-west-1.amazonses.com> Jun 20 10:04:34 mail pmg-smtp-filter[36199]: A1F8D62B02A12616D8: new mail message-id=<0102018180243ce2-f7a15916-9ddd-4d38-bcc9-76bba81c95c0-000000@eu-west-1.amazonses.com>
 
While grepping can help in reducing the number of lines - in that case it removes all relevant information - we already know that postfix handed the mails multiple times to pmg-smtp-filter due to timeouts - the idea was to find out why it timed out ...

so please post the complete log (maybe even the complete journal (anonymize what you don't want to have in public) around the time this issue occured
 
Hier ein kompletter Ausschnitt über 10 Minuten, es scheint als kämen die Mails sehr schnell hintereinander,
Jun 20 09:50:28 mail pmg-smtp-filter[31293]: 2022/06/20-09:50:28 CONNECT TCP Peer: "[127.0.0.1]:41418" Local: "[127.0.0.1]:10024" Jun 20 09:50:28 mail pmg-smtp-filter[31293]: A1F7A62B026C424B64: new mail message-id=<010201818017538a-abca127f-c5aa-447f-a3e5-b7fbebcd8ee4-000000@eu-west-1.amazonses.com> Jun 20 09:50:28 mail pmg-smtp-filter[32384]: 2022/06/20-09:50:28 CONNECT TCP Peer: "[127.0.0.1]:41420" Local: "[127.0.0.1]:10024" Jun 20 09:50:28 mail pmg-smtp-filter[28052]: Starting "1" children Jun 20 09:50:28 mail pmg-smtp-filter[32384]: A1F8D62B026C4ED71F: new mail message-id=<010201818017565c-d116009e-1baa-4dfe-bd45-da68facc464b-000000@eu-west-1.amazonses.com> Jun 20 09:51:19 mail pmg-smtp-filter[28052]: starting database maintenance Jun 20 09:51:19 mail pmg-smtp-filter[28052]: end database maintenance (7 ms) Jun 20 09:52:24 mail pmg-smtp-filter[28052]: Starting "1" children Jun 20 09:52:24 mail pmg-smtp-filter[35586]: 2022/06/20-09:52:24 CONNECT TCP Peer: "[127.0.0.1]:41422" Local: "[127.0.0.1]:10024" Jun 20 09:52:24 mail pmg-smtp-filter[35586]: A1F9762B027385B86C: new mail message-id=<01020181801931a0-c669c195-f4ba-422e-9e3b-1ae6f1637a62-000000@eu-west-1.amazonses.com> Jun 20 09:52:24 mail pmg-smtp-filter[28052]: Starting "1" children Jun 20 09:52:24 mail pmg-smtp-filter[35679]: 2022/06/20-09:52:24 CONNECT TCP Peer: "[127.0.0.1]:41424" Local: "[127.0.0.1]:10024" Jun 20 09:52:24 mail pmg-smtp-filter[35679]: A1FAE62B027388249A: new mail message-id=<01020181801931a3-abc49bbf-ff58-4ddb-903f-7e87a9aab090-000000@eu-west-1.amazonses.com> Jun 20 09:52:24 mail pmg-smtp-filter[31293]: A1F7A62B026C424B64: SA score=0/5 time=1.693 bayes=undefined autolearn=no autolearn_force=no hits=AWL(-0.349),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),KAM_ASCII_DIVIDERS(0.8),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:52:24 mail pmg-smtp-filter[31293]: A1F7A62B026C424B64: accept mail to <name1.name2@domainname.de> (ACB378043C) (rule: default-accept) Jun 20 09:52:24 mail pmg-smtp-filter[31293]: A1F7A62B026C424B64: processing time: 116.561 seconds (1.693, 0.044, 0) Jun 20 09:52:25 mail pmg-smtp-filter[32384]: A1F8D62B026C4ED71F: SA score=0/5 time=1.665 bayes=undefined autolearn=no autolearn_force=no hits=AWL(-0.174),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),KAM_ASCII_DIVIDERS(0.8),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:52:25 mail pmg-smtp-filter[32384]: A1F8D62B026C4ED71F: accept mail to <name1.name2@domainname.de> (352CF80428) (rule: default-accept) Jun 20 09:52:25 mail pmg-smtp-filter[32384]: A1F8D62B026C4ED71F: processing time: 116.269 seconds (1.665, 0.031, 0) Jun 20 09:52:55 mail pmg-smtp-filter[28052]: Killing "2" children Jun 20 09:53:22 mail pmg-smtp-filter[28052]: Starting "1" children Jun 20 09:53:22 mail pmg-smtp-filter[35685]: 2022/06/20-09:53:22 CONNECT TCP Peer: "[127.0.0.1]:41426" Local: "[127.0.0.1]:10024" Jun 20 09:53:22 mail pmg-smtp-filter[35685]: A0D4862B027728B7FF: new mail message-id=<01020181801a14a1-e5cfe6cf-6520-4029-89d3-a02b07b4beae-000000@eu-west-1.amazonses.com> Jun 20 09:53:32 mail pmg-smtp-filter[28052]: starting database maintenance Jun 20 09:53:32 mail pmg-smtp-filter[28052]: end database maintenance (11 ms) Jun 20 09:54:21 mail pmg-smtp-filter[35679]: A1FAE62B027388249A: SA score=0/5 time=0.781 bayes=undefined autolearn=no autolearn_force=no hits=AWL(-0.116),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),KAM_ASCII_DIVIDERS(0.8),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:54:21 mail pmg-smtp-filter[35679]: A1FAE62B027388249A: accept mail to <name1.name2@domainname.de> (3856E80431) (rule: default-accept) Jun 20 09:54:21 mail pmg-smtp-filter[35679]: A1FAE62B027388249A: processing time: 116.702 seconds (0.781, 0.023, 0) Jun 20 09:54:21 mail pmg-smtp-filter[28052]: Killing "1" children Jun 20 09:54:21 mail pmg-smtp-filter[35586]: A1F9762B027385B86C: SA score=0/5 time=0.784 bayes=undefined autolearn=no autolearn_force=no hits=AWL(-0.087),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),KAM_ASCII_DIVIDERS(0.8),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:54:21 mail pmg-smtp-filter[35586]: A1F9762B027385B86C: accept mail to <name1.name2@domainname.de> (84D8380431) (rule: default-accept) Jun 20 09:54:21 mail pmg-smtp-filter[35586]: A1F9762B027385B86C: processing time: 117.172 seconds (0.784, 0.02, 0) Jun 20 09:54:31 mail pmg-smtp-filter[28052]: Killing "1" children Jun 20 09:55:18 mail pmg-smtp-filter[35685]: A0D4862B027728B7FF: SA score=0/5 time=0.460 bayes=undefined autolearn=no autolearn_force=no hits=AWL(-0.070),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),KAM_ASCII_DIVIDERS(0.8),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:55:18 mail pmg-smtp-filter[35685]: A0D4862B027728B7FF: accept mail to <name1.name2@domainname.de> (0A47180431) (rule: default-accept) Jun 20 09:55:18 mail pmg-smtp-filter[35685]: A0D4862B027728B7FF: processing time: 115.477 seconds (0.46, 0.034, 0) Jun 20 09:55:48 mail pmg-smtp-filter[28052]: starting database maintenance Jun 20 09:55:48 mail pmg-smtp-filter[28052]: end database maintenance (15 ms) Jun 20 09:56:50 mail pmg-smtp-filter[35679]: 2022/06/20-09:56:50 CONNECT TCP Peer: "[127.0.0.1]:41428" Local: "[127.0.0.1]:10024" Jun 20 09:56:50 mail pmg-smtp-filter[35679]: A0D4862B0284262012: new mail message-id=<b11418965b2ad9c8d0564a358f13b15f@forum.proxmox.com> Jun 20 09:56:53 mail pmg-smtp-filter[35679]: A0D4862B0284262012: SA score=0/5 time=2.595 bayes=undefined autolearn=ham autolearn_force=no hits=HTML_MESSAGE(0.001),KAM_DMARC_STATUS(0.01),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:56:53 mail pmg-smtp-filter[35679]: A0D4862B0284262012: accept mail to <name1.name2@domainname.de> (0A41980431) (rule: default-accept) Jun 20 09:56:53 mail pmg-smtp-filter[35679]: A0D4862B0284262012: processing time: 2.685 seconds (2.595, 0.03, 0) Jun 20 09:57:22 mail pmg-smtp-filter[35685]: 2022/06/20-09:57:22 CONNECT TCP Peer: "[127.0.0.1]:41430" Local: "[127.0.0.1]:10024" Jun 20 09:57:22 mail pmg-smtp-filter[35685]: A0D4862B02862050CE: new mail message-id=<01020181801dbbd3-2b2e7e8a-9178-4291-9672-1b8210688f50-000000@eu-west-1.amazonses.com> Jun 20 09:57:52 mail pmg-smtp-filter[28052]: starting database maintenance Jun 20 09:57:52 mail pmg-smtp-filter[28052]: end database maintenance (14 ms) Jun 20 09:59:15 mail pmg-smtp-filter[35685]: A0D4862B02862050CE: SA score=0/5 time=0.789 bayes=undefined autolearn=no autolearn_force=no hits=AWL(-0.058),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),KAM_ASCII_DIVIDERS(0.8),SPF_HELO_NONE(0.001),SPF_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01) Jun 20 09:59:15 mail pmg-smtp-filter[35685]: A0D4862B02862050CE: accept mail to <name1.name2@domainname.de> (7CC5E80431) (rule: default-accept) Jun 20 09:59:15 mail pmg-smtp-filter[35685]: A0D4862B02862050CE: processing time: 113.494 seconds (0.789, 0.023, 0) Jun 20 09:59:55 mail pmg-smtp-filter[28052]: starting database maintenance Jun 20 09:59:55 mail pmg-smtp-filter[28052]: end database maintenance (14 ms)
 
Von Stackoverflow:

Amazon assigns a unique message ID to every email sent. Look in the full headers of the emails you received for an ID like the following:
0000012fea2d8375-85e23920-10cf-4d1b-b237-5dc13847b66c-000000@email.amazonses.com
If it is the same in both emails you got, then there is some sort of glitch between Amazon and the receiving SMTP server that is causing it to be resent.

In unserem pgm-smtp-filter log von heute gibt es 30 doppelte ID und 17 eindeutige ID von amazon
 
UCR said:
Hier ein kompletter Ausschnitt über 10 Minuten,
Click to expand...
nicht wirklich komplett - oder sind da nur messages von pmg-smtp-filter in dem Zeitraum?!

UCR said:
Jun 20 09:54:21 mail pmg-smtp-filter[35586]: A1F9762B027385B86C: processing time: 117.172 seconds (0.784, 0.02, 0)
Click to expand...
117 Sekunden sind eindeutig zu lange - und nachdem es nicht so aussieht als würde es an spamassassin oder am antivirus liegen (die ersten 2 Zahlen in der klammer) - bleibt die frage wo es hängt

* Wie sieht den das `ps auxwf` output aus?
* Steht etwas in den postgresql logs (/var/log/postgresql)
* und steht irgendetwas auffälliges im journal?
 
Stoiko Ivanov said:
nicht wirklich komplett - oder sind da nur messages von pmg-smtp-filter in dem Zeitraum?!
Click to expand...
Ja, nur pmg-smtp-filter
Stoiko Ivanov said:
Wie sieht den das `ps auxwf` output aus?
Click to expand...
Habe ich mal angehängt
Stoiko Ivanov said:
Steht etwas in den postgresql logs (/var/log/postgresql)
Click to expand...
Da finde ich nichts
Stoiko Ivanov said:
und steht irgendetwas auffälliges im journal?
Click to expand...
welches Journal ist denn gemeint und nach welchen Auffälligkeiten sollte ich suchen?
 

Attachments

  • ps_auxwf.txt
    18.7 KB · Views: 2
UCR said:
Da finde ich nichts
Click to expand...
Keine files in dem ordner oder steht im jeweiligen log gar nichts?
- wenn moeglich bitte mal anhaengen.

UCR said:
welches Journal ist denn gemeint und nach welchen Auffälligkeiten sollte ich suchen?
Click to expand...
das system-journal - siehe `man journalctl`

`journalctl --since '2022-06-20' sollte alles seit tagesbeginn listen - das (anonymisiert) hier posten bitte
 
wenns mit zippen auch nicht klein genug wird wuerde sich anbieten den Zeitraum etwas einzugrenzen...

`journalctl --since '2022-06-20 09:45' --until '2022-06-20 10:45' `
 
Ich muss ein wenig raten (da glaube ich etwas sehr grosszuegig sachen durch name1.name2@mydomain.de ersetzt wurden)

aber - ich glaube `mailq` sollte einige mails anzeigen, die gequeued sind:
```
Jun 20 00:27:03 mail postfix/qmgr[911]: 8C90880552: from=<name1.name2@mydomain.de>, size=67844, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: DBF3A800C2: from=<name1.name2@mydomain.de>, size=28265, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: D120A8043C: from=<name1.name2@mydomain.de>, size=41910, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: 5E346821B7: from=<name1.name2@mydomain.de>, size=67705, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: 5C40E806E5: from=<name1.name2@mydomain.de>, size=49375, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: 7CE5A823B4: from=<name1.name2@mydomain.de>, size=73671, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: 170E98043A: from=<name1.name2@mydomain.de>, size=67706, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: 13CFE80433: from=<name1.name2@mydomain.de>, size=54405, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: C636980431: from=<name1.name2@mydomain.de>, size=81886, nrcpt=1 (queue active)
Jun 20 00:27:03 mail postfix/qmgr[911]: E059280428: from=<name1.name2@mydomain.de>, size=78719, nrcpt=1 (queue active)
```

wenn ich das log richtig interpretiere sind ein teil dieser mails für die Hänger verantwortlich - die könnten aus der postfix-queue (/var/spool/postfix/..) heraus mal mit `spamassassin -Dall < /path/to/mail/in/queue) analysiert werden - vielleicht zeigt sich da war warum so lange dauert)

haben die mails irgendetwas gemeinsam?
 
mailq zeigt 6 Einträge:
Code: 
-Queue ID-  --Size-- ----Arrival Time---- -Sender/Recipient-------
05BE5822B4*   48927 Tue Jun 21 14:17:03  202206211216564783c1f2a507465babf4b00b9240p0eu-C1N7BPP2IWLHN@bounces.amazon.de
                                         ucr@int.de
05462823A1*   48919 Tue Jun 21 14:18:09  2022062112180330af9a1f8d22451eb0726d9c9450p0eu-C1N7BPP2IWLHN@bounces.amazon.de
                                         ucr@int.de
90A33822E5*   81341 Tue Jun 21 13:28:49  s-2mjcoavoghn9dcpq3s32ad22n5mllzcdcephk13iaocrozvkh6yi6at2@bounce.linkedin.com
                                         ucr@int.de
7ED9F806CD   189903 Tue Jun 21 11:11:56  20220621091149b868e3bc42b64afea5e81276ceb0p0eu-C1B63KDBWCSP80@bounces.amazon.de
(conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
                                         ucr@int.de
A17E5805FE    43497 Tue Jun 21 11:11:15  20220621091108556023ac36f1433481246eab8510p0eu-C25KF7NHG2JTPU@bounces.amazon.de
(conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
                                         ucr@int.de
A83F280802    41086 Tue Jun 21 11:25:50  20220621092549884c6a2701f34e52858a41769a40p0eu-C25KF7NHG2JTPU@bounces.amazon.de
(conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once)
                                         ucr@int.de
-- 443 Kbytes in 6 Requests.

spamassassin -Dall /var/spool/postfix/defer/8/8C90880552
listet mehrere Seiten Infos auf, hier mal die letzten Zeilen:

Code: 
This is a multi-part message in MIME format.

------------=_62B1B4C0.058AAF0B
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: 8bit

Spam detection software, running on the system "mail.domain.de",
has identified this incoming email as possible spam.  The original
message has been attached to this so you can view it or label
similar future email.  If you have any questions, see
the administrator of that system for details.

Content preview:  <n1.n2@domain.de>: conversation with 127.0.0.1[127.0.0.1]
   timed out while sending end of data -- message may be sent more than once
   recipient=n1.n2@domain.de offs [...]

Content analysis details:   (5.8 points, 5.0 required)

 pts rule name              description
---- ---------------------- --------------------------------------------------
 0.2 KAM_BLANKSUBJECT       Message has a blank Subject
-0.0 NO_RELAYS              Informational: message was not relayed via SMTP
 1.2 MISSING_HEADERS        Missing To: header
 1.8 MISSING_SUBJECT        Missing Subject: header
-0.0 T_SCC_BODY_TEXT_LINE   No description available.
 0.0 KAM_DMARC_STATUS       Test Rule for DKIM or SPF Failure with Strict
                            Alignment
-0.0 NO_RECEIVED            Informational: message has no Received headers
 0.1 MISSING_MID            Missing Message-Id: header
 1.4 MISSING_DATE           Missing Date: header
 1.0 MISSING_FROM           Missing From: header
 0.0 NO_HEADERS_MESSAGE     Message appears to be missing most RFC-822
                            headers

------------=_62B1B4C0.058AAF0B
Content-Type: message/rfc822; x-spam-type=original
Content-Description: original message before SpamAssassin
Content-Disposition: inline
Content-Transfer-Encoding: 8bit

<n1.n2@domain.de>: conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once
recipient=n1.n2@domain.de
offset=872
dsn_orig_rcpt=rfc822;n1.n2@domain.de
status=4.4.2
action=delayed
reason=conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once

------------=_62B1B4C0.058AAF0B--

Jun 21 14:08:32.896 [97782] dbg: check: tagrun - tag DKIMDOMAIN is still blocking action 0
Jun 21 14:08:32.896 [97782] dbg: check: tagrun - tag AUTHORDOMAIN is still blocking action 2
Jun 21 14:08:32.896 [97782] dbg: check: tagrun - tag SENDERDOMAIN is still blocking action 1
Jun 21 14:08:32.896 [97782] dbg: check: tagrun - tag LASTEXTERNALHELO is still blocking action 3
Jun 21 14:08:32.896 [97782] dbg: plugin: Mail::SpamAssassin::Plugin::MIMEHeader=HASH(0x5593d30b4aa8) implements 'finish_tests', priority 0
Jun 21 14:08:32.896 [97782] dbg: plugin: Mail::SpamAssassin::Plugin::Check=HASH(0x5593d2513550) implements 'finish_tests', priority 0
 
Last edited:
UCR said:
spamassassin -Dall /var/spool/postfix/defer/8/8C90880552
Click to expand...
sorry - hatte vergessen/übersehen, dass die spoolfiles ja nicht nur den body+header enthalten sondern auch meta-informationen.
(und das ist in /var/spool/postfix/deferred (mit 'ed' hinten dran ))

das tatsächliche mail sollte sich mittels `postcat -bh /var/spool/postfix/defered/8/8C90880552 > testmail.eml
dieses dann in spamassassin reinfüttern - beachte das '<'
`spamassassin -D all < testmail.eml`

Die Frage ist wie lange das dauert? (1-2 Sekunden oder eher im 10-60 Sekunden bereich?)

UCR said:
listet mehrere Seiten Infos auf,
Click to expand...
die wären potentiell auch hilfreich - vielleicht in ein file umleiten und mit gzip komprimieren.

Ich hoffe das hilft!
 
Sorry, ich war sehr mit anderen Dingen beschäftigt und konnte mich bisher nicht weiter um dieses Problem kümmern.

Letzte Woche habe ich festgestellt, dass unter htop die prozesse 'pmg-smtp-filter child' das system mit 2 cpu permanent zu 100% auslasten.
Möglicherweise kommt daher auch zu den timeouts.

Ich habe einige Probleme im Internet gefunden, die auf falsche dns Einstellungen zurückzuführen waren.
In der resolv.conv war bisher das default gateway 192.168.20.1 eingetragen.

Ein Änderung auf 1.1.1.1 hat dazu geführt, das alle eingehenden mails geblockt wurden.
.... listed by domain sbl-xbl.spamhaus.org as 127.255.255.254

Eine dns Auflösung funktioniert aber ohne Probleme mit beiden name server ip.
nslookup spamhaus.org 192.168.20.1
nslookup spamhaus.org 1.1.1.1

Screenshot_6.png
 
Hi, ich denke ich habe das Problem gestern gefunden und behoben.

In der white- und blacklist habe ich alle regex Einträge optimiert und teilweise entfernt.
Schon ein Ausdruck .*\.ru benötigt lt. regex101.com nur rund 5% der Schritte im Gegensatz zu dem vorherigen \S*\.ru

Der Fehler (conversation with 127.0.0.1[127.0.0.1] timed out while sending end of data -- message may be sent more than once) tritt nun auch nicht mehr auf und doppelte Mails bekommen wir auch nicht mehr.

Hier die aktuelle System Auslastung der letzten 24 Stunden, auf der der Unterschied vorher/nacher ersichtlich wird.
Screenshot_7.png
 
  • Like
Reactions: Stoiko Ivanov
You must log in or register to reply here.

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back