Почтовый транспорт
Описано большинство сценариев обычного хождения почты, кроме возврата с fallback.
Письмо внешнее, пришло на MX
Когда письмо приходит на MX, в логах появляется такое событие:
onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 40 -> 1007 1otTS4-0000GF-6Y <= a.lubin@msexchange.onpremise.email H=(e.demomail.onpremise.email) [109.120.188.18]:47870 I=[172.20.5.38]:2525 P=esmtp S=2800 SPAMSIGN=0 REC=1 TRUST=-1 id=1668170887.571627114@fmail1.qdit for commn@kaspersky.onprem.ru
- a.lubin@msexchange.onpremise.email - адрес отправителя
- commn@kaspersky.onprem.ru - адрес получателя (в нашей системе)
Греп по ID дает следующую картину:
journalctl -fu onpremise-container-* --since '5 minutes ago' | grep 1otTS4-0000GF-6Y
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 40 -> 1007 1otTS4-0000GF-6Y avscan: result no av found, forcing AV_DEFER
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 40 -> 1007 1otTS4-0000GF-6Y AV_CHECK: result DEFER
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 40 -> 1007 1otTS4-0000GF-6Y KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 40 -> 1007 1otTS4-0000GF-6Y <= a.lubin@msexchange.onpremise.email H=(e.demomail.onpremise.email) [109.120.188.18]:47870 I=[172.20.5.38]:2525 P=esmtp S=2800 SPAMSIGN=0 REC=1 TRUST=-1 id=1668170887.571627114@fmail1.qdit for commn@kaspersky.onprem.ru
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx-fakesmtpdgo1[1495395]: smtpd STATUS: from a.lubin@msexchange.onpremise.email to commn@kaspersky.onprem.ru. result=250 (OK id=1otTS4-0000GF-6Y) [peer:109.120.188.18:47870]
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx-fakesmtpdgo1[1495395]: 2022/11/11 15:48:08 result=passed (NONE), ip=109.120.188.18, code=250, status=OK id=1otTS4-0000GF-6Y, from=<a.lubin@msexchange.onpremise.email>, rcpt=<commn@kaspersky.onprem.ru>, ehlo=e.demomail.onpremise.email, mru_geo=RU, mru_p0f=off, mru_nr=1, mru_bl=off, chk_t=-1.00000, ses_t=-1.00000, port=47870
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx-fakesmtpdgo1[1495395]: smtpd sending: 250 OK id=1otTS4-0000GF-6Y [peer:109.120.188.18:47870]
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 40 -> 1007 1otTS4-0000GF-6Y RECEIVE_TIMINGS: TOTAL=0.352 DATABASE=0.005 LS=0.008 LSSPAM=0.000 LSVIRUS=0.000 CAPRON=0.006 DNS=0.248 DKIM=0.000 DOMAIN=0.003 LOG_WRITE=0.000
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.1:7500' (1/2) with timeout `1000' ms
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-del1[1025370]: [47.553.172.20.5.38:39702] store [warn]: delivery res: delivery res=ok ('ok'), iprohdr='[msg=0,len=396,sync=1]', hsz='392', type='exim_local', exim_message_id='1otTS4-0000GF-6Y', email='commn@kaspersky.onprem.ru', fsize='2678b', st_size='2769b', st='127.0.0.3:|1|3|3|commn@kaspersky.onprem.ru|1552|', uidl='16681708882046717111', zepto_id='(b:1;r:2330865)', msgflags='0', folderid='0', resp_sz='81'
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.1:7500'
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (3) *ok*, store_stage_real: 0, uidl: 16681708882046717111
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y kafka govlog: disabled by config
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y kafka govlog: disabled by config
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y [DWH] mail_receive||mx||1668170888||a.lubin@msexchange.onpremise.email||109.120.188.18||commn@kaspersky.onprem.ru||0||16681708882046717111||0||a.lubin@msexchange.onpremise.email||||<1668170887.571627114@fmail1.qdit>||||1otTS4-0000GF-6Y [/DWH]
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1008 -> 1010 1otTS4-0000GF-6Y DELIVERY_TIMINGS: TOTAL=0.066 DATABASE=0.002 CAPRON=0.003 LOG_WRITE=0.000
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1 -> 1008 1otTS4-0000GF-6Y => commn <commn@kaspersky.onprem.ru> F=<a.lubin@msexchange.onpremise.email> R=mpop_router T=mpop_transport S=2047
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1 -> 1008 1otTS4-0000GF-6Y TR=L TIME=0 COUNT=1 Q=0
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1 -> 1008 1otTS4-0000GF-6Y Deliver completed
Nov 11 15:48:08 redos-kasper-mail.novalocal onpremise-container-mx1[1492504]: 2022-11-11 15:48:08 1 -> 1008 1otTS4-0000GF-6Y PARENT_TIMINGS: TOTAL=0.074 DATABASE=0.002 CAPRON=0.002 DOMAIN=0.001 LOG_WRITE=0.000
Nov 11 15:48:44 redos-kasper-mail.novalocal onpremise-container-del-aestat1[1027743]: [2022-11-11 15:48:44] 11 I last processed line (deliveryd) : '[47.553.172.20.5.38:39702] store [warn]: delivery res: delivery res=ok ('ok'), iprohdr='[msg=0,len=396,sync=1]', hsz='392', type='exim_local', exim_message_id='1otTS4-0000GF-6Y', email='commn@kaspersky.onprem.ru', fsize='2678b', st_size='2769b', st='127.0.0.3:|1|3|3|commn@kaspersky.onprem.ru|1552|', uidl='16681708882046717111', zepto_id='(b:1;r:2330865)', msgflags='0', folderid='0', resp_sz='81''
Nov 11 15:49:00 redos-kasper-mail.novalocal onpremise-container-mx-aestat1[1495391]: [2022-11-11 15:49:00] 12 I last processed line (mx) : '2022-11-11 15:48:08 1 -> 1008 1otTS4-0000GF-6Y PARENT_TIMINGS: TOTAL=0.074 DATABASE=0.002 CAPRON=0.002 DOMAIN=0.001 LOG_WRITE=0.000'
- onpremise-container-mx1
- onpremise-container-mx-fakesmtpdgo1
- onpremise-container-del-aestat1
- onpremise-container-mx-aestat1
Письмо внутреннее, ушло c SMTP
При отправке письма "толстым" клиентом в логах контейнера smtp1 видим следующее:
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 Accepted SMTP connection from 109.120.188.18:59874 to 172.20.5.45:2535
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 XHDR: Auth-User: zaraysky@demomail.onpremise.email\r\nClient-IP: 95.84.164.106\r\nClient-Port: 60982\r\nAuth-User-ID: 14\r\nAuth-Protocol: plain\r\n
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 SMTP secured user <zaraysky@demomail.onpremise.email> auth success from ip [95.84.164.106] smtp visited [1] sec_visited [1]
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 xhdr auth: success
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 password change checker failed: Error response: r = -1
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 password change checker failed: Error response: r = -1
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 password change checker failed: Error response: r = -1
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D avscan: result no av found, forcing AV_DEFER
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D AV_CHECK: result DEFER
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D <= zaraysky@demomail.onpremise.email H=broadband-95-84-164-106.ip.moscow.rt.ru ([192.168.129.134]) [95.84.164.106]:60982 I=[172.20.5.45]:2535 P=esmtpa A=plain:zaraysky@demomail.onpremise.email S=997 SPAMSIGN=0 REC=1 TRUST=-1 id=e95c4ef9-7d32-99ee-61f3-3cdf1c3fe952@demomail.onpremise.email for i.testov@kaspersky.onprem.ru
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D RECEIVE_TIMINGS: TOTAL=0.115 DATABASE=0.014 LS=0.013 LSSPAM=0.000 LSVIRUS=0.000 CAPRON=0.020 DNS=0.002 DOMAIN=0.007 LOG_WRITE=0.000
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 password change checker failed: Error response: r = -1
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 SMTP connection from broadband-95-84-164-106.ip.moscow.rt.ru ([192.168.129.134]) [95.84.164.106]:60982 I=[172.20.5.45]:2535 closed by QUIT
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D unable to open private key file for reading: /usr/exim/conf/dkim/mail4/demomail.onpremise.email.private.key
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D unable to open private key file for reading: /usr/exim/conf/dkim/mail4/demomail.onpremise.email.private.key
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D unable to open private key file for reading: /usr/exim/conf/dkim/mail4/demomail.onpremise.email.private.key
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D kafka govlog: disabled by config
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D [DWH] remote_send||smtp||1668172534||zaraysky@demomail.onpremise.email||95.84.164.106||i.testov@kaspersky.onprem.ru [/DWH]
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D REMOTE_DELIVERY_TIMINGS: TOTAL=0.035 CAPRON=0.002 LOG_WRITE=0.001
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D => i.testov@kaspersky.onprem.ru F=<zaraysky@demomail.onpremise.email> R=dnslookup T=remote_smtp S=1020 H=kasmail.onprem.ru [89.208.229.27] X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 C="250 OK id=1otTsc-0000Gf-6I"
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D TR=R TIME=0 COUNT=1 Q=0
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D Deliver completed
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D PARENT_TIMINGS: TOTAL=0.047 CAPRON=0.001 DNS=0.002 DOMAIN=0.001 LOG_WRITE=0.000
Выделен ID сообщения 1otTsc-0001uK-2D, который был присвоен письму.
- zaraysky@demomail.onpremise.email - адрес отправителя (в нашей системе)
- i.testov@kaspersky.onprem.ru - адрес получателя
Греп по ID по всем логам дает следующую картину:
journalctl -fu onpremise-container-* --since '5 minutes ago' | grep 1otTsc-0001uK-2D
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D avscan: result no av found, forcing AV_DEFER
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D AV_CHECK: result DEFER
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D <= zaraysky@demomail.onpremise.email H=broadband-95-84-164-106.ip.moscow.rt.ru ([192.168.129.134]) [95.84.164.106]:60982 I=[172.20.5.45]:2535 P=esmtpa A=plain:zaraysky@demomail.onpremise.email S=997 SPAMSIGN=0 REC=1 TRUST=-1 id=e95c4ef9-7d32-99ee-61f3-3cdf1c3fe952@demomail.onpremise.email for i.testov@kaspersky.onprem.ru
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 40 -> 7336 1otTsc-0001uK-2D RECEIVE_TIMINGS: TOTAL=0.115 DATABASE=0.014 LS=0.013 LSSPAM=0.000 LSVIRUS=0.000 CAPRON=0.020 DNS=0.002 DOMAIN=0.007 LOG_WRITE=0.000
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D unable to open private key file for reading: /usr/exim/conf/dkim/mail4/demomail.onpremise.email.private.key
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D unable to open private key file for reading: /usr/exim/conf/dkim/mail4/demomail.onpremise.email.private.key
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D unable to open private key file for reading: /usr/exim/conf/dkim/mail4/demomail.onpremise.email.private.key
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D kafka govlog: disabled by config
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D [DWH] remote_send||smtp||1668172534||zaraysky@demomail.onpremise.email||95.84.164.106||i.testov@kaspersky.onprem.ru [/DWH]
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 7337 -> 7339 1otTsc-0001uK-2D REMOTE_DELIVERY_TIMINGS: TOTAL=0.035 CAPRON=0.002 LOG_WRITE=0.001
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D => i.testov@kaspersky.onprem.ru F=<zaraysky@demomail.onpremise.email> R=dnslookup T=remote_smtp S=1020 H=kasmail.onprem.ru [89.208.229.27] X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 C="250 OK id=1otTsc-0000Gf-6I"
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D TR=R TIME=0 COUNT=1 Q=0
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D Deliver completed
Nov 11 16:15:34 demo-mail.novalocal onpremise-container-smtp1[9202]: 2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D PARENT_TIMINGS: TOTAL=0.047 CAPRON=0.001 DNS=0.002 DOMAIN=0.001 LOG_WRITE=0.000
Nov 11 16:15:39 demo-mail.novalocal onpremise-container-smtp-aestat1[23231]: [2022-11-11 16:15:39] 13 I last processed line (smtp) : '2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D Deliver completed'
Nov 11 16:16:09 demo-mail.novalocal onpremise-container-smtp-aestat1[23231]: [2022-11-11 16:16:09] 16 I last processed line (smtp) : '2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D TR=R TIME=0 COUNT=1 Q=0'
Nov 11 16:16:31 demo-mail.novalocal onpremise-container-smtp-aestat1[23231]: [2022-11-11 16:16:31] 14 I last processed line (smtp) : '2022-11-11 16:15:34 1 -> 7337 1otTsc-0001uK-2D PARENT_TIMINGS: TOTAL=0.047 CAPRON=0.001 DNS=0.002 DOMAIN=0.001 LOG_WRITE=0.000'
В логах упоминаются следующие контейнеры:
- onpremise-container-smtp1
- onpremise-container-smtp-aestat1
Письмо внешнее, отправлено в WEB-клиента
За работу с веб-интерфейсом отвечает panda, смотрим в логах контейнера panda1:
отправка сообщения (?)
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022/11/14 09:41:46 [I] [1f86371e32a]: request has been received, client ip: 172.20.5.9:53332
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l api_delivery_canceller_host: NULL
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l host: panda1.qdit
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l avscan: result no av found, forcing AV_DEFER
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l AV_CHECK: result DEFER
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l <= i.testov@kaspersky.onprem.ru H=[95.84.164.106] U=root P=local S=2163 SPAMSIGN=0 REC=1 TRUST=0 id=1668408106.537306771@fmail1.qdit for zaraysky@demo.onpremise.email
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l RECEIVE_TIMINGS: TOTAL=0.007 LS=0.003 LSSPAM=0.000 LSVIRUS=0.000 CAPRON=0.001 DOMAIN=0.003 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118735 1ouTAA-000Ut3-9l PARENT_TIMINGS: TOTAL=0.003
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022/11/14 09:41:46 [I] [1f86371e32a]: response message id: 1ouTAA-000Ut3-9l, hostname: panda1.qdit
покладка в папку "отправленные" (?)
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 api_delivery_canceller_host: NULL
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 host: panda1.qdit
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 <= i.testov@kaspersky.onprem.ru H=[95.84.164.106] U=root P=local S=2033 SPAMSIGN=0 REC=1 TRUST=0 id=1668408106.537306771@fmail1.qdit for i.testov@kaspersky.onprem.ru
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 RECEIVE_TIMINGS: TOTAL=0.004 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (mb_mail.c:4027): check can use deliveryd to_sent: true: jig=1000, users='', st='' for i.testov@kaspersky.onprem.ru (127.0.0.1)
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.1:7500' (1/2) with timeout `1000' ms
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.1:7500'
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16684081060016725069
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [info] (mb_mail.c:5057): store to sent folder (new storing enabled is 1, size is 1 Kb, email: i.testov@kaspersky.onprem.ru, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk3/358/i.testov@kaspersky.onprem.ru') time: 62774 mksecs
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 kafka govlog: disabled by config
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 [DWH] sentmsg_exim||fe||1668408106||i.testov@kaspersky.onprem.ru||95.84.164.106||i.testov@kaspersky.onprem.ru||0||16684081060016725069||500000||i.testov@kaspersky.onprem.ru||||<1668408106.537306771@fmail1.qdit>||||1ouTAA-000Ut7-B7 [/DWH]
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 DELIVERY_TIMINGS: TOTAL=0.068 DATABASE=0.002 CAPRON=0.002 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 => i.testov <i.testov@kaspersky.onprem.ru> F=<i.testov@kaspersky.onprem.ru> R=mpop_router_sent T=mpop_transport S=795
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 TR=L TIME=0 COUNT=1 Q=0
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 Deliver completed
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 PARENT_TIMINGS: TOTAL=0.074 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022/11/14 09:41:46 [I] [1f86371e32a-sent]: response message id: 1ouTAA-000Ut7-B7, hostname: panda1.qdit
Выделены ID сообщения, которые были присвоены письму:
- 1ouTAA-000Ut3-9l
- 1ouTAA-000Ut7-B7
Адреса:
- i.testov@kaspersky.onprem.ru - адрес отправителя (в нашей системе)
- zaraysky@demo.onpremise.email - адрес получателя
Греп по ID 1ouTAA-000Ut3-9l по всем логам дает следующую картину:
# journalctl -fu onpremise-container-* --since '5 minutes ago' | grep 1ouTAA-000Ut3-9l
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l api_delivery_canceller_host: NULL
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l host: panda1.qdit
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l avscan: result no av found, forcing AV_DEFER
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l AV_CHECK: result DEFER
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l <= i.testov@kaspersky.onprem.ru H=[95.84.164.106] U=root P=local S=2163 SPAMSIGN=0 REC=1 TRUST=0 id=1668408106.537306771@fmail1.qdit for zaraysky@demo.onpremise.email
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l RECEIVE_TIMINGS: TOTAL=0.007 LS=0.003 LSSPAM=0.000 LSVIRUS=0.000 CAPRON=0.001 DOMAIN=0.003 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118733 1ouTAA-000Ut3-9l PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118735 1ouTAA-000Ut3-9l PARENT_TIMINGS: TOTAL=0.003
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022/11/14 09:41:46 [I] [1f86371e32a]: response message id: 1ouTAA-000Ut3-9l, hostname: panda1.qdit
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-mpop1[1371215]: [1f86371e32a]: 09:41:46.325923 [I] response message id: 1ouTAA-000Ut3-9l, hostname: panda1.qdit
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-mpop1[1371215]: 2022-11-14T09:41:46.327 I 503 i.testov@kaspersky.onprem.ru f5d662b79e >>> Sendmail log message id: 1ouTAA-000Ut3-9l
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda-delivery-canceller1[1086722]: 2022/11/14 09:42:06 [reqid=6853e58119] calling exim [pid: 143]: /usr/exim/bin/exim -mlmip 3 -midd -M 1ouTAA-000Ut3-9l
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 143 -> 145 1ouTAA-000Ut3-9l unable to open private key file for reading: /usr/exim/conf/dkim/mail4/kasmail.onprem.ru.private.key
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 143 -> 145 1ouTAA-000Ut3-9l unable to open private key file for reading: /usr/exim/conf/dkim/mail4/kasmail.onprem.ru.private.key
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 143 -> 145 1ouTAA-000Ut3-9l kafka govlog: disabled by config
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 143 -> 145 1ouTAA-000Ut3-9l [DWH] remote_send||fe||1668408126||i.testov@kaspersky.onprem.ru||95.84.164.106||zaraysky@demo.onpremise.email [/DWH]
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 143 -> 145 1ouTAA-000Ut3-9l REMOTE_DELIVERY_TIMINGS: TOTAL=0.586 CAPRON=0.001 LOG_WRITE=0.000
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 1 -> 143 1ouTAA-000Ut3-9l => zaraysky@demo.onpremise.email F=<i.testov@kaspersky.onprem.ru> R=dnslookup T=remote_smtp S=2014 H=demomail.onpremise.email [109.120.188.18] X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 C="250 OK id=1ouTAU-00026P-Nm"
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 1 -> 143 1ouTAA-000Ut3-9l TR=R TIME=20 COUNT=1 Q=2
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 1 -> 143 1ouTAA-000Ut3-9l Deliver completed
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:42:06 1 -> 143 1ouTAA-000Ut3-9l PARENT_TIMINGS: TOTAL=0.848 CAPRON=0.001 DNS=0.253 DOMAIN=0.002 LOG_WRITE=0.000
Nov 14 09:42:06 redos-kasper-mail.novalocal onpremise-container-panda-delivery-canceller1[1086722]: 2022/11/14 09:42:06 [reqid=6853e58119] exim stderr/stdout output: 2022-11-14 09:42:06 143 -> 145 1ouTAA-000Ut3-9l unable to open private key file for reading: /usr/exim/conf/dkim/mail4/kasmail.onprem.ru.private.key
Nov 14 09:42:37 redos-kasper-mail.novalocal onpremise-container-panda-aestat1[1086720]: [2022-11-14 09:42:36] 12 I last processed line (panda) : '2022-11-14 09:42:06 1 -> 143 1ouTAA-000Ut3-9l PARENT_TIMINGS: TOTAL=0.848 CAPRON=0.001 DNS=0.253 DOMAIN=0.002 LOG_WRITE=0.000'
В логах упоминаются следующие контейнеры:
- onpremise-container-panda1
- onpremise-container-mpop1
- onpremise-container-panda-delivery-canceller1
- onpremise-container-panda-aestat1
Греп по ID 1ouTAA-000Ut7-B7 по всем логам дает следующую картину:
# journalctl -fu onpremise-container-* --since '15 minutes ago' | grep 1ouTAA-000Ut7-B7
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 api_delivery_canceller_host: NULL
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 host: panda1.qdit
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 <= i.testov@kaspersky.onprem.ru H=[95.84.164.106] U=root P=local S=2033 SPAMSIGN=0 REC=1 TRUST=0 id=1668408106.537306771@fmail1.qdit for i.testov@kaspersky.onprem.ru
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 RECEIVE_TIMINGS: TOTAL=0.004 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 53 -> 118737 1ouTAA-000Ut7-B7 PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-del1[1025370]: [48.162.172.20.5.5:44228] store [warn]: delivery res: delivery res=ok ('ok'), iprohdr='[msg=0,len=305,sync=1]', hsz='301', type='exim_to_sent', exim_message_id='1ouTAA-000Ut7-B7', email='i.testov@kaspersky.onprem.ru', fsize='1521b', st_size='1530b', st='127.0.0.3:|1|3|2|i.testov@kaspersky.onprem.ru|1552|', uidl='16684081060016725069', zepto_id='(b:1;r:3961415)', needed_msgflags='65540', msgflags='65550', folderid='500000', resp_sz='81'
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (mb_mail.c:4027): check can use deliveryd to_sent: true: jig=1000, users='', st='' for i.testov@kaspersky.onprem.ru (127.0.0.1)
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.1:7500' (1/2) with timeout `1000' ms
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.1:7500'
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16684081060016725069
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 store [info] (mb_mail.c:5057): store to sent folder (new storing enabled is 1, size is 1 Kb, email: i.testov@kaspersky.onprem.ru, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk3/358/i.testov@kaspersky.onprem.ru') time: 62774 mksecs
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 kafka govlog: disabled by config
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 [DWH] sentmsg_exim||fe||1668408106||i.testov@kaspersky.onprem.ru||95.84.164.106||i.testov@kaspersky.onprem.ru||0||16684081060016725069||500000||i.testov@kaspersky.onprem.ru||||<1668408106.537306771@fmail1.qdit>||||1ouTAA-000Ut7-B7 [/DWH]
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 118739 -> 118741 1ouTAA-000Ut7-B7 DELIVERY_TIMINGS: TOTAL=0.068 DATABASE=0.002 CAPRON=0.002 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 => i.testov <i.testov@kaspersky.onprem.ru> F=<i.testov@kaspersky.onprem.ru> R=mpop_router_sent T=mpop_transport S=795
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 TR=L TIME=0 COUNT=1 Q=0
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 Deliver completed
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022-11-14 09:41:46 1 -> 118739 1ouTAA-000Ut7-B7 PARENT_TIMINGS: TOTAL=0.074 LOG_WRITE=0.000
Nov 14 09:41:46 redos-kasper-mail.novalocal onpremise-container-panda1[1084556]: 2022/11/14 09:41:46 [I] [1f86371e32a-sent]: response message id: 1ouTAA-000Ut7-B7, hostname: panda1.qdit
В логах упоминаются следующие контейнеры:
- onpremise-container-panda1
Письмо внутреннее (между доменами), отправлено в WEB-клиента (без аттача)
- Отправитель: zaraysky@demo.onpremise.email
- Получатель: a.lubin@msexchange.onpremise.email
За работу с веб-интерфейсом отвечает panda, смотрим в логах:
покладка в inbox для получателя
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 17:56:13 [I] [ef9636e628d]: request has been received, client ip: 172.20.5.13:49710
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS avscan: result no av found, forcing AV_DEFER
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS AV_CHECK: result DEFER
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS mpop_check.c:1243 capron returns error: 3 ()
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS get sender masks: fail
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS <= zaraysky@demo.onpremise.email H=[95.84.164.106] U=root P=local S=2427 SPAMSIGN=0 REC=1 TRUST=0 id=1668178573.570471992@fmail1.qdit for a.lubin@msexchange.onpremise.email
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS For zaraysky@demo.onpremise.email found dkim_domain demo.onpremise.email. Local recipients: 1
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS RECEIVE_TIMINGS: TOTAL=0.025 DATABASE=0.008 LS=0.015 LSSPAM=0.000 LSVIRUS=0.000 STATISTIC=0.000 CAPRON=0.011 DOMAIN=0.006 LOG_WRITE=0.000
Nov 11 17:56:13 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 54 -> 15792 1otVS1-00046i-TS PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 15794 -> 15796 1otVS1-00046i-TS store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.2:7500' (1/2) with timeout `1000' ms
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:13 15794 -> 15796 1otVS1-00046i-TS store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.2:7500'
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15794 -> 15796 1otVS1-00046i-TS store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (3) *ok*, store_stage_real: 0, uidl: 16681785731763530229
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15794 -> 15796 1otVS1-00046i-TS store [info] (mb_mail.c:5057): store by local_delivery: folder=0, new_store=1, mimeparser=0, size=2 Kb, email=a.lubin@msexchange.onpremise.email, st='127.0.0.1:/var/mail/vdomains/external/_disk03/089/a.lubin@msexchange.onpremise.email', time=76509 mksecs
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15794 -> 15796 1otVS1-00046i-TS kafka govlog: disabled by config
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15794 -> 15796 1otVS1-00046i-TS kafka govlog: disabled by config
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15794 -> 15796 1otVS1-00046i-TS [DWH] mail_receive||fe||1668178574||zaraysky@demo.onpremise.email||95.84.164.106||a.lubin@msexchange.onpremise.email||0||16681785731763530229||0||zaraysky@demo.onpremise.email||"demo.onpremise.email"||<1668178573.570471992@fmail1.qdit>||||1otVS1-00046i-TS [/DWH]
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15794 -> 15796 1otVS1-00046i-TS DELIVERY_TIMINGS: TOTAL=0.092 DATABASE=0.004 STATISTIC=0.000 CAPRON=0.008 DOMAIN=0.002 LOG_WRITE=0.000
покладка в sent для отправителя
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15794 1otVS1-00046i-TS => a.lubin <a.lubin@msexchange.onpremise.email> F=<zaraysky@demo.onpremise.email> R=mpop_router T=mpop_transport S=1462
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15794 1otVS1-00046i-TS TR=L TIME=1 COUNT=1 Q=0
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15794 1otVS1-00046i-TS Deliver completed
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15794 1otVS1-00046i-TS PARENT_TIMINGS: TOTAL=0.112 DATABASE=0.004 CAPRON=0.005 DOMAIN=0.005 LOG_WRITE=0.000
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 17:56:14 [I] [ef9636e628d]: response message id: 1otVS1-00046i-TS, hostname: e.demomail.onpremise.email
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 54 -> 15797 1otVS2-00046n-3I <= zaraysky@demo.onpremise.email H=[95.84.164.106] U=root P=local S=2118 SPAMSIGN=0 REC=1 TRUST=0 id=1668178573.570471992@fmail1.qdit for zaraysky@demo.onpremise.email
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 54 -> 15797 1otVS2-00046n-3I RECEIVE_TIMINGS: TOTAL=0.007 LOG_WRITE=0.000
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 54 -> 15797 1otVS2-00046n-3I PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I store [warn] (mb_mail.c:4027): check can use deliveryd to_sent: true: jig=1000, users='', st='' for zaraysky@demo.onpremise.email (127.0.0.1)
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.2:7500' (1/2) with timeout `1000' ms
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.2:7500'
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16681785741143058426
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I store [info] (mb_mail.c:5057): store to sent folder (new storing enabled is 1, size is 1 Kb, email: zaraysky@demo.onpremise.email, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk03/2F7/zaraysky@demo.onpremise.email') time: 69905 mksecs
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I kafka govlog: disabled by config
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I [DWH] sentmsg_exim||fe||1668178574||zaraysky@demo.onpremise.email||95.84.164.106||zaraysky@demo.onpremise.email||0||16681785741143058426||500000||zaraysky@demo.onpremise.email||||<1668178573.570471992@fmail1.qdit>||||1otVS2-00046n-3I [/DWH]
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 15799 -> 15801 1otVS2-00046n-3I DELIVERY_TIMINGS: TOTAL=0.080 DATABASE=0.006 CAPRON=0.004 LOG_WRITE=0.000
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15799 1otVS2-00046n-3I => zaraysky <zaraysky@demo.onpremise.email> F=<zaraysky@demo.onpremise.email> R=mpop_router_sent T=mpop_transport S=871
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15799 1otVS2-00046n-3I TR=L TIME=0 COUNT=1 Q=0
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15799 1otVS2-00046n-3I Deliver completed
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 17:56:14 1 -> 15799 1otVS2-00046n-3I PARENT_TIMINGS: TOTAL=0.092 LOG_WRITE=0.000
Nov 11 17:56:14 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 17:56:14 [I] [ef9636e628d-sent]: response message id: 1otVS2-00046n-3I, hostname: e.demomail.onpremise.email
Выделен ID сообщения 1otVS1-00046i-TS, который был присвоен письму.
Письмо внутреннее (между доменами), отправлено в WEB-клиента (большой аттач)
- Отправитель: zaraysky@demo.onpremise.email
- Получатель: a.lubin@msexchange.onpremise.email
За работу с веб-интерфейсом отвечает panda, смотрим в логах:
покладка в inbox для получателя
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 18:03:54 [I] [f03636e645a]: request has been received, client ip: 172.20.5.13:45202
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR avscan: result no av found, forcing AV_DEFER
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR AV_CHECK: result DEFER
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR mpop_check.c:1243 capron returns error: 3 ()
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR get sender masks: fail
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR <= zaraysky@demo.onpremise.email H=[95.84.164.106] U=root P=local S=4022 SPAMSIGN=0 REC=1 TRUST=0 id=1668179034.982470557@fmail1.qdit for a.lubin@msexchange.onpremise.email
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR For zaraysky@demo.onpremise.email found dkim_domain demo.onpremise.email. Local recipients: 1
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR RECEIVE_TIMINGS: TOTAL=0.023 DATABASE=0.008 LS=0.014 LSSPAM=0.000 LSVIRUS=0.000 STATISTIC=0.000 CAPRON=0.011 DOMAIN=0.006 LOG_WRITE=0.000
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15900 1otVZS-00048S-OR PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.2:7500' (1/2) with timeout `1000' ms
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.2:7500'
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (3) *ok*, store_stage_real: 0, uidl: 16681790341992424001
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR store [info] (mb_mail.c:5057): store by local_delivery: folder=0, new_store=1, mimeparser=0, size=3 Kb, email=a.lubin@msexchange.onpremise.email, st='127.0.0.1:/var/mail/vdomains/external/_disk03/089/a.lubin@msexchange.onpremise.email', time=77367 mksecs
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR kafka govlog: disabled by config
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR kafka govlog: disabled by config
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR [DWH] mail_receive||fe||1668179034||zaraysky@demo.onpremise.email||95.84.164.106||a.lubin@msexchange.onpremise.email||0||16681790341992424001||0||zaraysky@demo.onpremise.email||"demo.onpremise.email"||<1668179034.982470557@fmail1.qdit>||||1otVZS-00048S-OR [/DWH]
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15902 -> 15904 1otVZS-00048S-OR DELIVERY_TIMINGS: TOTAL=0.088 DATABASE=0.003 STATISTIC=0.000 CAPRON=0.006 DOMAIN=0.002 LOG_WRITE=0.000
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 1 -> 15902 1otVZS-00048S-OR => a.lubin <a.lubin@msexchange.onpremise.email> F=<zaraysky@demo.onpremise.email> R=mpop_router T=mpop_transport S=1654
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 1 -> 15902 1otVZS-00048S-OR TR=L TIME=0 COUNT=1 Q=0
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 1 -> 15902 1otVZS-00048S-OR Deliver completed
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 1 -> 15902 1otVZS-00048S-OR PARENT_TIMINGS: TOTAL=0.106 DATABASE=0.004 CAPRON=0.004 DOMAIN=0.003 LOG_WRITE=0.000
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 18:03:54 [I] [f03636e645a]: response message id: 1otVZS-00048S-OR, hostname: e.demomail.onpremise.email
покладка в sent для отправителя
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15905 1otVZS-00048X-UE <= zaraysky@demo.onpremise.email H=[95.84.164.106] U=root P=local S=3713 SPAMSIGN=0 REC=1 TRUST=0 id=1668179034.982470557@fmail1.qdit for zaraysky@demo.onpremise.email
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15905 1otVZS-00048X-UE RECEIVE_TIMINGS: TOTAL=0.006 LOG_WRITE=0.000
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 54 -> 15905 1otVZS-00048X-UE PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15907 -> 15909 1otVZS-00048X-UE store [warn] (mb_mail.c:4027): check can use deliveryd to_sent: true: jig=1000, users='', st='' for zaraysky@demo.onpremise.email (127.0.0.1)
Nov 11 18:03:54 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15907 -> 15909 1otVZS-00048X-UE store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.2:7500' (1/2) with timeout `1000' ms
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:54 15907 -> 15909 1otVZS-00048X-UE store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.2:7500'
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 15907 -> 15909 1otVZS-00048X-UE store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16681790340537179576
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 15907 -> 15909 1otVZS-00048X-UE store [info] (mb_mail.c:5057): store to sent folder (new storing enabled is 1, size is 3 Kb, email: zaraysky@demo.onpremise.email, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk03/2F7/zaraysky@demo.onpremise.email') time: 69794 mksecs
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 15907 -> 15909 1otVZS-00048X-UE DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 15907 -> 15909 1otVZS-00048X-UE kafka govlog: disabled by config
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 15907 -> 15909 1otVZS-00048X-UE [DWH] sentmsg_exim||fe||1668179035||zaraysky@demo.onpremise.email||95.84.164.106||zaraysky@demo.onpremise.email||0||16681790340537179576||500000||zaraysky@demo.onpremise.email||||<1668179034.982470557@fmail1.qdit>||||1otVZS-00048X-UE [/DWH]
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 15907 -> 15909 1otVZS-00048X-UE DELIVERY_TIMINGS: TOTAL=0.078 DATABASE=0.005 CAPRON=0.003 LOG_WRITE=0.000
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 1 -> 15907 1otVZS-00048X-UE => zaraysky <zaraysky@demo.onpremise.email> F=<zaraysky@demo.onpremise.email> R=mpop_router_sent T=mpop_transport S=1063
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 1 -> 15907 1otVZS-00048X-UE TR=L TIME=1 COUNT=1 Q=0
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 1 -> 15907 1otVZS-00048X-UE Deliver completed
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:03:55 1 -> 15907 1otVZS-00048X-UE PARENT_TIMINGS: TOTAL=0.086 LOG_WRITE=0.000
Nov 11 18:03:55 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 18:03:55 [I] [f03636e645a-sent]: response message id: 1otVZS-00048X-UE, hostname: e.demomail.onpremise.email
Выделены ID сообщения, которые были присвоены письму:
- 1otVZS-00048S-OR
- 1otVZS-00048X-UE
Письмо внутреннее (между доменами), отправлено в WEB-клиента (нормальный аттач)
За работу с веб-интерфейсом отвечает panda, смотрим в логах:
покладка в inbox для получателя
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 18:31:45 [I] [f37636e6ae1]: request has been received, client ip: 172.20.5.13:54892
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD avscan: result no av found, forcing AV_DEFER
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD AV_CHECK: result DEFER
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD KAV8 returned DEFER for 1 times, which is more than limit 1, forcing OK result
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD mpop_check.c:1243 capron returns error: 3 ()
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD get sender masks: fail
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD <= zaraysky@demo.onpremise.email H=[95.84.164.106] U=root P=local S=2823999 SPAMSIGN=0 REC=1 TRUST=0 id=1668180705.603447306@fmail1.qdit for a.lubin@msexchange.onpremise.email
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD For zaraysky@demo.onpremise.email found dkim_domain demo.onpremise.email. Local recipients: 1
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD RECEIVE_TIMINGS: TOTAL=0.060 DATABASE=0.008 LS=0.014 LSSPAM=0.000 LSVIRUS=0.000 STATISTIC=0.000 CAPRON=0.010 DOMAIN=0.005 LOG_WRITE=0.000
Nov 11 18:31:45 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:45 54 -> 16332 1otW0P-0004FQ-UD PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.2:7500' (1/2) with timeout `1000' ms
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.2:7500'
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (3) *ok*, store_stage_real: 0, uidl: 16681807060528059725
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD store [info] (mb_mail.c:5057): store by local_delivery: folder=0, new_store=1, mimeparser=0, size=2757 Kb, email=a.lubin@msexchange.onpremise.email, st='127.0.0.1:/var/mail/vdomains/external/_disk03/089/a.lubin@msexchange.onpremise.email', time=166730 mksecs
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD kafka govlog: disabled by config
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD kafka govlog: disabled by config
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD [DWH] mail_receive||fe||1668180706||zaraysky@demo.onpremise.email||95.84.164.106||a.lubin@msexchange.onpremise.email||1||pdf||16681807060528059725||0||zaraysky@demo.onpremise.email||"demo.onpremise.email"||<1668180705.603447306@fmail1.qdit>||||1otW0P-0004FQ-UD [/DWH]
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16334 -> 16336 1otW0P-0004FQ-UD DELIVERY_TIMINGS: TOTAL=0.179 DATABASE=0.004 STATISTIC=0.000 CAPRON=0.006 DOMAIN=0.002 LOG_WRITE=0.000
покладка в sent для отправителя
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16334 1otW0P-0004FQ-UD => a.lubin <a.lubin@msexchange.onpremise.email> F=<zaraysky@demo.onpremise.email> R=mpop_router T=mpop_transport S=1514
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16334 1otW0P-0004FQ-UD TR=L TIME=1 COUNT=1 Q=0
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16334 1otW0P-0004FQ-UD Deliver completed
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16334 1otW0P-0004FQ-UD PARENT_TIMINGS: TOTAL=0.197 DATABASE=0.004 CAPRON=0.004 DOMAIN=0.004 LOG_WRITE=0.000
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 18:31:46 [I] [f37636e6ae1]: response message id: 1otW0P-0004FQ-UD, hostname: e.demomail.onpremise.email
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 54 -> 16337 1otW0Q-0004FV-7p <= zaraysky@demo.onpremise.email H=[95.84.164.106] U=root P=local S=2823690 SPAMSIGN=0 REC=1 TRUST=0 id=1668180705.603447306@fmail1.qdit for zaraysky@demo.onpremise.email
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 54 -> 16337 1otW0Q-0004FV-7p RECEIVE_TIMINGS: TOTAL=0.041 LOG_WRITE=0.000
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 54 -> 16337 1otW0Q-0004FV-7p PARENT_TIMINGS: TOTAL=0.000 LOG_WRITE=0.000
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p store [warn] (mb_mail.c:4027): check can use deliveryd to_sent: true: jig=1000, users='', st='' for zaraysky@demo.onpremise.email (127.0.0.1)
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.2:7500' (1/2) with timeout `1000' ms
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.2:7500'
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16681807060013278137
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p store [info] (mb_mail.c:5057): store to sent folder (new storing enabled is 1, size is 2756 Kb, email: zaraysky@demo.onpremise.email, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk03/2F7/zaraysky@demo.onpremise.email') time: 173706 mksecs
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p kafka govlog: disabled by config
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p [DWH] sentmsg_exim||fe||1668180706||zaraysky@demo.onpremise.email||95.84.164.106||zaraysky@demo.onpremise.email||0||16681807060013278137||500000||zaraysky@demo.onpremise.email||||<1668180705.603447306@fmail1.qdit>||||1otW0Q-0004FV-7p [/DWH]
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 16339 -> 16341 1otW0Q-0004FV-7p DELIVERY_TIMINGS: TOTAL=0.183 DATABASE=0.004 CAPRON=0.003 LOG_WRITE=0.000
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16339 1otW0Q-0004FV-7p => zaraysky <zaraysky@demo.onpremise.email> F=<zaraysky@demo.onpremise.email> R=mpop_router_sent T=mpop_transport S=923
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16339 1otW0Q-0004FV-7p TR=L TIME=0 COUNT=1 Q=0
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16339 1otW0Q-0004FV-7p Deliver completed
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022-11-11 18:31:46 1 -> 16339 1otW0Q-0004FV-7p PARENT_TIMINGS: TOTAL=0.193 LOG_WRITE=0.000
Nov 11 18:31:46 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/11 18:31:46 [I] [f37636e6ae1-sent]: response message id: 1otW0Q-0004FV-7p, hostname: e.demomail.onpremise.email
Выделены ID сообщений, которые был присвоены:
- 1otW0P-0004FQ-UD
- 1otW0Q-0004FV-7p
Журнальный ключ (log key)
Если присмотреться, в некоторых случаях (в работе через WEB) в логах первой строкой идет такая:
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/14 11:06:38 [I] [fcf6371f70e]: request has been received, client ip: 172.20.5.13:41594
Греп по нему по всем логам даст следующее:
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/14 11:06:38 [I] [fcf6371f70e]: request has been received, client ip: 172.20.5.13:41594
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/14 11:06:38 [I] [fcf6371f70e]: response message id: 1ouUUI-0001Dn-AV, hostname: e.demomail.onpremise.email
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-mpop1[6784]: [fcf6371f70e]: 11:06:38.212314 [D] flags data ready: map[--:[a.lubin@msexchange.onpremise.email] exim-flag-f:[f zaraysky@demo.onpremise.email] exim-flag-i:[i] exim-flag-mal:[mal zaraysky@demo.onpremise.email] exim-flag-mdd:[mdd 0] exim-flag-mip:[mip 95.84.164.106] exim-flag-mlmi:[mlmi] exim-flag-mlmip:[mlmip 3] exim-flag-mqcs:[mqcs Snt4JXjE] exim-flag-oem:[oem] exim-sent-flag-s:[s FfDPTPuO] logkey:[fcf6371f70e] sendto:[zaraysky@demo.onpremise.email]]
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-mpop1[6784]: [fcf6371f70e]: 11:06:38.212428 [D] backend addr from cluster config: panda.qdit:7510
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-mpop1[6784]: [fcf6371f70e]: 11:06:38.237030 [D] backend addr from stream context: 172.20.5.12:7510
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-mpop1[6784]: [fcf6371f70e]: 11:06:38.237069 [I] request to the server: panda.qdit:7510, tls: false, args: [/usr/local/panda/bin/panda-client -mqcs Snt4JXjE -mlmi -mlmip 3 -i -oem -f zaraysky@demo.onpremise.email -mal zaraysky@demo.onpremise.email -mip 95.84.164.106 -sendto zaraysky@demo.onpremise.email -s FfDPTPuO -bcc -- a.lubin@msexchange.onpremise.email]
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-mpop1[6784]: [fcf6371f70e]: 11:06:38.237316 [D] the message has been sent
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-mpop1[6784]: [fcf6371f70e]: 11:06:38.486426 [I] response message id: 1ouUUI-0001Dn-AV, hostname: e.demomail.onpremise.email
Nov 14 11:06:38 demo-mail.novalocal onpremise-container-panda1[18866]: 2022/11/14 11:06:38 [I] [fcf6371f70e-sent]: response message id: 1ouUUI-0001Ds-GQ, hostname: e.demomail.onpremise.email
Nov 14 11:06:44 demo-mail.novalocal onpremise-container-panda-aestat1[21745]: [2022-11-14 11:06:44] 11 I last processed line (panda) : '2022/11/14 11:06:38 [I] [fcf6371f70e-sent]: response message id: 1ouUUI-0001Ds-GQ, hostname: e.demomail.onpremise.email'
[fcf6371f70e] → [fcf6371f70e-sent]
MX - более глубокий анализ
Греп по onpremise-container-mx* при получении письма дает следующее:
обмен с внешним сервером - получение почты
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 220 Welcome! [peer:109.120.188.18:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd received: EHLO e.kasmail.onprem.ru [peer:109.120.188.18:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 250 PIPELINING [peer:109.120.188.18:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd received: XCLIENT ADDR=89.208.229.27 LOGIN=@ NAME=[UNAVAILABLE] [peer:109.120.188.18:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 220 Welcome! [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd received: EHLO e.kasmail.onprem.ru [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 250 PIPELINING [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd received: MAIL FROM:<i.testov@kaspersky.onprem.ru> SIZE=4452 [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 250 Go ahead [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd received: RCPT TO:<zaraysky@demo.onpremise.email> [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 250 Go ahead [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd received: DATA [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd sending: 354 Go ahead. End your data with <CR><LF>.<CR><LF> [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd trace ptr record: ptr lookup: arpa: 27.229.208.89.in-addr.arpa. resolver: 172.20.4.130:53 error: read udp 172.20.5.43:54122->172.20.4.130:53: i/o timeout [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd trace ns record: domain ns lookup: empty response [peer:89.208.229.27:36820]
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx1[29111]: 2022-11-14 11:31:43 dbm;blacklist2.db key=89.208.229.27: expansion error: failed to open /usr/exim/conf/mpop/blacklist2.db as a db (v1) file: No such file or directory
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx1[29111]: 2022-11-14 11:31:43 dbm;blacklist2.db key=89.208.229.27: expansion error: failed to open /usr/exim/conf/mpop/blacklist2.db as a db (v1) file: No such file or directory
присвоение ID письму (первое появление)
Nov 14 11:31:43 demo-mail.novalocal onpremise-container-mx-fakesmtpdgo1[7189]: smtpd STATUS: from i.testov@kaspersky.onprem.ru to zaraysky@demo.onpremise.email. result=250 (OK id=1ouUsZ-00026p-BU) [peer:89.208.229.27:36820]
Дальше, как было описано выше
Логи Касперского
Транспорты настроены следующим образом:
Отправляем почту самому себе
Отправитель: i.testov@real5.on-premise.ru
Получатель: i.testov@real5.on-premise.ru
За работу с веб-интерфейсом отвечает panda, смотрим в логах:
Получение
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:51 [I] [43a637f488f]: request has been received, client ip: 172.20.5.11:46194
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu api_delivery_canceller_host: NULL
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu host: panda1.qdit
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu avscan: result no av found, forcing AV_DEFER
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu AV_CHECK: result DEFER
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu KAV8 returned DEFER for 1 times, which is more t
han limit 1, forcing OK result
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu <= i.testov@real5.on-premise.ru H=[172.20.111.11
2] U=root P=local S=3350 SPAMSIGN=0 REC=1 TRUST=0 id=1669286031.896302600@fmail1.qdit for i.testov@real5.on-premise.ru
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu RECEIVE_TIMINGS: TOTAL=0.055 LS=0.002 LSSPAM=0.0
00 LSVIRUS=0.000 CAPRON=0.039 DOMAIN=0.002 LOG_WRITE=0.000
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu PARENT_TIMINGS: TOTAL=0.001 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39058 -> 39060 1oy9YF-000A9w-Fu kafka govlog: disabled by config
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39058 -> 39060 1oy9YF-000A9w-Fu [DWH] remote_send||fe||1669286032||i.testov@r
eal5.on-premise.ru||172.20.111.112||i.testov@real5.on-premise.ru [/DWH]
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39058 -> 39060 1oy9YF-000A9w-Fu REMOTE_DELIVERY_TIMINGS: TOTAL=0.792 CAPRON=0
.001 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu => i.testov@real5.on-premise.ru F=<i.testov@real5
.on-premise.ru> R=mpop_router T=remote_smtp S=3219 H=klms1.on-premise.ru [100.70.80.24] C="250 OK id=1oy9YG-0001Eb-Ad"
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu TR=R TIME=1 COUNT=1 Q=0
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu Deliver completed
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu PARENT_TIMINGS: TOTAL=0.809 CAPRON=0.001 DNS=0.00
1 DOMAIN=0.003 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:52 [I] [43a637f488f]: response message id: 1oy9YF-000A9w-Fu, hostname: panda1.qd
it
Покладка в "Отправленные"
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci api_delivery_canceller_host: NULL
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci host: panda1.qdit
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci <= i.testov@real5.on-premise.ru H=[172.20.111.11
2] U=root P=local S=3229 SPAMSIGN=0 REC=1 TRUST=0 id=1669286031.896302600@fmail1.qdit for i.testov@real5.on-premise.ru
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci RECEIVE_TIMINGS: TOTAL=0.014 CAPRON=0.003 LOG_WR
ITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci PARENT_TIMINGS: TOTAL=0.001 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (mb_mail.c:4027): check can use
deliveryd to_sent: true: jig=1000, users='', st='' for i.testov@real5.on-premise.ru (127.0.0.1)
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (deliveryd_client.cpp:33): creat
e_deliveryd_connection: connecting to `172.20.5.3:7500' (1/2) with timeout `1000' ms
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (deliveryd_client.cpp:33): creat
e_deliveryd_connection: succesfully connected to `172.20.5.3:7500'
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (deliveryd_client.cpp:33): exim
storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16692860321494074967
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [info] (mb_mail.c:5057): store to sent
folder (new storing enabled is 1, size is 2 Kb, email: i.testov@real5.on-premise.ru, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk3/3FB/i.testov@real5
.on-premise.ru') time: 35231 mksecs
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci kafka govlog: disabled by config
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci [DWH] sentmsg_exim||fe||1669286032||i.testov@
real5.on-premise.ru||172.20.111.112||i.testov@real5.on-premise.ru||0||16692860321494074967||500000||i.testov@real5.on-premise.ru||||<1669286031.896302600@fmail1.qdit>||
||1oy9YG-000AA1-Ci [/DWH]
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci DELIVERY_TIMINGS: TOTAL=0.042 DATABASE=0.003
CAPRON=0.002 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci => i.testov <i.testov@real5.on-premise.ru> F=<i.t
estov@real5.on-premise.ru> R=mpop_router_sent T=mpop_transport S=951
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci TR=L TIME=0 COUNT=1 Q=0
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci Deliver completed
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci PARENT_TIMINGS: TOTAL=0.060 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:52 [I] [43a637f488f-sent]: response message id: 1oy9YG-000AA1-Ci, hostname: pand
a1.qdit
Выделены log key и ID сообщений.
Греп по log key:
[root@mail-dev5 ~]# journalctl -fu onpremise-container-* --since '300 seconds ago' | grep 43a637f488f
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:51 [I] [43a637f488f]: request has been received, client ip: 172.20.5.11:46194
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:52 [I] [43a637f488f]: response message id: 1oy9YF-000A9w-Fu, hostname: panda1.qd
it
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:51.463001 [D] flags data ready: map[--:[i.testov@real5.on-premise.ru] exim-fl
ag-f:[f i.testov@real5.on-premise.ru] exim-flag-i:[i] exim-flag-mal:[mal i.testov@real5.on-premise.ru] exim-flag-mdd:[mdd 0] exim-flag-mip:[mip 172.20.111.112] exim-fla
g-mlmi:[mlmi] exim-flag-mlmip:[mlmip 3] exim-flag-mqcs:[mqcs m4nQ8Bdo] exim-flag-mrm:[mrm 16692855610016398368] exim-flag-mru:[mru 1184207] exim-flag-oem:[oem] exim-sen
t-flag-s:[s P98SFBRj] exim-sent-flag-sr:[sr 16692855610016398368] logkey:[43a637f488f] self:[PT9VVEYtOD9CP1UyVnNaam9nVW1VNklHRmhZUT09Pz0=] sendto:[i.testov@real5.on-pre
mise.ru]]
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:51.463111 [D] backend addr from cluster config: panda.qdit:7510
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:51.465434 [D] backend addr from stream context: 172.20.5.9:7510
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:51.465485 [I] request to the server: panda.qdit:7510, tls: false, args: [/usr
/local/panda/bin/panda-client -mqcs m4nQ8Bdo -mlmi -mlmip 3 -i -oem -f i.testov@real5.on-premise.ru -mru 1184207 -mrm 16692855610016398368 -mal i.testov@real5.on-premis
e.ru -mip 172.20.111.112 -sendto i.testov@real5.on-premise.ru -s P98SFBRj -sr 16692855610016398368 -self PT9VVEYtOD9CP1UyVnNaam9nVW1VNklHRmhZUT09Pz0= -bcc -- i.testov@
real5.on-premise.ru]
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:51.465664 [D] the message has been sent
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:52.372035 [I] response message id: 1oy9YF-000A9w-Fu, hostname: panda1.qdit
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:52 [I] [43a637f488f-sent]: response message id: 1oy9YG-000AA1-Ci, hostname: pand
a1.qdit
В логах упоминаются следующие контейнеры:
- onpremise-container-panda1
- onpremise-container-mpop1
Греп по ID 1oy9YF-000A9w-Fu по всем логам дает следующую картину:
[root@mail-dev5 ~]# journalctl -fu onpremise-container-* --since '300 seconds ago' | grep 1oy9YF-000A9w-Fu
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu api_delivery_canceller_host: NULL
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu host: panda1.qdit
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu avscan: result no av found, forcing AV_DEFER
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu AV_CHECK: result DEFER
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu KAV8 returned DEFER for 1 times, which is more t
han limit 1, forcing OK result
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu <= i.testov@real5.on-premise.ru H=[172.20.111.11
2] U=root P=local S=3350 SPAMSIGN=0 REC=1 TRUST=0 id=1669286031.896302600@fmail1.qdit for i.testov@real5.on-premise.ru
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu RECEIVE_TIMINGS: TOTAL=0.055 LS=0.002 LSSPAM=0.0
00 LSVIRUS=0.000 CAPRON=0.039 DOMAIN=0.002 LOG_WRITE=0.000
Nov 24 13:33:51 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:51 53 -> 39056 1oy9YF-000A9w-Fu PARENT_TIMINGS: TOTAL=0.001 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39058 -> 39060 1oy9YF-000A9w-Fu kafka govlog: disabled by config
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39058 -> 39060 1oy9YF-000A9w-Fu [DWH] remote_send||fe||1669286032||i.testov@r
eal5.on-premise.ru||172.20.111.112||i.testov@real5.on-premise.ru [/DWH]
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39058 -> 39060 1oy9YF-000A9w-Fu REMOTE_DELIVERY_TIMINGS: TOTAL=0.792 CAPRON=0
.001 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu => i.testov@real5.on-premise.ru F=<i.testov@real5
.on-premise.ru> R=mpop_router T=remote_smtp S=3219 H=klms1.on-premise.ru [100.70.80.24] C="250 OK id=1oy9YG-0001Eb-Ad"
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu TR=R TIME=1 COUNT=1 Q=0
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu Deliver completed
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39058 1oy9YF-000A9w-Fu PARENT_TIMINGS: TOTAL=0.809 CAPRON=0.001 DNS=0.00
1 DOMAIN=0.003 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:52 [I] [43a637f488f]: response message id: 1oy9YF-000A9w-Fu, hostname: panda1.qd
it
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: [43a637f488f]: 13:33:52.372035 [I] response message id: 1oy9YF-000A9w-Fu, hostname: panda1.qdit
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-mpop1[87421]: 2022-11-24T13:33:52.374 I 1081 i.testov@real5.on-premise.ru ee2cfe46ba >>> Sendmail log message id
: 1oy9YF-000A9w-Fu
В логах упоминаются следующие контейнеры:
- onpremise-container-panda1
- onpremise-container-mpop1
Греп по ID 1oy9YG-000AA1-Ci по всем логам дает следующую картину:
[root@mail-dev5 ~]# journalctl -fu onpremise-container-* --since '500 seconds ago' | grep 1oy9YG-000AA1-Ci
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci api_delivery_canceller_host: NULL
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci host: panda1.qdit
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci <= i.testov@real5.on-premise.ru H=[172.20.111.112] U=root P=local S=3229 SPAMSIGN=0 REC=1 TRUST=0 id=1669286031.896302600@fmail1.qdit for i.testov@real5.on-premise.ru
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci RECEIVE_TIMINGS: TOTAL=0.014 CAPRON=0.003 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 53 -> 39061 1oy9YG-000AA1-Ci PARENT_TIMINGS: TOTAL=0.001 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-del1[82666]: [46.2.172.20.5.9:57716] store [warn]: delivery res: delivery res=ok ('ok'), iprohdr='[msg=0,len=314,sync=1]', hsz='310', type='exim_to_sent', exim_message_id='1oy9YG-000AA1-Ci', email='i.testov@real5.on-premise.ru', fsize='2617b', st_size='2382b', st='127.0.0.3:|1|3|1184207|i.testov@real5.on-premise.ru|1552|', uidl='16692860321494074967', zepto_id='(b:3;r:1436921653)', needed_msgflags='65540', msgflags='65550', folderid='500000', resp_sz='83'
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (mb_mail.c:4027): check can use deliveryd to_sent: true: jig=1000, users='', st='' for i.testov@real5.on-premise.ru (127.0.0.1)
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: connecting to `172.20.5.3:7500' (1/2) with timeout `1000' ms
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (deliveryd_client.cpp:33): create_deliveryd_connection: succesfully connected to `172.20.5.3:7500'
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [warn] (deliveryd_client.cpp:33): exim storing with deliveryd (8) *ok*, store_stage_real: 0, uidl: 16692860321494074967
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci store [info] (mb_mail.c:5057): store to sent folder (new storing enabled is 1, size is 2 Kb, email: i.testov@real5.on-premise.ru, mimeparser: 0, st: '127.0.0.1:/var/mail/vdomains/external/_disk3/3FB/i.testov@real5.on-premise.ru') time: 35231 mksecs
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci DELIVERY TO SENT FOLDER SUCCESSFUL
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci kafka govlog: disabled by config
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci [DWH] sentmsg_exim||fe||1669286032||i.testov@real5.on-premise.ru||172.20.111.112||i.testov@real5.on-premise.ru||0||16692860321494074967||500000||i.testov@real5.on-premise.ru||||<1669286031.896302600@fmail1.qdit>||||1oy9YG-000AA1-Ci [/DWH]
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 39063 -> 39065 1oy9YG-000AA1-Ci DELIVERY_TIMINGS: TOTAL=0.042 DATABASE=0.003 CAPRON=0.002 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci => i.testov <i.testov@real5.on-premise.ru> F=<i.testov@real5.on-premise.ru> R=mpop_router_sent T=mpop_transport S=951
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci TR=L TIME=0 COUNT=1 Q=0
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci Deliver completed
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022-11-24 13:33:52 1 -> 39063 1oy9YG-000AA1-Ci PARENT_TIMINGS: TOTAL=0.060 LOG_WRITE=0.000
Nov 24 13:33:52 mail-dev5.novalocal onpremise-container-panda1[19879]: 2022/11/24 13:33:52 [I] [43a637f488f-sent]: response message id: 1oy9YG-000AA1-Ci, hostname: panda1.qdit
В логах упоминается только onpremise-container-panda1
При этом в KLMS в логах видим:
Nov 24 13:33:54 mail-klms1.novalocal KLMS[17015]: clean: message-id="<1669286031.896302600@fmail1.qdit>": relay-ip="": action="Skipped": rules="1": size=3725: mail-from="i.testov@real5.on-premise.ru": rcpt-to="i.testov@real5.on-premise.ru": kt-status="NotScanned, disabled by settings", av-status="NotScanned, disabled by settings", ap-status="NotScanned, disabled by settings", as-status="Clean", ma-status="ViolationNotFound", dmarc="NotScanned", spf="NotScanned", dkim="Pass", cf-status="NotScanned, disabled by settings"
Nov 24 13:33:54 mail-klms1.novalocal klms-smtp_proxy[17202]: Message from <i.testov@real5.on-premise.ru> to <i.testov@real5.on-premise.ru> passed
Nov 24 13:33:54 mail-klms1.novalocal klms-smtp_proxy[17202]: temp file fd = 13, file name /tmp/klms_filter/klms_filter_995_992/klms-smtp_proxy.zhJkk9 at smtp_server.cpp: 182
Выделен ID сообщения.
Само сообщение выглядит так (во входящих):
Delivered-To: i.testov@real5.on-premise.ru
Return-path: <i.testov@real5.on-premise.ru>
Received: from [100.70.80.24] (port=50636 helo=klms1.on-premise.ru)
by relay1.qdit with esmtp (envelope-from <i.testov@real5.on-premise.ru>)
id 1oy9YG-0001Eb-Ad
for i.testov@real5.on-premise.ru; Thu, 24 Nov 2022 13:33:52 +0300
X-Mru-NR: 1
DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=real5.on-premise.ru; s=mailru;
h=References:In-Reply-To:Content-Type:Message-ID:Reply-To:Date:MIME-Version:Subject:To:From:From:Subject:Content-Type:Content-Transfer-Encoding:To:Cc; bh=foKriEmRmYV78Ak9fR8r8sjpOLSY0yTfJ4iwOoyTsRc=;
t=1669286031;x=1669891431;
b=jVnLd2O4A7T+6qf+2nWDCfTPrv9JaBiiQi5FSxau3mj2Kk+zhzYyYhAO76ayhKkixaKE9KolBwBN4FtaFqXnk3KKH4NM9bwoF6/iQ2ff24PcNz1tG/IMaCzcW0MfLBdBYmXppmH8ndpy6/maXIPP49jui7eRHUBDIYsjoOALSUU=;
Received: from [172.20.111.112] (ident=root)
by panda1.qdit with local (envelope-from <i.testov@real5.on-premise.ru>)
id 1oy9YF-000A9w-Fu
for i.testov@real5.on-premise.ru; Thu, 24 Nov 2022 13:33:51 +0300
Received: by e.dev5.on-premise.ru with HTTP;
Thu, 24 Nov 2022 13:33:51 +0300
From: =?UTF-8?B?aXZhbiB0ZXN0b3Y=?= <i.testov@real5.on-premise.ru>
To: =?UTF-8?B?aXZhbiB0ZXN0b3Y=?= <i.testov@real5.on-premise.ru>
Subject: =?UTF-8?B?UmU6IGFhYQ==?=
MIME-Version: 1.0
X-Mailer: Mail.Ru Mailer 1.0
X-SenderField-ReMsg: 16692855610016398368
X-SenderField-Remind: 0
Date: Thu, 24 Nov 2022 13:33:51 +0300
X-Mru-UID: 1184207
X-Mru-IsAutoreg:
X-Mru-AutoregInfo: ,
X-Mru-User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.0 Safari/605.1.15
X-Mru-PDD-Id: 1
X-Priority: 3 (Normal)
Reply-To: =?UTF-8?B?aXZhbiB0ZXN0b3Y=?= <i.testov@real5.on-premise.ru>
X-Mru-SendMsg: 37931396c5e940b74fe065a0a71040d0f6b113a238c93c185185226901b0e658
X-Mru-Data: 0:::0:0:0
X-Mru-Referer: 668db921b0e1ae8fd25440becc1cb5d5d5d6ccc72f2084c5c04982d4175a1f2f6d9a5e5fd243b2986cde9c6d7d2823fc7da12db4add156dcaa81a15acbc81cee9db2b218aaa888617d3b2661958215570d9ca966ac0708797494d5c016f61ce5cc8c78f65340c3e2
Message-ID: <1669286031.896302600@fmail1.qdit>
Content-Type: multipart/alternative;
boundary="--ALT--386a5CfBA5bA47B69FeC62B0a41E33671669286031"
In-Reply-To: <1669285559.324066694@fmail1.qdit>
References: <1669285559.324066694@fmail1.qdit>
X-KLMS-Rule-ID: 1
X-KLMS-Message-Action: clean
X-KLMS-AntiSpam-Lua-Profiles: 173738 [Nov 24 2022]
X-KLMS-AntiSpam-Version: 5.9.59.0
X-KLMS-AntiSpam-Envelope-From: i.testov@real5.on-premise.ru
X-KLMS-AntiSpam-Rate: 0
X-KLMS-AntiSpam-Status: not_detected
X-KLMS-AntiSpam-Method: none
X-KLMS-AntiSpam-Auth: dkim=pass header.d=real5.on-premise.ru
X-KLMS-AntiSpam-Info: LuaCore: 502 502 69dee8ef46717dd3cb3eeb129cb7cc8dab9e30f6, {Tracking_seems_internal}
X-MS-Exchange-Organization-SCL: -1
X-KLMS-AntiSpam-Interceptor-Info: scan successful
X-KLMS-AntiPhishing: not scanned, disabled by settings
X-KLMS-AntiVirus: Kaspersky Security for Linux Mail Server, version 8.0.3.30, not scanned, disabled by settings
Authentication-Results: relay1.qdit; auth=pass smtp.auth=i.testov@real5.on-premise.ru smtp.mailfrom=i.testov@real5.on-premise.ru; iprev=pass policy.iprev=100.70.80.24
X-Mailru-Intl-Transport: d,6cb942d
----ALT--386a5CfBA5bA47B69FeC62B0a41E33671669286031
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: base64
CmFhYQrCoArCoAotLQppdmFuIHRlc3RvdgrCoArCoCAKPtCn0LXRgtCy0LXRgNCzLCAyNCDQvdC+
0Y/QsdGA0Y8gMjAyMiwgMTM6MjYgKzAzOjAwINC+0YIgaXZhbiB0ZXN0b3YgPGkudGVzdG92QHJl
YWw1Lm9uLXByZW1pc2UucnU+Ogo+wqAKPmFhYQo+wqAKPi0tCj5pdmFuIHRlc3RvdgrCoA==
----ALT--386a5CfBA5bA47B69FeC62B0a41E33671669286031
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: base64
CjxIVE1MPjxCT0RZPjxkaXY+YWFhPC9kaXY+PGRpdj4mbmJzcDs8L2Rpdj48ZGl2PiZuYnNwOzwv
ZGl2PjxkaXYgZGF0YS1zaWduYXR1cmUtd2lkZ2V0PSJjb250YWluZXIiPjxkaXYgZGF0YS1zaWdu
YXR1cmUtd2lkZ2V0PSJjb250ZW50Ij48ZGl2Pi0tPGJyPml2YW4gdGVzdG92PC9kaXY+PC9kaXY+
PC9kaXY+PGRpdj4mbmJzcDs8L2Rpdj48ZGl2PiZuYnNwOzwvZGl2PjxibG9ja3F1b3RlIHN0eWxl
PSJib3JkZXItbGVmdDoxcHggc29saWQgIzA4NTdBNjsgbWFyZ2luOjEwcHg7IHBhZGRpbmc6MCAw
IDAgMTBweDsiPtCn0LXRgtCy0LXRgNCzLCAyNCDQvdC+0Y/QsdGA0Y8gMjAyMiwgMTM6MjYgKzAz
OjAwINC+0YIgaXZhbiB0ZXN0b3YgJmx0O2kudGVzdG92QHJlYWw1Lm9uLXByZW1pc2UucnUmZ3Q7
Ojxicj4mbmJzcDs8ZGl2IGlkPSIiPjxkaXYgY2xhc3M9ImpzLWhlbHBlciBqcy1yZWFkbXNnLW1z
ZyI+PGRpdj48ZGl2IGlkPSJzdHlsZV8xNjY5Mjg1NTYxMDAxNjM5ODM2OF9CT0RZIj48ZGl2IGNs
YXNzPSJjbF8yODcwOTMiPjxkaXY+YWFhPC9kaXY+PGRpdj4mbmJzcDs8L2Rpdj48ZGl2IGRhdGEt
c2lnbmF0dXJlLXdpZGdldD0iY29udGFpbmVyIj48ZGl2IGRhdGEtc2lnbmF0dXJlLXdpZGdldD0i
Y29udGVudCI+PGRpdj4tLTxicj5pdmFuIHRlc3RvdjwvZGl2PjwvZGl2PjwvZGl2PjwvZGl2Pjwv
ZGl2PjwvZGl2PjwvZGl2PjwvZGl2PjwvYmxvY2txdW90ZT48ZGl2PiZuYnNwOzwvZGl2PjwvQk9E
WT48L0hUTUw+Cg==
----ALT--386a5CfBA5bA47B69FeC62B0a41E33671669286031--
Выделены интересные для нас заголовки - их оставил KLMS