[pmg-devel] applied: [PATCH v3 log-tracker] close #2106: show outgoing TLS connection in tracking center
Stoiko Ivanov
s.ivanov at proxmox.com
Tue Mar 23 15:09:27 CET 2021
On Tue, 23 Mar 2021 12:05:31 +0100
Mira Limbeck <m.limbeck at proxmox.com> wrote:
> This is a best effort try to add the outgoing TLS connection information
> to the output of pmg-log-tracker. The only thing we can match on is the
> PID of the 'smtp' process. In the code we asumme that the TLS log entry
> always happens before the actual smtp send entry that has a QID. This means
> we save the TLS log entry in a map with the PID as key and then, once the
> send entry happens, we look it up and add the log entry to the QEntry's
> logs.
applied - huge thanks!
>
> Signed-off-by: Mira Limbeck <m.limbeck at proxmox.com>
> ---
> v3:
> - fixed tests
> - added sorting to QMGR logs
> v2:
> - added 'Untrusted' line match as well
>
> src/main.rs | 24 +++++++++++++++++++
> tests/test_output_after_queue | 1 +
> tests/test_output_after_queue_host | 1 +
> ...before_queue_mixed_accept_block_quarantine | 1 +
> 4 files changed, 27 insertions(+)
>
> diff --git a/src/main.rs b/src/main.rs
> index 5069252..9594b18 100644
> --- a/src/main.rs
> +++ b/src/main.rs
> @@ -378,6 +378,18 @@ fn handle_qmgr_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
>
> // handle log entries for 'lmtp', 'smtp', 'error' and 'local'
> fn handle_lmtp_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
> + if msg.starts_with(b"Trusted TLS connection established to")
> + || msg.starts_with(b"Untrusted TLS connection established to")
> + {
> + // the only way to match outgoing TLS connections is by smtp pid
> + // this message has to appear before the 'qmgr: <QID>: removed' entry in the log
> + parser.smtp_tls_log_by_pid.insert(
> + parser.current_record_state.pid,
> + (complete_line.into(), parser.lines),
> + );
> + return;
> + }
> +
> let (qid, data) = match parse_qid(msg, 15) {
> Some((q, t)) => (q, t),
> None => return,
> @@ -393,6 +405,14 @@ fn handle_lmtp_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
> .log
> .push((complete_line.into(), parser.lines));
>
> + // assume the TLS log entry always appears before as it is the same process
> + if let Some(log_line) = parser
> + .smtp_tls_log_by_pid
> + .remove(&parser.current_record_state.pid)
> + {
> + qe.borrow_mut().log.push(log_line);
> + }
> +
> let data = &data[2..];
> if !data.starts_with(b"to=<") {
> return;
> @@ -1594,6 +1614,7 @@ impl QEntry {
>
> if !self.log.is_empty() {
> parser.write_all_ok(b"QMGR:\n");
> + self.log.sort_by(|a, b| a.1.cmp(&b.1));
> print_log(parser, &self.log);
> }
> }
> @@ -1668,6 +1689,8 @@ struct Parser {
> fentries: HashMap<Box<[u8]>, Rc<RefCell<FEntry>>>,
> qentries: HashMap<Box<[u8]>, Rc<RefCell<QEntry>>>,
>
> + smtp_tls_log_by_pid: HashMap<u64, (Box<[u8]>, u64)>,
> +
> current_record_state: RecordState,
> rel_line_nr: u64,
>
> @@ -1705,6 +1728,7 @@ impl Parser {
> sentries: HashMap::new(),
> fentries: HashMap::new(),
> qentries: HashMap::new(),
> + smtp_tls_log_by_pid: HashMap::new(),
> current_record_state: Default::default(),
> rel_line_nr: 0,
> current_year: years,
> diff --git a/tests/test_output_after_queue b/tests/test_output_after_queue
> index ec2fc65..b93d4c4 100644
> --- a/tests/test_output_after_queue
> +++ b/tests/test_output_after_queue
> @@ -70,6 +70,7 @@ L00000018 Dec 18 15:50:38 proxmox-new postfix/smtpd[13179]: disconnect from loca
> QMGR:
> L00000016 Dec 18 15:50:38 proxmox-new postfix/cleanup[13173]: 88F2E42667: message-id=<xyz>
> L00000017 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: 88F2E42667: from=<test at test.localdomain>, size=8037, nrcpt=4 (queue active)
> +L0000001D Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: Untrusted TLS connection established to 192.168.22.40[192.168.22.40]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
> L00000024 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test1 at localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C928BF624F6)
> L00000025 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test2 at localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C928BF624F6)
> L00000026 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test3 at localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C928BF624F6)
> diff --git a/tests/test_output_after_queue_host b/tests/test_output_after_queue_host
> index ead669c..219bdb9 100644
> --- a/tests/test_output_after_queue_host
> +++ b/tests/test_output_after_queue_host
> @@ -41,6 +41,7 @@ L00000018 Dec 18 15:50:38 proxmox-new postfix/smtpd[13179]: disconnect from loca
> QMGR:
> L00000016 Dec 18 15:50:38 proxmox-new postfix/cleanup[13173]: 88F2E42667: message-id=<xyz>
> L00000017 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: 88F2E42667: from=<test at test.localdomain>, size=8037, nrcpt=4 (queue active)
> +L0000001D Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: Untrusted TLS connection established to 192.168.22.40[192.168.22.40]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
> L00000024 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test1 at localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C928BF624F6)
> L00000025 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test2 at localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C928BF624F6)
> L00000026 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test3 at localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.04/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C928BF624F6)
> diff --git a/tests/test_output_before_queue_mixed_accept_block_quarantine b/tests/test_output_before_queue_mixed_accept_block_quarantine
> index 7495a78..637b40a 100644
> --- a/tests/test_output_before_queue_mixed_accept_block_quarantine
> +++ b/tests/test_output_before_queue_mixed_accept_block_quarantine
> @@ -30,6 +30,7 @@ L00000013 Apr 30 15:40:41 pmg6 pmg-smtp-filter[21528]: 611D85EAAD6477B053: proce
> QMGR:
> L0000000E Apr 30 15:40:40 pmg6 postfix/cleanup[21632]: E1C6561393: message-id=<20200430134439.GE6794 at test@localdomain>
> L0000000F Apr 30 15:40:41 pmg6 postfix/qmgr[23452]: E1C6561393: from=<senduser at test@localdomain>, size=1436, nrcpt=1 (queue active)
> +L00000012 Apr 30 15:40:41 pmg6 postfix/smtp[21626]: Untrusted TLS connection established to 192.0.2.69[192.0.2.69]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)
> L00000015 Apr 30 15:40:41 pmg6 postfix/smtp[21626]: E1C6561393: to=<reject at test.recipient.example>, relay=192.0.2.69[192.0.2.69]:25, delay=0.73, delays=0.19/0/0.05/0.5, dsn=5.7.1, status=bounced (host 192.0.2.69[192.0.2.69] said: 554 5.7.1 <reject at test.recipient.example>: Recipient address rejected: no mail for reject@ (in reply to RCPT TO command))
> L00000019 Apr 30 15:40:42 pmg6 postfix/qmgr[23452]: E1C6561393: removed
>
More information about the pmg-devel
mailing list