From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id C088869A65 for ; Tue, 23 Mar 2021 15:10:00 +0100 (CET) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id B58252F730 for ; Tue, 23 Mar 2021 15:09:30 +0100 (CET) Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com [212.186.127.180]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by firstgate.proxmox.com (Proxmox) with ESMTPS id 2E9E72F6C2 for ; Tue, 23 Mar 2021 15:09:29 +0100 (CET) Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1]) by proxmox-new.maurer-it.com (Proxmox) with ESMTP id E30E5463E5 for ; Tue, 23 Mar 2021 15:09:28 +0100 (CET) Date: Tue, 23 Mar 2021 15:09:27 +0100 From: Stoiko Ivanov To: Mira Limbeck Cc: pmg-devel@lists.proxmox.com Message-ID: <20210323150927.39c3832b@rosa.proxmox.com> In-Reply-To: <20210323110531.4128-1-m.limbeck@proxmox.com> References: <20210323110531.4128-1-m.limbeck@proxmox.com> X-Mailer: Claws Mail 3.17.3 (GTK+ 2.24.32; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit X-SPAM-LEVEL: Spam detection results: 0 AWL 0.061 Adjusted score from AWL reputation of From: address KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment RCVD_IN_DNSWL_MED -2.3 Sender listed at https://www.dnswl.org/, medium trust SPF_HELO_NONE 0.001 SPF: HELO does not publish an SPF Record SPF_PASS -0.001 SPF: sender matches SPF record URIBL_BLOCKED 0.001 ADMINISTRATOR NOTICE: The query to URIBL was blocked. See http://wiki.apache.org/spamassassin/DnsBlocklists#dnsbl-block for more information. [main.rs] Subject: Re: [pmg-devel] applied: [PATCH v3 log-tracker] close #2106: show outgoing TLS connection in tracking center X-BeenThere: pmg-devel@lists.proxmox.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Proxmox Mail Gateway development discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 23 Mar 2021 14:10:00 -0000 On Tue, 23 Mar 2021 12:05:31 +0100 Mira Limbeck 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 > --- > 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: : 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, Rc>>, > qentries: HashMap, Rc>>, > > + smtp_tls_log_by_pid: HashMap, 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= > L00000017 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: 88F2E42667: from=, 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=, 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=, 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=, 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= > L00000017 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: 88F2E42667: from=, 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=, 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=, 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=, 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@test@localdomain> > L0000000F Apr 30 15:40:41 pmg6 postfix/qmgr[23452]: E1C6561393: from=, 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=, 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 : 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 >