public inbox for pmg-devel@lists.proxmox.com
 help / color / mirror / Atom feed
* [pmg-devel] [PATCH log-tracker 1/3] update tests
@ 2021-02-19 10:31 Mira Limbeck
  2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 2/3] after-queue: fix wrong DStatus if relay is 'removed' before 'lmtp' line Mira Limbeck
                   ` (2 more replies)
  0 siblings, 3 replies; 9+ messages in thread
From: Mira Limbeck @ 2021-02-19 10:31 UTC (permalink / raw)
  To: pmg-devel

As we only have month, day and time available but not the year, we have
to update the tests every year.

Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
 tests/test_output_after_queue                 | 34 ++++++------
 tests/test_output_after_queue_host            | 18 +++----
 tests/test_output_after_queue_qid             |  4 +-
 tests/test_output_after_queue_search_string   |  6 +--
 tests/test_output_before_queue                | 40 +++++++-------
 tests/test_output_before_queue_from_to        |  6 +--
 tests/test_output_before_queue_host           | 34 ++++++------
 ...before_queue_mixed_accept_block_quarantine |  8 +--
 .../test_output_before_queue_mixed_downstream | 12 ++---
 tests/test_output_before_queue_qid            | 10 ++--
 tests/test_output_before_queue_search_string  | 12 ++---
 tests/test_output_before_queue_syntax_reject  |  6 +--
 tests/test_output_before_queue_to             |  6 +--
 .../test_output_before_queue_to_search_string | 18 +++----
 tests/tests_after_queue.rs                    | 24 ++++-----
 tests/tests_before_queue.rs                   | 52 +++++++++----------
 16 files changed, 145 insertions(+), 145 deletions(-)

diff --git a/tests/test_output_after_queue b/tests/test_output_after_queue
index ec2fc65..ae7c5d2 100644
--- a/tests/test_output_after_queue
+++ b/tests/test_output_after_queue
@@ -5,11 +5,11 @@
 # End Query Options
 
 QENTRY: 21BCE3807B6
-CTIME: 5FDCCEB8
+CTIME: 61BE0238
 SIZE: 2053
 CLIENT: pmg.localhost[192.168.22.40]
 MSGID: <xyz>
-TO:5FDCCEB8:21BCE3807B6:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (381C6F5DFA39502F470)
+TO:61BE0238:21BCE3807B6:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (381C6F5DFA39502F470)
 SMTP:
 L00000002 Dec 18 15:46:00 pmg postfix/smtpd[24784]: connect from pmg.localhost[192.168.22.40]
 L00000003 Dec 18 15:46:00 pmg postfix/smtpd[24784]: 21BCE3807B6: client=pmg.localhost[192.168.22.40]
@@ -25,14 +25,14 @@ L0000000A Dec 18 15:46:00 pmg postfix/lmtp[24788]: 21BCE3807B6: to=<pmgtest@loca
 L0000000B Dec 18 15:46:00 pmg postfix/qmgr[24651]: 21BCE3807B6: removed
 
 QENTRY: CFC5F42740
-CTIME: 5FDCCFCE
+CTIME: 61BE034E
 SIZE: 7102
 CLIENT: test.localdomain[192.168.22.40]
 MSGID: <xyz>
-TO:5FDCCFCE:CFC5F42740:A: from <test@test.localdomain> to <test4@localhost> (88F2E42667)
-TO:5FDCCFCE:CFC5F42740:A: from <test@test.localdomain> to <test3@localhost> (88F2E42667)
-TO:5FDCCFCE:CFC5F42740:A: from <test@test.localdomain> to <test2@localhost> (88F2E42667)
-TO:5FDCCFCE:CFC5F42740:A: from <test@test.localdomain> to <test1@localhost> (88F2E42667)
+TO:61BE034E:CFC5F42740:A: from <test@test.localdomain> to <test4@localhost> (88F2E42667)
+TO:61BE034E:CFC5F42740:A: from <test@test.localdomain> to <test3@localhost> (88F2E42667)
+TO:61BE034E:CFC5F42740:A: from <test@test.localdomain> to <test2@localhost> (88F2E42667)
+TO:61BE034E:CFC5F42740:A: from <test@test.localdomain> to <test1@localhost> (88F2E42667)
 SMTP:
 L0000000C Dec 18 15:50:34 proxmox-new postfix/smtpd[13169]: connect from test.localdomain[192.168.22.40]
 L0000000D Dec 18 15:50:34 proxmox-new postfix/smtpd[13169]: CFC5F42740: client=test.localdomain[192.168.22.40]
@@ -55,14 +55,14 @@ L00000022 Dec 18 15:50:38 proxmox-new postfix/lmtp[13174]: CFC5F42740: to=<test4
 L00000023 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: CFC5F42740: removed
 
 QENTRY: 88F2E42667
-CTIME: 5FDCCFCE
+CTIME: 61BE034E
 SIZE: 8037
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <xyz>
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
 SMTP:
 L00000014 Dec 18 15:50:38 proxmox-new postfix/smtpd[13179]: connect from localhost.localdomain[127.0.0.1]
 L00000015 Dec 18 15:50:38 proxmox-new postfix/smtpd[13179]: 88F2E42667: client=localhost.localdomain[127.0.0.1], orig_client=test.localdomain[192.168.22.40]
@@ -76,19 +76,19 @@ L00000026 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test3
 L00000027 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test4@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)
 L00000028 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: 88F2E42667: removed
 
-SMTPD: T5FDCCFDAL00000000
-CTIME: 5FDCCFDA
+SMTPD: T61BE035AL00000000
+CTIME: 61BE035A
 CLIENT: 10.0.0.1
-TO:5FDCCFDA:T5FDCCFDAL00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
+TO:61BE035A:T61BE035AL00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
 LOGS:
 L00000029 Dec 18 15:50:50 proxmox-new postfix/postscreen[32700]: NOQUEUE: reject: RCPT from [10.0.0.1]:34453: 550 5.7.1 Service unavailable; client [10.0.0.1] blocked using zen.spamhaus.org; from=<rbl_reject_test@localhost.localdomain>, to=<test@reject.localhost.localdomain>, proto=ESMTP, helo=<localhost.localdomain>
 
 QENTRY: 0022C3801B5
-CTIME: 5FDCD100
+CTIME: 61BE0480
 SIZE: 2053
 CLIENT: pmg.localhost[192.168.22.40]
 MSGID: <dc730f87-0b1d-3ecf-b9a5-5b4d910be95f@localhost>
-TO:5FDCD100:0022C3801B5:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (none)
+TO:61BE0480:0022C3801B5:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (none)
 SMTP:
 L0000002A Dec 18 15:55:43 pmg postfix/smtpd[29323]: connect from pmg.localhost[192.168.22.40]
 L0000002B Dec 18 15:55:44 pmg postfix/smtpd[29323]: 0022C3801B5: client=pmg.localhost[192.168.22.40]
diff --git a/tests/test_output_after_queue_host b/tests/test_output_after_queue_host
index ead669c..dfbcfb1 100644
--- a/tests/test_output_after_queue_host
+++ b/tests/test_output_after_queue_host
@@ -6,11 +6,11 @@
 # End Query Options
 
 QENTRY: 21BCE3807B6
-CTIME: 5FDCCEB8
+CTIME: 61BE0238
 SIZE: 2053
 CLIENT: pmg.localhost[192.168.22.40]
 MSGID: <xyz>
-TO:5FDCCEB8:21BCE3807B6:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (381C6F5DFA39502F470)
+TO:61BE0238:21BCE3807B6:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (381C6F5DFA39502F470)
 SMTP:
 L00000002 Dec 18 15:46:00 pmg postfix/smtpd[24784]: connect from pmg.localhost[192.168.22.40]
 L00000003 Dec 18 15:46:00 pmg postfix/smtpd[24784]: 21BCE3807B6: client=pmg.localhost[192.168.22.40]
@@ -26,14 +26,14 @@ L0000000A Dec 18 15:46:00 pmg postfix/lmtp[24788]: 21BCE3807B6: to=<pmgtest@loca
 L0000000B Dec 18 15:46:00 pmg postfix/qmgr[24651]: 21BCE3807B6: removed
 
 QENTRY: 88F2E42667
-CTIME: 5FDCCFCE
+CTIME: 61BE034E
 SIZE: 8037
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <xyz>
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCFCE:88F2E42667:2: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE034E:88F2E42667:2: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
 SMTP:
 L00000014 Dec 18 15:50:38 proxmox-new postfix/smtpd[13179]: connect from localhost.localdomain[127.0.0.1]
 L00000015 Dec 18 15:50:38 proxmox-new postfix/smtpd[13179]: 88F2E42667: client=localhost.localdomain[127.0.0.1], orig_client=test.localdomain[192.168.22.40]
@@ -48,11 +48,11 @@ L00000027 Dec 18 15:50:38 proxmox-new postfix/smtp[13180]: 88F2E42667: to=<test4
 L00000028 Dec 18 15:50:38 proxmox-new postfix/qmgr[18171]: 88F2E42667: removed
 
 QENTRY: 0022C3801B5
-CTIME: 5FDCD100
+CTIME: 61BE0480
 SIZE: 2053
 CLIENT: pmg.localhost[192.168.22.40]
 MSGID: <dc730f87-0b1d-3ecf-b9a5-5b4d910be95f@localhost>
-TO:5FDCD100:0022C3801B5:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (none)
+TO:61BE0480:0022C3801B5:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (none)
 SMTP:
 L0000002A Dec 18 15:55:43 pmg postfix/smtpd[29323]: connect from pmg.localhost[192.168.22.40]
 L0000002B Dec 18 15:55:44 pmg postfix/smtpd[29323]: 0022C3801B5: client=pmg.localhost[192.168.22.40]
diff --git a/tests/test_output_after_queue_qid b/tests/test_output_after_queue_qid
index 6cc9a9e..012712f 100644
--- a/tests/test_output_after_queue_qid
+++ b/tests/test_output_after_queue_qid
@@ -6,11 +6,11 @@
 # End Query Options
 
 QENTRY: 0022C3801B5
-CTIME: 5FDCD100
+CTIME: 61BE0480
 SIZE: 2053
 CLIENT: pmg.localhost[192.168.22.40]
 MSGID: <dc730f87-0b1d-3ecf-b9a5-5b4d910be95f@localhost>
-TO:5FDCD100:0022C3801B5:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (none)
+TO:61BE0480:0022C3801B5:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost> (none)
 SMTP:
 L0000002A Dec 18 15:55:43 pmg postfix/smtpd[29323]: connect from pmg.localhost[192.168.22.40]
 L0000002B Dec 18 15:55:44 pmg postfix/smtpd[29323]: 0022C3801B5: client=pmg.localhost[192.168.22.40]
diff --git a/tests/test_output_after_queue_search_string b/tests/test_output_after_queue_search_string
index dbd985b..53bc03f 100644
--- a/tests/test_output_after_queue_search_string
+++ b/tests/test_output_after_queue_search_string
@@ -5,10 +5,10 @@
 # END:       2020-12-18 16:00:00 (1608307200)
 # End Query Options
 
-SMTPD: T5FDCCFDAL00000000
-CTIME: 5FDCCFDA
+SMTPD: T61BE035AL00000000
+CTIME: 61BE035A
 CLIENT: 10.0.0.1
-TO:5FDCCFDA:T5FDCCFDAL00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
+TO:61BE035A:T61BE035AL00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
 LOGS:
 L00000029 Dec 18 15:50:50 proxmox-new postfix/postscreen[32700]: NOQUEUE: reject: RCPT from [10.0.0.1]:34453: 550 5.7.1 Service unavailable; client [10.0.0.1] blocked using zen.spamhaus.org; from=<rbl_reject_test@localhost.localdomain>, to=<test@reject.localhost.localdomain>, proto=ESMTP, helo=<localhost.localdomain>
 
diff --git a/tests/test_output_before_queue b/tests/test_output_before_queue
index aca61b9..394f539 100644
--- a/tests/test_output_before_queue
+++ b/tests/test_output_before_queue
@@ -4,10 +4,10 @@
 # End: 2020-12-18 15:40:00 (1608306000)
 # End Query Options
 
-SMTPD: T5FDCC4EFL00000000
-CTIME: 5FDCC4EF
+SMTPD: T61BDF86FL00000000
+CTIME: 61BDF86F
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC4EF:T5FDCC4EFL00000000:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF86F:T61BDF86FL00000000:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L00000002 Dec 18 15:04:15 pmg postfix/smtpd[21842]: connect from pmg.localhost[192.168.22.40]
 L00000003 Dec 18 15:04:15 pmg postfix/smtpd[21842]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -17,10 +17,10 @@ L00000007 Dec 18 15:04:15 pmg pmg-smtp-filter[1565]: 381C4E5DFA31DF9E90F: proces
 L00000008 Dec 18 15:04:15 pmg postfix/smtpd[21842]: proxy-reject: END-OF-MESSAGE: 554 5.7.1 Rejected for policy reasons (381C4E5DFA31DF9E90F); from=<mailtestsender2@localhost.localdomain> to=<pmgtest@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L00000009 Dec 18 15:04:15 pmg postfix/smtpd[21842]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=0/1 commands=3/4
 
-SMTPD: T5FDCC572L00000000
-CTIME: 5FDCC572
+SMTPD: T61BDF8F2L00000000
+CTIME: 61BDF8F2
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC572:T5FDCC572L00000000:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF8F2:T61BDF8F2L00000000:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L0000000A Dec 18 15:06:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L0000000B Dec 18 15:06:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -30,10 +30,10 @@ L00000010 Dec 18 15:06:26 pmg pmg-smtp-filter[1564]: 381C4E5DFA32622BFC4: proces
 L00000011 Dec 18 15:06:26 pmg postfix/smtpd[21949]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (381C4E5DFA32622BFC4); from=<mailtestsender2@localhost.localdomain> to=<pmgtest@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L00000012 Dec 18 15:06:26 pmg postfix/smtpd[21949]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=1 commands=4
 
-SMTPD: T5FDCC5EAL00000000
-CTIME: 5FDCC5EA
+SMTPD: T61BDF96AL00000000
+CTIME: 61BDF96A
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC5EA:T5FDCC5EAL00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtes2@localhost.localdomain>
+TO:61BDF96A:T61BDF96AL00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtes2@localhost.localdomain>
 LOGS:
 L00000013 Dec 18 15:08:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L00000014 Dec 18 15:08:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -43,10 +43,10 @@ L00000019 Dec 18 15:08:26 pmg pmg-smtp-filter[1564]: 381C4E5DFA32622BFC4: proces
 L0000001A Dec 18 15:08:26 pmg postfix/smtpd[21949]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (381C4E5DFA32622BFC4); from=<mailtestsender3@localhost.localdomain> to=<pmgtes2@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L0000001B Dec 18 15:08:26 pmg postfix/smtpd[21949]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=1 commands=4
 
-SMTPD: T5FDCC662L00000000
-CTIME: 5FDCC662
+SMTPD: T61BDF9E2L00000000
+CTIME: 61BDF9E2
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC662:T5FDCC662L00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF9E2:T61BDF9E2L00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L0000001C Dec 18 15:10:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L0000001D Dec 18 15:10:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -57,14 +57,14 @@ L00000023 Dec 18 15:10:26 pmg postfix/smtpd[21949]: proxy-accept: END-OF-MESSAGE
 L00000024 Dec 18 15:10:26 pmg postfix/smtpd[21949]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=1 commands=4
 
 QENTRY: 1C6B541C5D
-CTIME: 5FDCCD39
+CTIME: 61BE00B9
 SIZE: 7298
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <xyz>
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
 SMTP:
 L00000025 Dec 18 15:36:32 proxmox-new postfix/smtpd[29902]: connect from test.localdomain[192.168.22.40]
 L00000026 Dec 18 15:36:33 proxmox-new postfix/smtpd[29902]: NOQUEUE: client=test.localdomain[192.168.22.40]
@@ -90,10 +90,10 @@ L00000036 Dec 18 15:36:37 proxmox-new postfix/smtp[29913]: 1C6B541C5D: to=<test3
 L00000037 Dec 18 15:36:37 proxmox-new postfix/smtp[29913]: 1C6B541C5D: to=<test4@localhost>, relay=192.168.22.40[192.168.22.40]:25, delay=0.15, delays=0.05/0/0.05/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C19A3F62578)
 L00000038 Dec 18 15:36:37 proxmox-new postfix/qmgr[6194]: 1C6B541C5D: removed
 
-SMTPD: T5FDCCD46L00000000
-CTIME: 5FDCCD46
+SMTPD: T61BE00C6L00000000
+CTIME: 61BE00C6
 CLIENT: 10.0.0.1
-TO:5FDCCD46:T5FDCCD46L00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
+TO:61BE00C6:T61BE00C6L00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
 LOGS:
 L0000003A Dec 18 15:39:50 proxmox-new postfix/postscreen[32700]: NOQUEUE: reject: RCPT from [10.0.0.1]:34453: 550 5.7.1 Service unavailable; client [10.0.0.1] blocked using zen.spamhaus.org; from=<rbl_reject_test@localhost.localdomain>, to=<test@reject.localhost.localdomain>, proto=ESMTP, helo=<localhost.localdomain>
 
diff --git a/tests/test_output_before_queue_from_to b/tests/test_output_before_queue_from_to
index 610bf34..a273edb 100644
--- a/tests/test_output_before_queue_from_to
+++ b/tests/test_output_before_queue_from_to
@@ -6,10 +6,10 @@
 # End: 2020-12-18 15:40:00 (1608306000)
 # End Query Options
 
-SMTPD: T5FDCC662L00000000
-CTIME: 5FDCC662
+SMTPD: T61BDF9E2L00000000
+CTIME: 61BDF9E2
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC662:T5FDCC662L00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF9E2:T61BDF9E2L00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L0000001C Dec 18 15:10:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L0000001D Dec 18 15:10:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
diff --git a/tests/test_output_before_queue_host b/tests/test_output_before_queue_host
index 4595d25..e668f7f 100644
--- a/tests/test_output_before_queue_host
+++ b/tests/test_output_before_queue_host
@@ -5,10 +5,10 @@
 # End: 2020-12-18 15:40:00 (1608306000)
 # End Query Options
 
-SMTPD: T5FDCC4EFL00000000
-CTIME: 5FDCC4EF
+SMTPD: T61BDF86FL00000000
+CTIME: 61BDF86F
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC4EF:T5FDCC4EFL00000000:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF86F:T61BDF86FL00000000:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L00000002 Dec 18 15:04:15 pmg postfix/smtpd[21842]: connect from pmg.localhost[192.168.22.40]
 L00000003 Dec 18 15:04:15 pmg postfix/smtpd[21842]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -18,10 +18,10 @@ L00000007 Dec 18 15:04:15 pmg pmg-smtp-filter[1565]: 381C4E5DFA31DF9E90F: proces
 L00000008 Dec 18 15:04:15 pmg postfix/smtpd[21842]: proxy-reject: END-OF-MESSAGE: 554 5.7.1 Rejected for policy reasons (381C4E5DFA31DF9E90F); from=<mailtestsender2@localhost.localdomain> to=<pmgtest@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L00000009 Dec 18 15:04:15 pmg postfix/smtpd[21842]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=0/1 commands=3/4
 
-SMTPD: T5FDCC572L00000000
-CTIME: 5FDCC572
+SMTPD: T61BDF8F2L00000000
+CTIME: 61BDF8F2
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC572:T5FDCC572L00000000:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF8F2:T61BDF8F2L00000000:Q: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L0000000A Dec 18 15:06:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L0000000B Dec 18 15:06:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -31,10 +31,10 @@ L00000010 Dec 18 15:06:26 pmg pmg-smtp-filter[1564]: 381C4E5DFA32622BFC4: proces
 L00000011 Dec 18 15:06:26 pmg postfix/smtpd[21949]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (381C4E5DFA32622BFC4); from=<mailtestsender2@localhost.localdomain> to=<pmgtest@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L00000012 Dec 18 15:06:26 pmg postfix/smtpd[21949]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=1 commands=4
 
-SMTPD: T5FDCC5EAL00000000
-CTIME: 5FDCC5EA
+SMTPD: T61BDF96AL00000000
+CTIME: 61BDF96A
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC5EA:T5FDCC5EAL00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtes2@localhost.localdomain>
+TO:61BDF96A:T61BDF96AL00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtes2@localhost.localdomain>
 LOGS:
 L00000013 Dec 18 15:08:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L00000014 Dec 18 15:08:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -44,10 +44,10 @@ L00000019 Dec 18 15:08:26 pmg pmg-smtp-filter[1564]: 381C4E5DFA32622BFC4: proces
 L0000001A Dec 18 15:08:26 pmg postfix/smtpd[21949]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (381C4E5DFA32622BFC4); from=<mailtestsender3@localhost.localdomain> to=<pmgtes2@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L0000001B Dec 18 15:08:26 pmg postfix/smtpd[21949]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=1 commands=4
 
-SMTPD: T5FDCC662L00000000
-CTIME: 5FDCC662
+SMTPD: T61BDF9E2L00000000
+CTIME: 61BDF9E2
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC662:T5FDCC662L00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF9E2:T61BDF9E2L00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L0000001C Dec 18 15:10:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L0000001D Dec 18 15:10:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -58,14 +58,14 @@ L00000023 Dec 18 15:10:26 pmg postfix/smtpd[21949]: proxy-accept: END-OF-MESSAGE
 L00000024 Dec 18 15:10:26 pmg postfix/smtpd[21949]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=1 commands=4
 
 QENTRY: 1C6B541C5D
-CTIME: 5FDCCD39
+CTIME: 61BE00B9
 SIZE: 7298
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <xyz>
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
 SMTP:
 L00000025 Dec 18 15:36:32 proxmox-new postfix/smtpd[29902]: connect from test.localdomain[192.168.22.40]
 L00000026 Dec 18 15:36:33 proxmox-new postfix/smtpd[29902]: NOQUEUE: client=test.localdomain[192.168.22.40]
diff --git a/tests/test_output_before_queue_mixed_accept_block_quarantine b/tests/test_output_before_queue_mixed_accept_block_quarantine
index 7495a78..2c4ad66 100644
--- a/tests/test_output_before_queue_mixed_accept_block_quarantine
+++ b/tests/test_output_before_queue_mixed_accept_block_quarantine
@@ -5,13 +5,13 @@
 # End Query Options
 
 QENTRY: E1C6561393
-CTIME: 5EAAF183
+CTIME: 608C2503
 SIZE: 1436
 CLIENT: localhost[127.0.0.1],
 MSGID: <20200430134439.GE6794@test@localdomain>
-TO:5EAAF179:E1C6561393:R: from <senduser@test@localdomain> to <reject@test.recipient.example> (192.0.2.69[192.0.2.69]:25)
-TO:5EAAF178:E1C6561393:B: from <senduser@test@localdomain> to <blocked@test.recipient.example> (none)
-TO:5EAAF178:E1C6561393:Q: from <senduser@test@localdomain> to <quarantined@test.recipient.example> (612405EAAD648755DD)
+TO:608C24F9:E1C6561393:R: from <senduser@test@localdomain> to <reject@test.recipient.example> (192.0.2.69[192.0.2.69]:25)
+TO:608C24F8:E1C6561393:B: from <senduser@test@localdomain> to <blocked@test.recipient.example> (none)
+TO:608C24F8:E1C6561393:Q: from <senduser@test@localdomain> to <quarantined@test.recipient.example> (612405EAAD648755DD)
 SMTP:
 L00000003 Apr 30 15:40:39 pmg6 postfix/smtpd[21615]: connect from unknown[2001:DB8:1:12::75]
 L00000004 Apr 30 15:40:39 pmg6 postfix/smtpd[21615]: Anonymous TLS connection established from unknown[2001:DB8:1:12::75]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits)
diff --git a/tests/test_output_before_queue_mixed_downstream b/tests/test_output_before_queue_mixed_downstream
index 450f509..41e4581 100644
--- a/tests/test_output_before_queue_mixed_downstream
+++ b/tests/test_output_before_queue_mixed_downstream
@@ -5,17 +5,17 @@
 # End Query Options
 
 QENTRY: E2487636D9
-CTIME: 5FDCD233
+CTIME: 61BE05B3
 SIZE: 3628
 MSGID: <20200428171350.E2487636D9@pmg6.rosa.proxmox.com>
-TO:5FDCD233:E2487636D9:2: from <> to <sender@test.localdomain> (test.localdomain[192.0.2.0.70]:25)
+TO:61BE05B3:E2487636D9:2: from <> to <sender@test.localdomain> (test.localdomain[192.0.2.0.70]:25)
 
 QENTRY: B8010636D6
-CTIME: 5FDCD233
+CTIME: 61BE05B3
 SIZE: 1436
 CLIENT: localhost[127.0.0.1],
 MSGID: <20200428171349.GC5963@test.localdomain>
-TO:5FDCD232:B8010636D6:P: from <sender@test.localdomain> to <discard@test.recipient.example> (192.0.2.0.69[192.0.2.0.69]:25)
-TO:5FDCD232:B8010636D6:R: from <sender@test.localdomain> to <reject@test.recipient.example> (192.0.2.0.69[192.0.2.0.69]:25)
-TO:5FDCD232:B8010636D6:D: from <sender@test.localdomain> to <defer@test.recipient.example> (192.0.2.0.69[192.0.2.0.69]:25)
+TO:61BE05B2:B8010636D6:P: from <sender@test.localdomain> to <discard@test.recipient.example> (192.0.2.0.69[192.0.2.0.69]:25)
+TO:61BE05B2:B8010636D6:R: from <sender@test.localdomain> to <reject@test.recipient.example> (192.0.2.0.69[192.0.2.0.69]:25)
+TO:61BE05B2:B8010636D6:D: from <sender@test.localdomain> to <defer@test.recipient.example> (192.0.2.0.69[192.0.2.0.69]:25)
 
diff --git a/tests/test_output_before_queue_qid b/tests/test_output_before_queue_qid
index e2eb137..0fcbca7 100644
--- a/tests/test_output_before_queue_qid
+++ b/tests/test_output_before_queue_qid
@@ -6,14 +6,14 @@
 # End Query Options
 
 QENTRY: 1C6B541C5D
-CTIME: 5FDCCD39
+CTIME: 61BE00B9
 SIZE: 7298
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <xyz>
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
-TO:5FDCCC85:1C6B541C5D:P: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test4@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test3@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test2@localhost> (192.168.22.40[192.168.22.40]:25)
+TO:61BE0005:1C6B541C5D:P: from <test@test.localdomain> to <test1@localhost> (192.168.22.40[192.168.22.40]:25)
 SMTP:
 L00000025 Dec 18 15:36:32 proxmox-new postfix/smtpd[29902]: connect from test.localdomain[192.168.22.40]
 L00000026 Dec 18 15:36:33 proxmox-new postfix/smtpd[29902]: NOQUEUE: client=test.localdomain[192.168.22.40]
diff --git a/tests/test_output_before_queue_search_string b/tests/test_output_before_queue_search_string
index da04042..f20c33e 100644
--- a/tests/test_output_before_queue_search_string
+++ b/tests/test_output_before_queue_search_string
@@ -5,10 +5,10 @@
 # End: 2020-12-18 15:40:00 (1608306000)
 # End Query Options
 
-SMTPD: T5FDCC4EFL00000000
-CTIME: 5FDCC4EF
+SMTPD: T61BDF86FL00000000
+CTIME: 61BDF86F
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC4EF:T5FDCC4EFL00000000:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
+TO:61BDF86F:T61BDF86FL00000000:B: from <mailtestsender2@localhost.localdomain> to <pmgtest@localhost.localdomain>
 LOGS:
 L00000002 Dec 18 15:04:15 pmg postfix/smtpd[21842]: connect from pmg.localhost[192.168.22.40]
 L00000003 Dec 18 15:04:15 pmg postfix/smtpd[21842]: NOQUEUE: client=pmg.localhost[192.168.22.40]
@@ -18,10 +18,10 @@ L00000007 Dec 18 15:04:15 pmg pmg-smtp-filter[1565]: 381C4E5DFA31DF9E90F: proces
 L00000008 Dec 18 15:04:15 pmg postfix/smtpd[21842]: proxy-reject: END-OF-MESSAGE: 554 5.7.1 Rejected for policy reasons (381C4E5DFA31DF9E90F); from=<mailtestsender2@localhost.localdomain> to=<pmgtest@localhost.localdomain> proto=ESMTP helo=<localhost.localdomain>
 L00000009 Dec 18 15:04:15 pmg postfix/smtpd[21842]: disconnect from pmg.localhost[192.168.22.40] ehlo=1 mail=1 rcpt=1 data=0/1 commands=3/4
 
-SMTPD: T5FDCCD46L00000000
-CTIME: 5FDCCD46
+SMTPD: T61BE00C6L00000000
+CTIME: 61BE00C6
 CLIENT: 10.0.0.1
-TO:5FDCCD46:T5FDCCD46L00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
+TO:61BE00C6:T61BE00C6L00000000:N: from <rbl_reject_test@localhost.localdomain> to <test@reject.localhost.localdomain>
 LOGS:
 L0000003A Dec 18 15:39:50 proxmox-new postfix/postscreen[32700]: NOQUEUE: reject: RCPT from [10.0.0.1]:34453: 550 5.7.1 Service unavailable; client [10.0.0.1] blocked using zen.spamhaus.org; from=<rbl_reject_test@localhost.localdomain>, to=<test@reject.localhost.localdomain>, proto=ESMTP, helo=<localhost.localdomain>
 
diff --git a/tests/test_output_before_queue_syntax_reject b/tests/test_output_before_queue_syntax_reject
index 5be90db..8a0b802 100644
--- a/tests/test_output_before_queue_syntax_reject
+++ b/tests/test_output_before_queue_syntax_reject
@@ -4,10 +4,10 @@
 # End: 2020-08-27 14:05:00 (1598537100)
 # End Query Options
 
-SMTPD: T5F47BD58L00000000
-CTIME: 5F47BD58
+SMTPD: T6128F0D8L00000000
+CTIME: 6128F0D8
 CLIENT: pmgsender[192.168.22.40]
-TO:5F47BD58:T5F47BD58L00000000:N: from <test@pmgsender.local> to <test@pmgreceiver.local>
+TO:6128F0D8:T6128F0D8L00000000:N: from <test@pmgsender.local> to <test@pmgreceiver.local>
 LOGS:
 L00000001 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: connect from pmgsender[192.168.22.40]
 L00000002 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: Anonymous TLS connection established from pmgsender[192.168.22.40]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256
diff --git a/tests/test_output_before_queue_to b/tests/test_output_before_queue_to
index 49793dd..9a944f1 100644
--- a/tests/test_output_before_queue_to
+++ b/tests/test_output_before_queue_to
@@ -5,10 +5,10 @@
 # End: 2020-12-18 15:40:00 (1608306000)
 # End Query Options
 
-SMTPD: T5FDCC5EAL00000000
-CTIME: 5FDCC5EA
+SMTPD: T61BDF96AL00000000
+CTIME: 61BDF96A
 CLIENT: pmg.localhost[192.168.22.40]
-TO:5FDCC5EA:T5FDCC5EAL00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtes2@localhost.localdomain>
+TO:61BDF96A:T61BDF96AL00000000:Q: from <mailtestsender3@localhost.localdomain> to <pmgtes2@localhost.localdomain>
 LOGS:
 L00000013 Dec 18 15:08:26 pmg postfix/smtpd[21949]: connect from pmg.localhost[192.168.22.40]
 L00000014 Dec 18 15:08:26 pmg postfix/smtpd[21949]: NOQUEUE: client=pmg.localhost[192.168.22.40]
diff --git a/tests/test_output_before_queue_to_search_string b/tests/test_output_before_queue_to_search_string
index 5fe963a..fc022f2 100644
--- a/tests/test_output_before_queue_to_search_string
+++ b/tests/test_output_before_queue_to_search_string
@@ -6,10 +6,10 @@
 # End: 2020-05-18 16:10:00 (1589818200)
 # End Query Options
 
-SMTPD: T5EC2B077L00000002
-CTIME: 5EC2B077
+SMTPD: T60A3E3F7L00000002
+CTIME: 60A3E3F7
 CLIENT: pmg-demo.proxmox.com[192.168.30.128]
-TO:5EC2B077:T5EC2B077L00000002:B: from <mailtestsender.bad@proxtest.com> to <ferdl@example.proxmox.com>
+TO:60A3E3F7:T60A3E3F7L00000002:B: from <mailtestsender.bad@proxtest.com> to <ferdl@example.proxmox.com>
 LOGS:
 L00000003 May 18 15:57:43 pmg-demo postfix/smtpd[16982]: connect from pmg-demo.proxmox.com[192.168.30.128]
 L00000004 May 18 15:57:43 pmg-demo postfix/smtpd[16982]: NOQUEUE: client=pmg-demo.proxmox.com[192.168.30.128]
@@ -22,11 +22,11 @@ L0000000B May 18 15:57:43 pmg-demo postfix/smtpd[16982]: proxy-accept: END-OF-ME
 L0000000C May 18 15:57:43 pmg-demo postfix/smtpd[16982]: disconnect from pmg-demo.proxmox.com[192.168.30.128] ehlo=1 mail=1 rcpt=2 data=1 commands=5
 
 QENTRY: 6B2CD3209E0
-CTIME: 5EC2B1EB
+CTIME: 60A3E56B
 SIZE: 2342
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <20200518140355.6B2CD3209E0@pmg-demo.proxmox.com>
-TO:5EC2B1EB:6B2CD3209E0:B: from <mailtestsender.good@proxtest.com> to <ferdl@example.proxmox.com> (none)
+TO:60A3E56B:6B2CD3209E0:B: from <mailtestsender.good@proxtest.com> to <ferdl@example.proxmox.com> (none)
 SMTP:
 L00000024 May 18 16:03:55 pmg-demo postfix/smtpd[16982]: connect from pmg-demo.proxmox.com[192.168.30.128]
 L00000025 May 18 16:03:55 pmg-demo postfix/smtpd[16982]: NOQUEUE: client=pmg-demo.proxmox.com[192.168.30.128]
@@ -48,11 +48,11 @@ L00000033 May 18 16:03:55 pmg-demo postfix/smtp[17728]: 6B2CD3209E0: to=<office@
 L00000034 May 18 16:03:55 pmg-demo postfix/qmgr[1097]: 6B2CD3209E0: removed
 
 QENTRY: 264C33209E0
-CTIME: 5EC2B303
+CTIME: 60A3E683
 SIZE: 2339
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <20200518140835.264C33209E0@pmg-demo.proxmox.com>
-TO:5EC2B303:264C33209E0:B: from <mailtestsender.good@proxtest.com> to <ferdl@example.proxmox.com> (none)
+TO:60A3E683:264C33209E0:B: from <mailtestsender.good@proxtest.com> to <ferdl@example.proxmox.com> (none)
 SMTP:
 L00000037 May 18 16:08:34 pmg-demo postfix/smtpd[16982]: connect from pmg-demo.proxmox.com[192.168.30.128]
 L00000038 May 18 16:08:34 pmg-demo postfix/smtpd[16982]: NOQUEUE: client=pmg-demo.proxmox.com[192.168.30.128]
@@ -74,11 +74,11 @@ L00000046 May 18 16:08:35 pmg-demo postfix/smtp[17728]: 264C33209E0: to=<ceo@exa
 L00000047 May 18 16:08:35 pmg-demo postfix/qmgr[1097]: 264C33209E0: removed
 
 QENTRY: 86D0C3209DE
-CTIME: 5EC2B344
+CTIME: 60A3E6C4
 SIZE: 2932
 CLIENT: localhost.localdomain[127.0.0.1],
 MSGID: <20200518140940.86D0C3209DE@pmg-demo.proxmox.com>
-TO:5EC2B344:86D0C3209DE:B: from <mailtestsender.good@proxtest.com> to <ferdl@example.proxmox.com> (none)
+TO:60A3E6C4:86D0C3209DE:B: from <mailtestsender.good@proxtest.com> to <ferdl@example.proxmox.com> (none)
 SMTP:
 L0000004A May 18 16:09:39 pmg-demo postfix/smtpd[16982]: connect from pmg-demo.proxmox.com[192.168.30.128]
 L0000004B May 18 16:09:39 pmg-demo postfix/smtpd[16982]: NOQUEUE: client=pmg-demo.proxmox.com[192.168.30.128]
diff --git a/tests/tests_after_queue.rs b/tests/tests_after_queue.rs
index f479325..8a66887 100644
--- a/tests/tests_after_queue.rs
+++ b/tests/tests_after_queue.rs
@@ -9,9 +9,9 @@ fn after_queue_start_end_time_string() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("2020-12-18 15:40:00")
+        .arg("2021-12-18 15:40:00")
         .arg("-e")
-        .arg("2020-12-18 16:00:00")
+        .arg("2021-12-18 16:00:00")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .output()
@@ -30,9 +30,9 @@ fn after_queue_start_end_timestamp() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-e")
-        .arg("1608303600")
+        .arg("1639839600")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .output()
@@ -51,9 +51,9 @@ fn after_queue_qid() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-e")
-        .arg("1608303600")
+        .arg("1639839600")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-q")
@@ -74,9 +74,9 @@ fn after_queue_host() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-e")
-        .arg("1608303600")
+        .arg("1639839600")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-h")
@@ -97,9 +97,9 @@ fn after_queue_search_string() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-e")
-        .arg("1608303600")
+        .arg("1639839600")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-x")
@@ -120,9 +120,9 @@ fn after_queue_search_string_case_insensitive() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-e")
-        .arg("1608303600")
+        .arg("1639839600")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-x")
diff --git a/tests/tests_before_queue.rs b/tests/tests_before_queue.rs
index 5f36ec2..77b6ab5 100644
--- a/tests/tests_before_queue.rs
+++ b/tests/tests_before_queue.rs
@@ -8,9 +8,9 @@ fn before_queue_start_end_time_string() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("2020-12-18 15:00:00")
+        .arg("2021-12-18 15:00:00")
         .arg("-e")
-        .arg("2020-12-18 15:40:00")
+        .arg("2021-12-18 15:40:00")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .output()
@@ -29,9 +29,9 @@ fn before_queue_start_end_timestamp() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .output()
@@ -50,9 +50,9 @@ fn before_queue_qid() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-q")
@@ -73,9 +73,9 @@ fn before_queue_host() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-h")
@@ -96,9 +96,9 @@ fn before_queue_search_string() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-x")
@@ -119,9 +119,9 @@ fn before_queue_search_string_case_insensitive() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-x")
@@ -142,9 +142,9 @@ fn before_queue_exclude_greylist_ndr() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-g")
@@ -165,9 +165,9 @@ fn before_queue_to() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-t")
@@ -188,9 +188,9 @@ fn before_queue_mixed_downstream() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-v")
         .arg("-s")
-        .arg("1608303600")
+        .arg("1639839600")
         .arg("-e")
-        .arg("1608304200")
+        .arg("1639840200")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .output()
@@ -209,9 +209,9 @@ fn before_queue_from_to() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1608300000")
+        .arg("1639836000")
         .arg("-e")
-        .arg("1608302400")
+        .arg("1639838400")
         .arg("-i")
         .arg("tests/test_input_mixed")
         .arg("-f")
@@ -234,9 +234,9 @@ fn before_queue_mixed_accept_block_quarantine() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1588254000")
+        .arg("1619790000")
         .arg("-e")
-        .arg("1588255200")
+        .arg("1619791200")
         .arg("-i")
         .arg("tests/test_input_mixed_accept_block_quarantine")
         .arg("-n")
@@ -256,9 +256,9 @@ fn before_queue_to_search_string() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("1589810100")
+        .arg("1621346100")
         .arg("-e")
-        .arg("1589812000")
+        .arg("1621348000")
         .arg("-i")
         .arg("tests/test_input_before_queue_to_search_string")
         .arg("-t")
@@ -281,9 +281,9 @@ fn before_queue_syntax_reject() {
     let output = Command::new(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
-        .arg("2020-08-27 14:00:00")
+        .arg("2021-08-27 14:00:00")
         .arg("-e")
-        .arg("2020-08-27 14:05:00")
+        .arg("2021-08-27 14:05:00")
         .arg("-i")
         .arg("tests/test_input_before_queue_syntax_reject")
         .output()
-- 
2.20.1





^ permalink raw reply	[flat|nested] 9+ messages in thread

* [pmg-devel] [PATCH log-tracker 2/3] after-queue: fix wrong DStatus if relay is 'removed' before 'lmtp' line
  2021-02-19 10:31 [pmg-devel] [PATCH log-tracker 1/3] update tests Mira Limbeck
@ 2021-02-19 10:31 ` Mira Limbeck
  2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 3/3] add test case for relay removed before lmtp Mira Limbeck
  2021-02-25 10:56 ` [pmg-devel] [PATCH log-tracker 1/3] update tests Thomas Lamprecht
  2 siblings, 0 replies; 9+ messages in thread
From: Mira Limbeck @ 2021-02-19 10:31 UTC (permalink / raw)
  To: pmg-devel

We only match a QEntry with the relay Qentry in the after-queue case
when we get to the 'lmtp' line. This is because it contains a reference
from the first QEntry to the filter, and the filter contains a reference
to the relay QEntry.

If the relay log entries are finished before the 'lmtp' line, there's no
way to match the relay to the first QEntry and we still assume it is
before-queue filtered.

To fix this we try to match the QEntries via message-id and add weak
references to each other. Then we wait with finalizing either until the
other is also 'removed' (finished).

The message-id matching might break if the same message-id is used for
different entries, so this is rather a 'hack' than a nice solution, but
there's no other info in the logs we could use to match both QEntries.

Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
This was reported in the forum:
https://forum.proxmox.com/threads/difference-between-status-accepted-accepted-and-accepted-delivered.82827/

 src/main.rs | 51 ++++++++++++++++++++++++++++++++++++++++-----------
 1 file changed, 40 insertions(+), 11 deletions(-)

diff --git a/src/main.rs b/src/main.rs
index 5069252..78d6def 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -427,18 +427,8 @@ fn handle_lmtp_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
         None => return,
     };
 
-    let mut dstatus = DStatus::Dsn(dsn);
+    let dstatus = DStatus::Dsn(dsn);
 
-    // the dsn (enhanced status code can only have a class of 2, 4 or 5
-    // see https://tools.ietf.org/html/rfc3463
-    if qe.borrow_mut().bq_filtered {
-        dstatus = match dsn {
-            2 => DStatus::BqPass,
-            4 => DStatus::BqDefer,
-            5 => DStatus::BqReject,
-            _ => return,
-        }
-    }
     qe.borrow_mut()
         .add_to_entry(to, relay, dstatus, parser.current_record_state.timestamp);
 
@@ -751,6 +741,18 @@ fn handle_cleanup_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8])
             qe.borrow_mut().msgid = msgid.into();
         }
         qe.borrow_mut().cleanup = true;
+
+
+        // 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));
+            if let Some(q) = q.upgrade() {
+                q.borrow_mut().aq_qentry = Some(Rc::downgrade(&qe));
+            }
+        }
+        else {
+            parser.msgid_lookup.insert(msgid.into(), Rc::downgrade(&qe));
+        }
     }
 }
 
@@ -1205,6 +1207,7 @@ struct QEntry {
     bq_filtered: bool,
     // will differ from smtpd
     bq_sentry: Option<Rc<RefCell<SEntry>>>,
+    aq_qentry: Option<Weak<RefCell<QEntry>>>,
 }
 
 impl QEntry {
@@ -1234,6 +1237,16 @@ impl QEntry {
                 }
             }
 
+            if let Some(qe) = &self.aq_qentry {
+                if let Some(qe) = qe.upgrade() {
+                    if !qe.borrow().removed {
+                        return;
+                    }
+                    qe.borrow_mut().aq_qentry = None;
+                    qe.borrow_mut().finalize(parser);
+                }
+            }
+
             if let Some(fe) = self.filter.clone() {
                 // verify that the attached FEntry is finished if it is not
                 // before queue filtered
@@ -1472,12 +1485,26 @@ impl QEntry {
             self.print_qentry_boilerplate(parser, is_se_bq_sentry, se);
         }
 
+        if self.bq_filtered {
+            for to in self.to_entries.iter_mut() {
+                to.dstatus = match to.dstatus {
+                    // the dsn (enhanced status code can only have a class of 2, 4 or 5
+                    // see https://tools.ietf.org/html/rfc3463
+                    DStatus::Dsn(2) => DStatus::BqPass,
+                    DStatus::Dsn(4) => DStatus::BqDefer,
+                    DStatus::Dsn(5) => DStatus::BqReject,
+                    _ => to.dstatus,
+                };
+            }
+        }
+
         // rev() to match the C code iteration direction (linked list vs Vec)
         for to in self.to_entries.iter().rev() {
             if !to.to.is_empty() {
                 let final_rc;
                 let final_borrow;
                 let mut final_to: &ToEntry = to;
+
                 // if status == success and there's a filter attached that has
                 // a matching 'to' in one of the ToEntries, set the ToEntry to
                 // the one in the filter
@@ -1667,6 +1694,7 @@ struct Parser {
     sentries: HashMap<u64, Rc<RefCell<SEntry>>>,
     fentries: HashMap<Box<[u8]>, Rc<RefCell<FEntry>>>,
     qentries: HashMap<Box<[u8]>, Rc<RefCell<QEntry>>>,
+    msgid_lookup: HashMap<Box<[u8]>, Weak<RefCell<QEntry>>>,
 
     current_record_state: RecordState,
     rel_line_nr: u64,
@@ -1705,6 +1733,7 @@ impl Parser {
             sentries: HashMap::new(),
             fentries: HashMap::new(),
             qentries: HashMap::new(),
+            msgid_lookup: HashMap::new(),
             current_record_state: Default::default(),
             rel_line_nr: 0,
             current_year: years,
-- 
2.20.1





^ permalink raw reply	[flat|nested] 9+ messages in thread

* [pmg-devel] [PATCH log-tracker 3/3] add test case for relay removed before lmtp
  2021-02-19 10:31 [pmg-devel] [PATCH log-tracker 1/3] update tests Mira Limbeck
  2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 2/3] after-queue: fix wrong DStatus if relay is 'removed' before 'lmtp' line Mira Limbeck
@ 2021-02-19 10:31 ` Mira Limbeck
  2021-03-22 13:07   ` Mira Limbeck
  2021-02-25 10:56 ` [pmg-devel] [PATCH log-tracker 1/3] update tests Thomas Lamprecht
  2 siblings, 1 reply; 9+ messages in thread
From: Mira Limbeck @ 2021-02-19 10:31 UTC (permalink / raw)
  To: pmg-devel

Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
 .../test_input_after_queue_relay_before_lmtp  | 19 ++++++++
 .../test_output_after_queue_relay_before_lmtp | 44 +++++++++++++++++++
 tests/tests_after_queue.rs                    | 21 +++++++++
 3 files changed, 84 insertions(+)
 create mode 100644 tests/test_input_after_queue_relay_before_lmtp
 create mode 100644 tests/test_output_after_queue_relay_before_lmtp

diff --git a/tests/test_input_after_queue_relay_before_lmtp b/tests/test_input_after_queue_relay_before_lmtp
new file mode 100644
index 0000000..3cb6e8b
--- /dev/null
+++ b/tests/test_input_after_queue_relay_before_lmtp
@@ -0,0 +1,19 @@
+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/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_relay_before_lmtp b/tests/test_output_after_queue_relay_before_lmtp
new file mode 100644
index 0000000..a1dbc40
--- /dev/null
+++ b/tests/test_output_after_queue_relay_before_lmtp
@@ -0,0 +1,44 @@
+# 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: 60092E44
+SIZE: 162287
+CLIENT: localhost[127.0.0.1],
+MSGID: <redacted:msgid>
+TO:60092E44:A673520AB5:2: from <redacted:returnpath@domain.tld> to <redacted:recipient@mydomain.tld> (192.168.1.002[192.168.1.002]:25)
+SMTP:
+L00000009 Jan 21 07:33:24 pmghost postfix/smtpd[29375]: connect from localhost[127.0.0.1]
+L0000000A 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]
+L0000000C 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:
+L0000000B Jan 21 07:33:24 pmghost postfix/cleanup[29364]: A673520AB5: message-id=<redacted:msgid>
+L0000000E Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: from=<redacted:returnpath@domain.tld>, size=162287, nrcpt=1 (queue active)
+L0000000F 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)
+L00000010 Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: removed
+
+QENTRY: DEF2520A69
+CTIME: 60092E44
+SIZE: 161138
+CLIENT: pmghost.mydomain.tld[192.168.1.001]
+MSGID: <redacted:msgid>
+TO:60092E44: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]
+L00000006 Jan 21 07:33:21 pmghost postfix/smtpd[29361]: 1855220A70: client=pmghost.mydomain.tld[192.168.1.001]
+L00000007 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
+L00000005 Jan 21 07:33:21 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: new mail message-id=<redacted:msgid>#012
+L00000008 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)
+L0000000D Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: accept mail to <redacted:recipient@mydomain.tld> (A673520AB5) (rule: default-accept)
+L00000011 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/qmgr[529]: DEF2520A69: from=<redacted:returnpath@domain.tld>, size=161138, nrcpt=1 (queue active)
+L00000012 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))
+L00000013 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 8a66887..a1b3fac 100644
--- a/tests/tests_after_queue.rs
+++ b/tests/tests_after_queue.rs
@@ -137,3 +137,24 @@ fn after_queue_search_string_case_insensitive() {
     let output_reader = BufReader::new(&output.stdout[..]);
     utils::compare_output(output_reader, expected_output);
 }
+
+#[test]
+fn after_queue_relay_before_lmtp() {
+    let output = Command::new(utils::log_tracker_path())
+        .arg("-vv")
+        .arg("-s")
+        .arg("2021-01-21 07:30:00")
+        .arg("-e")
+        .arg("2021-01-21 07:35:00")
+        .arg("-i")
+        .arg("tests/test_input_after_queue_relay_before_lmtp")
+        .output()
+        .expect("failed to execute pmg-log-tracker");
+
+    let expected_file = File::open("tests/test_output_after_queue_relay_before_lmtp")
+        .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





^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [pmg-devel] [PATCH log-tracker 1/3] update tests
  2021-02-19 10:31 [pmg-devel] [PATCH log-tracker 1/3] update tests Mira Limbeck
  2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 2/3] after-queue: fix wrong DStatus if relay is 'removed' before 'lmtp' line Mira Limbeck
  2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 3/3] add test case for relay removed before lmtp Mira Limbeck
@ 2021-02-25 10:56 ` Thomas Lamprecht
  2021-02-26  9:22   ` Mira Limbeck
  2 siblings, 1 reply; 9+ messages in thread
From: Thomas Lamprecht @ 2021-02-25 10:56 UTC (permalink / raw)
  To: Mira Limbeck, pmg-devel

On 19.02.21 11:31, Mira Limbeck wrote:
> As we only have month, day and time available but not the year, we have
> to update the tests every year.

I'm probably just missing context but why exactly is that the case?





^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [pmg-devel] [PATCH log-tracker 1/3] update tests
  2021-02-25 10:56 ` [pmg-devel] [PATCH log-tracker 1/3] update tests Thomas Lamprecht
@ 2021-02-26  9:22   ` Mira Limbeck
  2021-02-26 12:52     ` Mira Limbeck
  0 siblings, 1 reply; 9+ messages in thread
From: Mira Limbeck @ 2021-02-26  9:22 UTC (permalink / raw)
  To: Thomas Lamprecht, pmg-devel

On 2/25/21 11:56 AM, Thomas Lamprecht wrote:
> On 19.02.21 11:31, Mira Limbeck wrote:
>> As we only have month, day and time available but not the year, we have
>> to update the tests every year.
> I'm probably just missing context but why exactly is that the case?
>
The logs only contain month, day and time of the day which we parse. We 
do this based on the current date and timezone.

So depending on the current date and the date in the logs, we either 
assume it to be in the past or in the future. This results in a 
different calculated CTIME then and the tests need to be updated 
accordingly.


Stoiko and I talked about this when I sent the patch, and we probably 
want to switch to logging the year as well with 7.0 so these test 
updates are no longer required afterwards.





^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [pmg-devel] [PATCH log-tracker 1/3] update tests
  2021-02-26  9:22   ` Mira Limbeck
@ 2021-02-26 12:52     ` Mira Limbeck
  2021-02-26 13:08       ` Thomas Lamprecht
  0 siblings, 1 reply; 9+ messages in thread
From: Mira Limbeck @ 2021-02-26 12:52 UTC (permalink / raw)
  To: pmg-devel

On 2/26/21 10:22 AM, Mira Limbeck wrote:
> On 2/25/21 11:56 AM, Thomas Lamprecht wrote:
>> On 19.02.21 11:31, Mira Limbeck wrote:
>>> As we only have month, day and time available but not the year, we have
>>> to update the tests every year.
>> I'm probably just missing context but why exactly is that the case?
>>
> The logs only contain month, day and time of the day which we parse. 
> We do this based on the current date and timezone.
>
> So depending on the current date and the date in the logs, we either 
> assume it to be in the past or in the future. This results in a 
> different calculated CTIME then and the tests need to be updated 
> accordingly.
Correction, we always assume it to be in the past. But without the year 
info we assume it is no older than 1 year. This means when the test 
results we check against was created before that, the CTIME does not 
match anymore now.
>
>
> Stoiko and I talked about this when I sent the patch, and we probably 
> want to switch to logging the year as well with 7.0 so these test 
> updates are no longer required afterwards.
>
>
>
> _______________________________________________
> pmg-devel mailing list
> pmg-devel@lists.proxmox.com
> https://lists.proxmox.com/cgi-bin/mailman/listinfo/pmg-devel
>
>




^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [pmg-devel] [PATCH log-tracker 1/3] update tests
  2021-02-26 12:52     ` Mira Limbeck
@ 2021-02-26 13:08       ` Thomas Lamprecht
  2021-03-15  9:30         ` Thomas Lamprecht
  0 siblings, 1 reply; 9+ messages in thread
From: Thomas Lamprecht @ 2021-02-26 13:08 UTC (permalink / raw)
  To: Mira Limbeck, pmg-devel

On 26.02.21 13:52, Mira Limbeck wrote:
> On 2/26/21 10:22 AM, Mira Limbeck wrote:
>> On 2/25/21 11:56 AM, Thomas Lamprecht wrote:
>>> On 19.02.21 11:31, Mira Limbeck wrote:
>>>> As we only have month, day and time available but not the year, we have
>>>> to update the tests every year.
>>> I'm probably just missing context but why exactly is that the case?
>>>
>> The logs only contain month, day and time of the day which we parse. We do this based on the current date and timezone.
>>
>> So depending on the current date and the date in the logs, we either assume it to be in the past or in the future. This results in a different calculated CTIME then and the tests need to be updated accordingly.
> Correction, we always assume it to be in the past. But without the year info we assume it is no older than 1 year. This means when the test results we check against was created before that, the CTIME does not match anymore now.


Can't we just run the test under a fixed time? For common test harnesses which
run as specific commands one could use something like

faketime 2020-12-01 ./test-command

in the respective make target.

For cargo test based ones we could just add a wrapper helper around getting
the time and mock that in the #[cfg(not(test))] and #[cfg(test)], respectively.




^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [pmg-devel] [PATCH log-tracker 1/3] update tests
  2021-02-26 13:08       ` Thomas Lamprecht
@ 2021-03-15  9:30         ` Thomas Lamprecht
  0 siblings, 0 replies; 9+ messages in thread
From: Thomas Lamprecht @ 2021-03-15  9:30 UTC (permalink / raw)
  To: Mira Limbeck, pmg-devel

On 26.02.21 14:08, Thomas Lamprecht wrote:
> On 26.02.21 13:52, Mira Limbeck wrote:
>> On 2/26/21 10:22 AM, Mira Limbeck wrote:
>>> On 2/25/21 11:56 AM, Thomas Lamprecht wrote:
>>>> On 19.02.21 11:31, Mira Limbeck wrote:
>>>>> As we only have month, day and time available but not the year, we have
>>>>> to update the tests every year.
>>>> I'm probably just missing context but why exactly is that the case?
>>>>
>>> The logs only contain month, day and time of the day which we parse. We do this based on the current date and timezone.
>>>
>>> So depending on the current date and the date in the logs, we either assume it to be in the past or in the future. This results in a different calculated CTIME then and the tests need to be updated accordingly.
>> Correction, we always assume it to be in the past. But without the year info we assume it is no older than 1 year. This means when the test results we check against was created before that, the CTIME does not match anymore now.
> 
> 
> Can't we just run the test under a fixed time? For common test harnesses which
> run as specific commands one could use something like
> 

any update on this?

> faketime 2020-12-01 ./test-command
> 
> in the respective make target.
> 
> For cargo test based ones we could just add a wrapper helper around getting
> the time and mock that in the #[cfg(not(test))] and #[cfg(test)], respectively.





^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [pmg-devel] [PATCH log-tracker 3/3] add test case for relay removed before lmtp
  2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 3/3] add test case for relay removed before lmtp Mira Limbeck
@ 2021-03-22 13:07   ` Mira Limbeck
  0 siblings, 0 replies; 9+ messages in thread
From: Mira Limbeck @ 2021-03-22 13:07 UTC (permalink / raw)
  To: pmg-devel

I'll send this updated to the faketime tests tomorrow, together with the 
outgoing TLS tests.

On 2/19/21 11:31 AM, Mira Limbeck wrote:
> Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
> ---
>   .../test_input_after_queue_relay_before_lmtp  | 19 ++++++++
>   .../test_output_after_queue_relay_before_lmtp | 44 +++++++++++++++++++
>   tests/tests_after_queue.rs                    | 21 +++++++++
>   3 files changed, 84 insertions(+)
>   create mode 100644 tests/test_input_after_queue_relay_before_lmtp
>   create mode 100644 tests/test_output_after_queue_relay_before_lmtp
>
> diff --git a/tests/test_input_after_queue_relay_before_lmtp b/tests/test_input_after_queue_relay_before_lmtp
> new file mode 100644
> index 0000000..3cb6e8b
> --- /dev/null
> +++ b/tests/test_input_after_queue_relay_before_lmtp
> @@ -0,0 +1,19 @@
> +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/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_relay_before_lmtp b/tests/test_output_after_queue_relay_before_lmtp
> new file mode 100644
> index 0000000..a1dbc40
> --- /dev/null
> +++ b/tests/test_output_after_queue_relay_before_lmtp
> @@ -0,0 +1,44 @@
> +# 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: 60092E44
> +SIZE: 162287
> +CLIENT: localhost[127.0.0.1],
> +MSGID: <redacted:msgid>
> +TO:60092E44:A673520AB5:2: from <redacted:returnpath@domain.tld> to <redacted:recipient@mydomain.tld> (192.168.1.002[192.168.1.002]:25)
> +SMTP:
> +L00000009 Jan 21 07:33:24 pmghost postfix/smtpd[29375]: connect from localhost[127.0.0.1]
> +L0000000A 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]
> +L0000000C 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:
> +L0000000B Jan 21 07:33:24 pmghost postfix/cleanup[29364]: A673520AB5: message-id=<redacted:msgid>
> +L0000000E Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: from=<redacted:returnpath@domain.tld>, size=162287, nrcpt=1 (queue active)
> +L0000000F 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)
> +L00000010 Jan 21 07:33:24 pmghost postfix/qmgr[529]: A673520AB5: removed
> +
> +QENTRY: DEF2520A69
> +CTIME: 60092E44
> +SIZE: 161138
> +CLIENT: pmghost.mydomain.tld[192.168.1.001]
> +MSGID: <redacted:msgid>
> +TO:60092E44: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]
> +L00000006 Jan 21 07:33:21 pmghost postfix/smtpd[29361]: 1855220A70: client=pmghost.mydomain.tld[192.168.1.001]
> +L00000007 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
> +L00000005 Jan 21 07:33:21 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: new mail message-id=<redacted:msgid>#012
> +L00000008 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)
> +L0000000D Jan 21 07:33:24 pmghost pmg-smtp-filter[28437]: 20A9560092030F3374: accept mail to <redacted:recipient@mydomain.tld> (A673520AB5) (rule: default-accept)
> +L00000011 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/qmgr[529]: DEF2520A69: from=<redacted:returnpath@domain.tld>, size=161138, nrcpt=1 (queue active)
> +L00000012 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))
> +L00000013 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 8a66887..a1b3fac 100644
> --- a/tests/tests_after_queue.rs
> +++ b/tests/tests_after_queue.rs
> @@ -137,3 +137,24 @@ fn after_queue_search_string_case_insensitive() {
>       let output_reader = BufReader::new(&output.stdout[..]);
>       utils::compare_output(output_reader, expected_output);
>   }
> +
> +#[test]
> +fn after_queue_relay_before_lmtp() {
> +    let output = Command::new(utils::log_tracker_path())
> +        .arg("-vv")
> +        .arg("-s")
> +        .arg("2021-01-21 07:30:00")
> +        .arg("-e")
> +        .arg("2021-01-21 07:35:00")
> +        .arg("-i")
> +        .arg("tests/test_input_after_queue_relay_before_lmtp")
> +        .output()
> +        .expect("failed to execute pmg-log-tracker");
> +
> +    let expected_file = File::open("tests/test_output_after_queue_relay_before_lmtp")
> +        .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);
> +}




^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2021-03-22 13:07 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-02-19 10:31 [pmg-devel] [PATCH log-tracker 1/3] update tests Mira Limbeck
2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 2/3] after-queue: fix wrong DStatus if relay is 'removed' before 'lmtp' line Mira Limbeck
2021-02-19 10:31 ` [pmg-devel] [PATCH log-tracker 3/3] add test case for relay removed before lmtp Mira Limbeck
2021-03-22 13:07   ` Mira Limbeck
2021-02-25 10:56 ` [pmg-devel] [PATCH log-tracker 1/3] update tests Thomas Lamprecht
2021-02-26  9:22   ` Mira Limbeck
2021-02-26 12:52     ` Mira Limbeck
2021-02-26 13:08       ` Thomas Lamprecht
2021-03-15  9:30         ` Thomas Lamprecht

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
Service provided by Proxmox Server Solutions GmbH | Privacy | Legal