Всем привет! Имеется созданный файл recipient_bcc и подключен в Postfix, письма дублируются, все успешно.
Однако к одному пользователю, пусть будет lololo@DOMAIN2 может придти две копии одного письма. Пытаюсь отловить кто виноват, но не могу.
Получаю почту с внешних imap-серверов c помощью fetchmail, затем ее принимает связка postfix-dovecot-amavis-SA-Roundcube, обслуживают два домена: DOMAIN1 и DOMAIN2.
содержимое файла recipient_bcc:
someuser@DOMAIN1 someuser@DOMAIN2
lololo@DOMAIN1 lololo@DOMAIN2
....
и еще несколько записей, которые не ведут на lololo@somedomain2.ru
Что может заставить postfix дважды отправить одно письмо? Как диагностировать такое поведение?
Кусок лога для такого письма:
Jul 2 11:45:17 mail postfix/postscreen[20257]: CONNECT from [127.0.0.1]:38294 to [127.0.0.1]:25
Jul 2 11:45:17 mail postfix/postscreen[20257]: WHITELISTED [127.0.0.1]:38294
Jul 2 11:45:17 mail postfix/smtpd[20258]: connect from localhost[127.0.0.1]
Jul 2 11:45:17 mail postfix/postscreen[20257]: CONNECT from [127.0.0.1]:38298 to [127.0.0.1]:25
Jul 2 11:45:17 mail postfix/postscreen[20257]: WHITELISTED [127.0.0.1]:38298
Jul 2 11:45:17 mail postfix/smtpd[20260]: connect from localhost[127.0.0.1]
Jul 2 11:45:17 mail postfix/smtpd[20260]: disconnect from localhost[127.0.0.1] helo=1 mail=1 quit=1 commands=3
Jul 2 11:45:17 mail postfix/smtpd[20258]: disconnect from localhost[127.0.0.1] ehlo=1 rset=1 quit=1 commands=3
Jul 2 11:45:18 mail postfix/postscreen[20257]: CONNECT from [127.0.0.1]:38310 to [127.0.0.1]:25
Jul 2 11:45:18 mail postfix/postscreen[20257]: WHITELISTED [127.0.0.1]:38310
Jul 2 11:45:18 mail postfix/smtpd[20260]: connect from localhost[127.0.0.1]
Jul 2 11:45:18 mail postfix/smtpd[20260]: EE5003088856: client=localhost[127.0.0.1]
Jul 2 11:45:19 mail postfix/cleanup[20269]: EE5003088856: message-id=<1343347328.510716.1562053430221.JavaMail.tomcat55@ugr-back-notifier2>
Jul 2 11:45:19 mail postfix/qmgr[13877]: EE5003088856: from=<merchants@yamoney.ru>, size=12685, nrcpt=2 (queue active)
Jul 2 11:45:19 mail postfix/smtpd[20260]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Jul 2 11:45:20 mail postfix/10025/smtpd[20285]: connect from localhost[127.0.0.1]
Jul 2 11:45:20 mail postfix/10025/smtpd[20286]: connect from localhost[127.0.0.1]
Jul 2 11:45:20 mail postfix/10025/smtpd[20285]: 57E793088857: client=localhost[127.0.0.1]
Jul 2 11:45:20 mail postfix/cleanup[20269]: 57E793088857: message-id=<1343347328.510716.1562053430221.JavaMail.tomcat55@ugr-back-notifier2>
Jul 2 11:45:20 mail postfix/10025/smtpd[20286]: 616983088858: client=localhost[127.0.0.1]
Jul 2 11:45:20 mail postfix/cleanup[20288]: 616983088858: message-id=<1343347328.510716.1562053430221.JavaMail.tomcat55@ugr-back-notifier2>
Jul 2 11:45:20 mail postfix/10025/smtpd[20285]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Jul 2 11:45:20 mail postfix/qmgr[13877]: 616983088858: from=<merchants@yamoney.ru>, size=14305, nrcpt=1 (queue active)
Jul 2 11:45:20 mail postfix/qmgr[13877]: 57E793088857: from=<merchants@yamoney.ru>, size=14297, nrcpt=1 (queue active)
Jul 2 11:45:20 mail amavis[16664]: (16664-10) Passed CLEAN {RelayedInternal}, MYNETS LOCAL [127.0.0.1]:38310 [77.75.154.204] <merchants@yamoney.ru> -> <lololo@DOMAIN1>, Queue-ID: EE5003088856, Message-ID: <1343347328.510716.1562053430221.JavaMail.tomcat55@ugr-back-notifier2>, mail_id: UM4M48D-pW-f, Hits: 4.124, size: 12684, queued_as: 57E793088857, dkim_sd=mail:yamoney.ru, dkim_new=dkim:DOMAIN1, 1241 ms, Tests: тут тесты
Jul 2 11:45:20 mail postfix/10025/smtpd[20286]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Jul 2 11:45:20 mail postfix/amavis/smtp[20278]: EE5003088856: to=<lololo@DOMAIN1>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.6, delays=0.27/0.03/0/1.3, 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 57E793088857)
Jul 2 11:45:20 mail amavis[17232]: (17232-11) Passed CLEAN {RelayedInternal}, MYNETS LOCAL [127.0.0.1]:38310 [77.75.154.204] <merchants@yamoney.ru> -> <lololo@DOMAIN2>, Queue-ID: EE5003088856, Message-ID: <1343347328.510716.1562053430221.JavaMail.tomcat55@ugr-back-notifier2>, mail_id: HQM4G06xGdhJ, Hits: 4.124, size: 12684, queued_as: 616983088858, dkim_sd=mail:yamoney.ru, dkim_new=dkim:DOMAIN1, 1304 ms, Tests: [и тут тесты]
Jul 2 11:45:20 mail postfix/amavis/smtp[20277]: EE5003088856: to=<lololo@DOMAIN2>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.6, delays=0.27/0.01/0/1.4, 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 616983088858)
Jul 2 11:45:20 mail postfix/qmgr[13877]: EE5003088856: removed
Jul 2 11:45:21 mail postfix/pipe[20290]: 57E793088857: to=<lololo@DOMAIN1>, relay=dovecot, delay=0.82, delays=0.13/0.08/0/0.61, dsn=2.0.0, status=sent (delivered via dovecot service)
Jul 2 11:45:21 mail postfix/qmgr[13877]: 57E793088857: removed
Jul 2 11:45:21 mail postfix/pipe[20289]: 616983088858: to=<lololo@DOMAIN2>, relay=dovecot, delay=0.83, delays=0.11/0.07/0/0.65, dsn=2.0.0, status=sent (delivered via dovecot service)
Jul 2 11:45:21 mail postfix/qmgr[13877]: 616983088858: removed
