public inbox for pmg-devel@lists.proxmox.com
 help / color / mirror / Atom feed
* [pmg-devel] [PATCH pmg-log-tracker] add output for proxy-reject with 'Syntax:' message
@ 2020-08-28 10:19 Mira Limbeck
  2020-08-28 11:31 ` Stoiko Ivanov
  0 siblings, 1 reply; 2+ messages in thread
From: Mira Limbeck @ 2020-08-28 10:19 UTC (permalink / raw)
  To: pmg-devel

Messages like the following
'proxy-reject: END-OF-MESSAGE: 501 5.5.2 Syntax: MAIL FROM: <address>;'
can happen if an EHLO keyword is announced which is not handled by
pmg-smtp-filter (see #2795). This patch adds output to the log tracker
so this mail shows up as 'rejected' in the GUI instead of silently
ignoring it.

Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
 src/main.rs                                  | 33 +++++++++++++++++---
 tests/test_input_before_queue_syntax_reject  | 14 +++++++++
 tests/test_output_before_queue_syntax_reject | 18 +++++++++++
 tests/tests_before_queue.rs                  | 21 +++++++++++++
 4 files changed, 81 insertions(+), 5 deletions(-)
 create mode 100644 tests/test_input_before_queue_syntax_reject
 create mode 100644 tests/test_output_before_queue_syntax_reject

diff --git a/src/main.rs b/src/main.rs
index 613cecd..ce09f14 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -647,19 +647,20 @@ fn handle_smtpd_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
             return;
         }
         let data = &data[16..];
+
+        // specify that before queue filtering is used and the mail
+        // was rejected for all receivers
+        se.borrow_mut().is_bq_rejected = true;
+
         if let Some(qid_index) = find(data, b"(") {
             let data = &data[qid_index + 1..];
-            if let Some((qid, data)) = parse_qid(data, 25) {
+            if let Some((qid, _)) = parse_qid(data, 25) {
                 let fe = get_or_create_fentry(&mut parser.fentries, qid);
                 // set the FEntry to before-queue filtered
                 fe.borrow_mut().is_bq = true;
                 // we never have a QEntry in this case, so just set the SEntry
                 // filter reference
                 se.borrow_mut().filter = Some(Rc::downgrade(&fe));
-                // specify that before queue filtering is used and the mail
-                // was rejected for all receivers
-                se.borrow_mut().is_bq_rejected = true;
-
                 if let Some(from_index) = find(data, b"from=<") {
                     let data = &data[from_index + 6..];
                     let from_count = data.iter().take_while(|b| (**b as char) != '>').count();
@@ -668,6 +669,28 @@ fn handle_smtpd_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
                     se.borrow_mut().bq_from = from.into();
                 }
             }
+        } else if let Some(from_index) = find(data, b"from=<") {
+            let data = &data[from_index + 6..];
+            let from_count = data.iter().take_while(|b| (**b as char) != '>').count();
+            let from = &data[..from_count];
+            // same as for 'proxy-accept' above
+            se.borrow_mut().bq_from = from.into();
+
+            if let Some(to_index) = find(data, b"to=<") {
+                let data = &data[to_index + 4..];
+                let to_count = data
+                    .iter()
+                    .take_while(|b| (**b as char) != '>')
+                    .count();
+                let to = &data[..to_count];
+
+                se.borrow_mut().add_noqueue_entry(
+                    from,
+                    to,
+                    DStatus::Noqueue,
+                    parser.current_record_state.timestamp,
+                );
+            };
         }
 
         return;
diff --git a/tests/test_input_before_queue_syntax_reject b/tests/test_input_before_queue_syntax_reject
new file mode 100644
index 0000000..11c2e11
--- /dev/null
+++ b/tests/test_input_before_queue_syntax_reject
@@ -0,0 +1,14 @@
+Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: connect from pmgsender[192.168.22.40]
+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
+Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: NOQUEUE: client=pmgsender[192.168.22.40]
+Aug 27 14:04:08 pmg6 pmg-smtp-filter[28926]: 2020/08/27-14:04:08 CONNECT TCP Peer: "[127.0.0.1]:39208" Local: "[127.0.0.1]:10023"
+Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: warning: proxy 127.0.0.1:10023 rejected "MAIL FROM:<test@pmgsender.local> SIZE=722 BODY=8BITMIME ENVID=<c7ca5cde-cd5b-e042-c18e-f0c7e4253955@pmgsender.local> RET=FULL": "501 5.5.2 Syntax: MAIL FROM: <address>"
+Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: proxy-reject: END-OF-MESSAGE: 501 5.5.2 Syntax: MAIL FROM: <address>; from=<test@pmgsender.local> to=<test@pmgreceiver.local> proto=ESMTP helo=<pmgsender.local>
+Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: disconnect from pmgsender[192.168.22.40] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7
+Aug 27 14:04:28 pmg6 pmg-smtp-filter[28920]: starting database maintainance
+Aug 27 14:04:28 pmg6 pmg-smtp-filter[28920]: end database maintainance (3 ms)
+Aug 27 14:04:30 pmg6 pmgpolicy[1137]: starting policy database maintainance (greylist, rbl)
+Aug 27 14:04:30 pmg6 pmgpolicy[1137]: end policy database maintainance (7 ms, 0 ms)
+Aug 27 14:04:37 pmg6 pmgmirror[1069]: starting cluster syncronization
+Aug 27 14:04:37 pmg6 pmgmirror[1069]: cluster syncronization finished  (0 errors, 0.11 seconds (files 0.09, database 0.03, config 0.00))
+
diff --git a/tests/test_output_before_queue_syntax_reject b/tests/test_output_before_queue_syntax_reject
new file mode 100644
index 0000000..5be90db
--- /dev/null
+++ b/tests/test_output_before_queue_syntax_reject
@@ -0,0 +1,18 @@
+# LogReader: 20067
+# Query options
+# Start: 2020-08-27 14:00:00 (1598536800)
+# End: 2020-08-27 14:05:00 (1598537100)
+# End Query Options
+
+SMTPD: T5F47BD58L00000000
+CTIME: 5F47BD58
+CLIENT: pmgsender[192.168.22.40]
+TO:5F47BD58:T5F47BD58L00000000: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
+L00000003 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: NOQUEUE: client=pmgsender[192.168.22.40]
+L00000005 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: warning: proxy 127.0.0.1:10023 rejected "MAIL FROM:<test@pmgsender.local> SIZE=722 BODY=8BITMIME ENVID=<c7ca5cde-cd5b-e042-c18e-f0c7e4253955@pmgsender.local> RET=FULL": "501 5.5.2 Syntax: MAIL FROM: <address>"
+L00000006 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: proxy-reject: END-OF-MESSAGE: 501 5.5.2 Syntax: MAIL FROM: <address>; from=<test@pmgsender.local> to=<test@pmgreceiver.local> proto=ESMTP helo=<pmgsender.local>
+L00000007 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: disconnect from pmgsender[192.168.22.40] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7
+
diff --git a/tests/tests_before_queue.rs b/tests/tests_before_queue.rs
index 128ffad..bd46e53 100644
--- a/tests/tests_before_queue.rs
+++ b/tests/tests_before_queue.rs
@@ -252,3 +252,24 @@ fn before_queue_to_search_string() {
     let output_reader = BufReader::new(&output.stdout[..]);
     utils::compare_output(output_reader, expected_output);
 }
+
+#[test]
+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("-e")
+        .arg("2020-08-27 14:05:00")
+        .arg("-i")
+        .arg("tests/test_input_before_queue_syntax_reject")
+        .output()
+        .expect("failed to execute pmg-log-tracker");
+
+    let expected_file = File::open("tests/test_output_before_queue_syntax_reject")
+        .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] 2+ messages in thread

* Re: [pmg-devel] [PATCH pmg-log-tracker] add output for proxy-reject with 'Syntax:' message
  2020-08-28 10:19 [pmg-devel] [PATCH pmg-log-tracker] add output for proxy-reject with 'Syntax:' message Mira Limbeck
@ 2020-08-28 11:31 ` Stoiko Ivanov
  0 siblings, 0 replies; 2+ messages in thread
From: Stoiko Ivanov @ 2020-08-28 11:31 UTC (permalink / raw)
  To: Mira Limbeck; +Cc: pmg-devel

Thanks for the quick patch!

The change looks good to me and a quick spin on my test-system indicates
that it works as intended.

Tested-By: Stoiko Ivanov <s.ivanov@proxmox.com>
Reviewed-By: Stoiko Ivanov <s.ivanov@proxmox.com>

On Fri, 28 Aug 2020 12:19:51 +0200
Mira Limbeck <m.limbeck@proxmox.com> wrote:

> Messages like the following
> 'proxy-reject: END-OF-MESSAGE: 501 5.5.2 Syntax: MAIL FROM: <address>;'
> can happen if an EHLO keyword is announced which is not handled by
> pmg-smtp-filter (see #2795). This patch adds output to the log tracker
> so this mail shows up as 'rejected' in the GUI instead of silently
> ignoring it.
> 
> Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
> ---
>  src/main.rs                                  | 33 +++++++++++++++++---
>  tests/test_input_before_queue_syntax_reject  | 14 +++++++++
>  tests/test_output_before_queue_syntax_reject | 18 +++++++++++
>  tests/tests_before_queue.rs                  | 21 +++++++++++++
>  4 files changed, 81 insertions(+), 5 deletions(-)
>  create mode 100644 tests/test_input_before_queue_syntax_reject
>  create mode 100644 tests/test_output_before_queue_syntax_reject
> 
> diff --git a/src/main.rs b/src/main.rs
> index 613cecd..ce09f14 100644
> --- a/src/main.rs
> +++ b/src/main.rs
> @@ -647,19 +647,20 @@ fn handle_smtpd_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
>              return;
>          }
>          let data = &data[16..];
> +
> +        // specify that before queue filtering is used and the mail
> +        // was rejected for all receivers
> +        se.borrow_mut().is_bq_rejected = true;
> +
>          if let Some(qid_index) = find(data, b"(") {
>              let data = &data[qid_index + 1..];
> -            if let Some((qid, data)) = parse_qid(data, 25) {
> +            if let Some((qid, _)) = parse_qid(data, 25) {
>                  let fe = get_or_create_fentry(&mut parser.fentries, qid);
>                  // set the FEntry to before-queue filtered
>                  fe.borrow_mut().is_bq = true;
>                  // we never have a QEntry in this case, so just set the SEntry
>                  // filter reference
>                  se.borrow_mut().filter = Some(Rc::downgrade(&fe));
> -                // specify that before queue filtering is used and the mail
> -                // was rejected for all receivers
> -                se.borrow_mut().is_bq_rejected = true;
> -
>                  if let Some(from_index) = find(data, b"from=<") {
>                      let data = &data[from_index + 6..];
>                      let from_count = data.iter().take_while(|b| (**b as char) != '>').count();
> @@ -668,6 +669,28 @@ fn handle_smtpd_message(msg: &[u8], parser: &mut Parser, complete_line: &[u8]) {
>                      se.borrow_mut().bq_from = from.into();
>                  }
>              }
> +        } else if let Some(from_index) = find(data, b"from=<") {
> +            let data = &data[from_index + 6..];
> +            let from_count = data.iter().take_while(|b| (**b as char) != '>').count();
> +            let from = &data[..from_count];
> +            // same as for 'proxy-accept' above
> +            se.borrow_mut().bq_from = from.into();
> +
> +            if let Some(to_index) = find(data, b"to=<") {
> +                let data = &data[to_index + 4..];
> +                let to_count = data
> +                    .iter()
> +                    .take_while(|b| (**b as char) != '>')
> +                    .count();
> +                let to = &data[..to_count];
> +
> +                se.borrow_mut().add_noqueue_entry(
> +                    from,
> +                    to,
> +                    DStatus::Noqueue,
> +                    parser.current_record_state.timestamp,
> +                );
> +            };
>          }
>  
>          return;
> diff --git a/tests/test_input_before_queue_syntax_reject b/tests/test_input_before_queue_syntax_reject
> new file mode 100644
> index 0000000..11c2e11
> --- /dev/null
> +++ b/tests/test_input_before_queue_syntax_reject
> @@ -0,0 +1,14 @@
> +Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: connect from pmgsender[192.168.22.40]
> +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
> +Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: NOQUEUE: client=pmgsender[192.168.22.40]
> +Aug 27 14:04:08 pmg6 pmg-smtp-filter[28926]: 2020/08/27-14:04:08 CONNECT TCP Peer: "[127.0.0.1]:39208" Local: "[127.0.0.1]:10023"
> +Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: warning: proxy 127.0.0.1:10023 rejected "MAIL FROM:<test@pmgsender.local> SIZE=722 BODY=8BITMIME ENVID=<c7ca5cde-cd5b-e042-c18e-f0c7e4253955@pmgsender.local> RET=FULL": "501 5.5.2 Syntax: MAIL FROM: <address>"
> +Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: proxy-reject: END-OF-MESSAGE: 501 5.5.2 Syntax: MAIL FROM: <address>; from=<test@pmgsender.local> to=<test@pmgreceiver.local> proto=ESMTP helo=<pmgsender.local>
> +Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: disconnect from pmgsender[192.168.22.40] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7
> +Aug 27 14:04:28 pmg6 pmg-smtp-filter[28920]: starting database maintainance
> +Aug 27 14:04:28 pmg6 pmg-smtp-filter[28920]: end database maintainance (3 ms)
> +Aug 27 14:04:30 pmg6 pmgpolicy[1137]: starting policy database maintainance (greylist, rbl)
> +Aug 27 14:04:30 pmg6 pmgpolicy[1137]: end policy database maintainance (7 ms, 0 ms)
> +Aug 27 14:04:37 pmg6 pmgmirror[1069]: starting cluster syncronization
> +Aug 27 14:04:37 pmg6 pmgmirror[1069]: cluster syncronization finished  (0 errors, 0.11 seconds (files 0.09, database 0.03, config 0.00))
> +
> diff --git a/tests/test_output_before_queue_syntax_reject b/tests/test_output_before_queue_syntax_reject
> new file mode 100644
> index 0000000..5be90db
> --- /dev/null
> +++ b/tests/test_output_before_queue_syntax_reject
> @@ -0,0 +1,18 @@
> +# LogReader: 20067
> +# Query options
> +# Start: 2020-08-27 14:00:00 (1598536800)
> +# End: 2020-08-27 14:05:00 (1598537100)
> +# End Query Options
> +
> +SMTPD: T5F47BD58L00000000
> +CTIME: 5F47BD58
> +CLIENT: pmgsender[192.168.22.40]
> +TO:5F47BD58:T5F47BD58L00000000: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
> +L00000003 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: NOQUEUE: client=pmgsender[192.168.22.40]
> +L00000005 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: warning: proxy 127.0.0.1:10023 rejected "MAIL FROM:<test@pmgsender.local> SIZE=722 BODY=8BITMIME ENVID=<c7ca5cde-cd5b-e042-c18e-f0c7e4253955@pmgsender.local> RET=FULL": "501 5.5.2 Syntax: MAIL FROM: <address>"
> +L00000006 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: proxy-reject: END-OF-MESSAGE: 501 5.5.2 Syntax: MAIL FROM: <address>; from=<test@pmgsender.local> to=<test@pmgreceiver.local> proto=ESMTP helo=<pmgsender.local>
> +L00000007 Aug 27 14:04:08 pmg6 postfix/smtpd[7567]: disconnect from pmgsender[192.168.22.40] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7
> +
> diff --git a/tests/tests_before_queue.rs b/tests/tests_before_queue.rs
> index 128ffad..bd46e53 100644
> --- a/tests/tests_before_queue.rs
> +++ b/tests/tests_before_queue.rs
> @@ -252,3 +252,24 @@ fn before_queue_to_search_string() {
>      let output_reader = BufReader::new(&output.stdout[..]);
>      utils::compare_output(output_reader, expected_output);
>  }
> +
> +#[test]
> +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("-e")
> +        .arg("2020-08-27 14:05:00")
> +        .arg("-i")
> +        .arg("tests/test_input_before_queue_syntax_reject")
> +        .output()
> +        .expect("failed to execute pmg-log-tracker");
> +
> +    let expected_file = File::open("tests/test_output_before_queue_syntax_reject")
> +        .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] 2+ messages in thread

end of thread, other threads:[~2020-08-28 11:31 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-08-28 10:19 [pmg-devel] [PATCH pmg-log-tracker] add output for proxy-reject with 'Syntax:' message Mira Limbeck
2020-08-28 11:31 ` Stoiko Ivanov

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