From: Mira Limbeck <m.limbeck@proxmox.com>
To: pmg-devel@lists.proxmox.com
Subject: [pmg-devel] [PATCH log-tracker] fix mutable borrow panic on duplicate msgid
Date: Thu, 29 Apr 2021 15:25:08 +0200 [thread overview]
Message-ID: <20210429132508.29570-1-m.limbeck@proxmox.com> (raw)
Because of the relay before lmtp issue we now add and remove QEntrys
based on their message-id. But if the cleanup line containing the
message-id appears twice in the log for the same QEntry it keeps a weak
reference to itself which leads to a panic because of a mutable borrow
while it is already mutably borrowed in the 'finalize' function.
To circumvent this we check after the lookup if it is the same QEntry
and if so, insert it again with that message-id in the lookup table and
don't add the weak reference.
Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
src/main.rs | 11 ++++-
tests/test_input_after_queue_duplicate_msgid | 20 +++++++++
tests/test_output_after_queue_duplicate_msgid | 45 +++++++++++++++++++
tests/tests_after_queue.rs | 23 ++++++++++
4 files changed, 97 insertions(+), 2 deletions(-)
create mode 100644 tests/test_input_after_queue_duplicate_msgid
create mode 100644 tests/test_output_after_queue_duplicate_msgid
diff --git a/src/main.rs b/src/main.rs
index 33a13a5..b1d4f8c 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -765,9 +765,16 @@ fn handle_cleanup_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8])
// does not work correctly if there's a duplicate message id in the logfiles
if let Some(q) = parser.msgid_lookup.remove(msgid) {
- qe.borrow_mut().aq_qentry = Some(Weak::clone(&q));
+ let q_clone = Weak::clone(&q);
if let Some(q) = q.upgrade() {
- q.borrow_mut().aq_qentry = Some(Rc::downgrade(&qe));
+ // check to make sure it's not the same QEntry
+ // this can happen if the cleanup line is duplicated in the log
+ if Rc::ptr_eq(&q, &qe) {
+ parser.msgid_lookup.insert(msgid.into(), q_clone);
+ } else {
+ qe.borrow_mut().aq_qentry = Some(q_clone);
+ q.borrow_mut().aq_qentry = Some(Rc::downgrade(&qe));
+ }
}
}
else {
diff --git a/tests/test_input_after_queue_duplicate_msgid b/tests/test_input_after_queue_duplicate_msgid
new file mode 100644
index 0000000..b159f51
--- /dev/null
+++ b/tests/test_input_after_queue_duplicate_msgid
@@ -0,0 +1,20 @@
+Jan 21 07:33:20 pmghost postfix/smtpd[29361]: connect from pmghost.mydomain.tld[192.168.1.001]
+Jan 21 07:33:20 pmghost postfix/smtpd[29361]: DEF2520A69: client=pmghost.mydomain.tld[192.168.1.001]
+Jan 21 07:33:20 pmghost postfix/cleanup[29364]: DEF2520A69: message-id=<redacted:msgid>
+Jan 21 07:33:20 pmghost postfix/cleanup[29364]: DEF2520A69: message-id=<redacted:msgid>
+Jan 21 07:33:20 pmghost postfix/qmgr[529]: DEF2520A69: from=<redacted:returnpath@domain.tld>, size=161138, nrcpt=1 (queue active)
+Jan 21 07:33:21 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: new mail message-id=<redacted:msgid>#012
+Jan 21 07:33:21 pmghost postfix/smtpd[29361]: 1855220A70: client=pmghost.mydomain.tld[192.168.1.001]
+Jan 21 07:33:21 pmghost postfix/smtpd[29361]: disconnect from pmghost.mydomain.tld[192.168.1.001] ehlo=1 mail=2 rcpt=2 data=2 quit=1 commands=8
+Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: SA score=1/5 time=3.500 bayes=undefined autolearn=no autolearn_force=no hits=AWL(0.270),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),HTML_EMBEDS(0.001),HTML_FONT_LOW_CONTRAST(0.001),HTML_IMAGE_RATIO_02(0.001),HTML_MESSAGE(0.001),KAM_LOTSOFHASH(0.25),MPART_ALT_DIFF_COUNT(1.483),SPF_HELO_NONE(0.001),SPF_PASS(-0.001)
+Jan 21 07:33:24 pmghost postfix/smtpd[29375]: connect from localhost[127.0.0.1]
+Jan 21 07:33:24 pmghost postfix/smtpd[29375]: A673520AB5: client=localhost[127.0.0.1], orig_client=pmghost.mydomain.tld[192.168.1.001]
+Jan 21 07:33:24 pmghost postfix/cleanup[29364]: A673520AB5: message-id=<redacted:msgid>
+Jan 21 07:33:24 pmghost postfix/smtpd[29375]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
+Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: accept mail to <redacted:recipient@mydomain.tld> (A673520AB5) (rule: default-accept)
+Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: from=<redacted:returnpath@domain.tld>, size=162287, nrcpt=1 (queue active)
+Jan 21 07:33:24 pmghost postfix/smtp[29376]: A673520AB5: to=<redacted:recipient@mydomain.tld>, relay=192.168.1.002[192.168.1.002]:25, delay=0.07, delays=0.06/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B6B682E547)
+Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: removed
+Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: processing time: 3.748 seconds (3.5, 0.137, 0)
+Jan 21 07:33:24 pmghost postfix/lmtp[29365]: DEF2520A69: to=<redacted:recipient@mydomain.tld>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.9, delays=0.05/0.04/0.01/3.8, dsn=2.5.0, status=sent (250 2.5.0 OK (20A9560092030F3374))
+Jan 21 07:33:24 pmghost postfix/qmgr[529]: DEF2520A69: removed
diff --git a/tests/test_output_after_queue_duplicate_msgid b/tests/test_output_after_queue_duplicate_msgid
new file mode 100644
index 0000000..80e29dd
--- /dev/null
+++ b/tests/test_output_after_queue_duplicate_msgid
@@ -0,0 +1,45 @@
+# LogReader: 4815
+# Query options
+# Start: 2020-01-21 00:00:00 (1579564800)
+# End: 2021-02-19 11:07:50 (1613732870)
+# End Query Options
+
+QENTRY: A673520AB5
+CTIME: 5E26A944
+SIZE: 162287
+CLIENT: localhost[127.0.0.1],
+MSGID: <redacted:msgid>
+TO:5E26A944:A673520AB5:2: from <redacted:returnpath@domain.tld> to <redacted:recipient@mydomain.tld> (192.168.1.002[192.168.1.002]:25)
+SMTP:
+L0000000A Jan 21 07:33:24 pmghost postfix/smtpd[29375]: connect from localhost[127.0.0.1]
+L0000000B Jan 21 07:33:24 pmghost postfix/smtpd[29375]: A673520AB5: client=localhost[127.0.0.1], orig_client=pmghost.mydomain.tld[192.168.1.001]
+L0000000D Jan 21 07:33:24 pmghost postfix/smtpd[29375]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
+QMGR:
+L0000000C Jan 21 07:33:24 pmghost postfix/cleanup[29364]: A673520AB5: message-id=<redacted:msgid>
+L0000000F Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: from=<redacted:returnpath@domain.tld>, size=162287, nrcpt=1 (queue active)
+L00000010 Jan 21 07:33:24 pmghost postfix/smtp[29376]: A673520AB5: to=<redacted:recipient@mydomain.tld>, relay=192.168.1.002[192.168.1.002]:25, delay=0.07, delays=0.06/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B6B682E547)
+L00000011 Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: removed
+
+QENTRY: DEF2520A69
+CTIME: 5E26A944
+SIZE: 161138
+CLIENT: pmghost.mydomain.tld[192.168.1.001]
+MSGID: <redacted:msgid>
+TO:5E26A944:DEF2520A69:A: from <redacted:returnpath@domain.tld> to <redacted:recipient@mydomain.tld> (A673520AB5)
+SMTP:
+L00000001 Jan 21 07:33:20 pmghost postfix/smtpd[29361]: connect from pmghost.mydomain.tld[192.168.1.001]
+L00000002 Jan 21 07:33:20 pmghost postfix/smtpd[29361]: DEF2520A69: client=pmghost.mydomain.tld[192.168.1.001]
+L00000007 Jan 21 07:33:21 pmghost postfix/smtpd[29361]: 1855220A70: client=pmghost.mydomain.tld[192.168.1.001]
+L00000008 Jan 21 07:33:21 pmghost postfix/smtpd[29361]: disconnect from pmghost.mydomain.tld[192.168.1.001] ehlo=1 mail=2 rcpt=2 data=2 quit=1 commands=8
+FILTER: 20A9560092030F3374
+L00000006 Jan 21 07:33:21 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: new mail message-id=<redacted:msgid>#012
+L00000009 Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: SA score=1/5 time=3.500 bayes=undefined autolearn=no autolearn_force=no hits=AWL(0.270),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),HTML_EMBEDS(0.001),HTML_FONT_LOW_CONTRAST(0.001),HTML_IMAGE_RATIO_02(0.001),HTML_MESSAGE(0.001),KAM_LOTSOFHASH(0.25),MPART_ALT_DIFF_COUNT(1.483),SPF_HELO_NONE(0.001),SPF_PASS(-0.001)
+L0000000E Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: accept mail to <redacted:recipient@mydomain.tld> (A673520AB5) (rule: default-accept)
+L00000012 Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: processing time: 3.748 seconds (3.5, 0.137, 0)
+QMGR:
+L00000003 Jan 21 07:33:20 pmghost postfix/cleanup[29364]: DEF2520A69: message-id=<redacted:msgid>
+L00000004 Jan 21 07:33:20 pmghost postfix/cleanup[29364]: DEF2520A69: message-id=<redacted:msgid>
+L00000005 Jan 21 07:33:20 pmghost postfix/qmgr[529]: DEF2520A69: from=<redacted:returnpath@domain.tld>, size=161138, nrcpt=1 (queue active)
+L00000013 Jan 21 07:33:24 pmghost postfix/lmtp[29365]: DEF2520A69: to=<redacted:recipient@mydomain.tld>, relay=127.0.0.1[127.0.0.1]:10024, delay=3.9, delays=0.05/0.04/0.01/3.8, dsn=2.5.0, status=sent (250 2.5.0 OK (20A9560092030F3374))
+L00000014 Jan 21 07:33:24 pmghost postfix/qmgr[529]: DEF2520A69: removed
+
diff --git a/tests/tests_after_queue.rs b/tests/tests_after_queue.rs
index 2a8e637..5349889 100644
--- a/tests/tests_after_queue.rs
+++ b/tests/tests_after_queue.rs
@@ -172,3 +172,26 @@ fn after_queue_relay_before_lmtp() {
let output_reader = BufReader::new(&output.stdout[..]);
utils::compare_output(output_reader, expected_output);
}
+
+#[test]
+fn after_queue_duplicate_msgid() {
+ let output = Command::new("faketime")
+ .arg("2020-12-31 23:59:59")
+ .arg(utils::log_tracker_path())
+ .arg("-vv")
+ .arg("-s")
+ .arg("2020-01-21 07:30:00")
+ .arg("-e")
+ .arg("2020-01-21 07:35:00")
+ .arg("-i")
+ .arg("tests/test_input_after_queue_duplicate_msgid")
+ .output()
+ .expect("failed to execute pmg-log-tracker");
+
+ let expected_file = File::open("tests/test_output_after_queue_duplicate_msgid")
+ .expect("failed to open test_output");
+
+ let expected_output = BufReader::new(&expected_file);
+ let output_reader = BufReader::new(&output.stdout[..]);
+ utils::compare_output(output_reader, expected_output);
+}
--
2.20.1
next reply other threads:[~2021-04-29 13:32 UTC|newest]
Thread overview: 3+ messages / expand[flat|nested] mbox.gz Atom feed top
2021-04-29 13:25 Mira Limbeck [this message]
2021-04-29 13:38 ` Aaron Lauterer
2021-05-11 14:16 ` [pmg-devel] applied: " Thomas Lamprecht
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20210429132508.29570-1-m.limbeck@proxmox.com \
--to=m.limbeck@proxmox.com \
--cc=pmg-devel@lists.proxmox.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox