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 DB4CD697F9 for ; Tue, 23 Mar 2021 12:06:04 +0100 (CET) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id C8CC92D6AC for ; Tue, 23 Mar 2021 12:05:34 +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 EF5D92D6A4 for ; Tue, 23 Mar 2021 12:05:33 +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 B293F428C9 for ; Tue, 23 Mar 2021 12:05:33 +0100 (CET) From: Mira Limbeck To: pmg-devel@lists.proxmox.com Date: Tue, 23 Mar 2021 12:05:31 +0100 Message-Id: <20210323110531.4128-1-m.limbeck@proxmox.com> X-Mailer: git-send-email 2.20.1 MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-SPAM-LEVEL: Spam detection results: 0 AWL -0.241 Adjusted score from AWL reputation of From: address KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment KAM_LAZY_DOMAIN_SECURITY 1 Sending domain does not have any anti-forgery methods NO_DNS_FOR_FROM 0.379 Envelope sender has no MX or A DNS records 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_NONE 0.001 SPF: sender does not publish an 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: [pmg-devel] [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 11:06:04 -0000 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. 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 -- 2.20.1