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 <m.limbeck@proxmox.com>
// handle log entries for 'lmtp', 'smtp', 'error' and 'local'
fn handle_lmtp_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,
let (qid, data) = match parse_qid(msg, 15) {
Some((q, t)) => (q, t),
None => return,
.log
.push((complete_line.into(), parser.lines));
.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;
let data = &data[2..];
if !data.starts_with(b"to=<") {
return;
if !self.log.is_empty() {
parser.write_all_ok(b"QMGR:\n");
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);
}
}
print_log(parser, &self.log);
}
}
fentries: HashMap<Box<[u8]>, Rc<RefCell<FEntry>>>,
qentries: HashMap<Box<[u8]>, Rc<RefCell<QEntry>>>,
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,
current_record_state: RecordState,
rel_line_nr: u64,
sentries: HashMap::new(),
fentries: HashMap::new(),
qentries: HashMap::new(),
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,
current_record_state: Default::default(),
rel_line_nr: 0,
current_year: years,
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@test.localdomain>, size=8037, nrcpt=4 (queue active)
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@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@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@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@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)
L00000024 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test1@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@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@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)
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@test.localdomain>, size=8037, nrcpt=4 (queue active)
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@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@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@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@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)
L00000024 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test1@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@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@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)
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=<senduser@test@localdomain>, size=1436, nrcpt=1 (queue active)
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=<senduser@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@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@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
L00000015 Apr 30 15:40:41 pmg6 postfix/smtp[21626]: E1C6561393: to=<reject@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@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