[pmg-devel] applied-series: [PATCH pmg-log-tracker 1/3] make QID parsing more robust

[Thomas Lamprecht]

On 5/15/20 4:49 PM, Mira Limbeck wrote:
> As a user had the problem that 'fa' of 'fatal' matched for a QID,
> increase the number of characters that have to match. The QID always has
> at least 5 characters for the microseconds, so increase it to 5.
> 
> See http://www.postfix.org/postconf.5.html#enable_long_queue_ids
> 
> Signed-off-by: Mira Limbeck <m.limbeck at proxmox.com>
> ---
>  src/main.rs | 6 ++++--
>  1 file changed, 4 insertions(+), 2 deletions(-)
> 
> diff --git a/src/main.rs b/src/main.rs
> index 9e3883f..55e1516 100644
> --- a/src/main.rs
> +++ b/src/main.rs
> @@ -2124,8 +2124,10 @@ fn parse_qid(data: &[u8], max: usize) -> Option<(&[u8], &[u8])> {
>      let max = max.min(data.len());
>      // take at most max, find the first non-hex-digit
>      match data.iter().take(max).position(|b| !b.is_ascii_hexdigit()) {
> -        // if there were less than 2 return nothing
> -        Some(n) if n < 2 => None,
> +        // if there were less than 5 return nothing
> +        // the QID always has at least 5 characters for the microseconds (see
> +        // http://www.postfix.org/postconf.5.html#enable_long_queue_ids)
> +        Some(n) if n < 5 => None,
>          // otherwise split at the first non-hex-digit
>          Some(n) => Some(data.split_at(n)),
>          // or return 'max' length QID if no non-hex-digit is found
> 

applied series, but when testing I run into some unrelated issues, I pointed to
them off-list already, still noting here for sake of completeness.

The issue is reproducible when setting a "To/Receiver" and using the same value
for the xfilter. Adding or dropping xfilter should not make any difference for a
fixed time frame from the past. But it does, e.g., xfilter reduces the set of
shown messages, even if the xfilter value can clearly be found in the through
filtering dropped mails.

I get shown a bit more when downgrading to 2.1.4, but still not correct there.

Mails get wrongly omitted in a stable way, i.e., the same mails disappear when
switching from "target" only filter to "target" and "xfilter".

While yes, I'm doing a bit faked injection of mail here, that shouldn't matter
for this case.

A log from a mail which gets wrongly dropped below:

> May 18 16:28:27 pmg-demo postfix/smtpd[18733]: connect from pmg-demo.proxmox.com[192.168.30.128]
> May 18 16:28:27 pmg-demo postfix/smtpd[18733]: NOQUEUE: client=pmg-demo.proxmox.com[192.168.30.128]
> May 18 16:28:27 pmg-demo pmg-smtp-filter[18883]: 3204C55EC29B8B401E1: new mail message-id=
> May 18 16:28:27 pmg-demo pmg-smtp-filter[18883]: 3204C55EC29B8B401E1: SA score=1001/5 time=0.310 bayes=undefined autolearn=no autolearn_force=no hits=ALL_TRUSTED(-1),AWL(-0.395),DKIM_ADSP_NXDOMAIN(0.8),GTUBE(1000),KAM_DMARC_STATUS(0.01),KAM_NUMSUBJECT(0.5),MISSING_DATE(1.396),MISSING_MID(0.14),NO_DNS_FOR_FROM(0.379)
> May 18 16:28:27 pmg-demo pmg-smtp-filter[18883]: 3204C55EC29B8B401E1: block mail to <ferdl at example.proxmox.com> (rule: block-ferdl)
> May 18 16:28:27 pmg-demo pmg-smtp-filter[18883]: 3204C55EC29B8B401E1: moved mail for <j.smith at example.proxmox.com> to spam quarantine - 3209DD5EC29B8B8E6A2 (rule: Quarantine/Mark Spam (Level 3))
> May 18 16:28:27 pmg-demo pmg-smtp-filter[18883]: 3204C55EC29B8B401E1: processing time: 0.323 seconds (0.31, 0.006, 0)
> May 18 16:28:27 pmg-demo postfix/smtpd[18733]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (3204C55EC29B8B401E1); from=<mailtestsender.bad at proxtest.com> to=<j.smith at example.proxmox.com> proto=ESMTP helo=<localhost.localdomain>
> May 18 16:28:27 pmg-demo postfix/smtpd[18733]: disconnect from pmg-demo.proxmox.com[192.168.30.128] ehlo=1 mail=1 rcpt=2 data=1 commands=5