Re: milter - wrong ordering of responses on pipelining
there is bug report for PMilter: https://rt.cpan.org/Ticket/Display.html?id=145263 On 2022.12.11. 15:10, Wietse Venema wrote: lists+post...@sad.lv: Hello ! I met an issue with milter when multiple messages pushed within single smtp session (using pipelining indeed): warning: milter unix:/run/t.socket: unexpected filter response SMFIR_ADDHEADER after event SMFIC_MAIL It looks similar for https://www.mail-archive.com/postfix-users@postfix.org/msg13652.html This was caused by a bug in Sendmail::PMilter. Background: the SMTP protocol supports multiple MAIL transactions per SMTP connection. After each successful or unsuccessful MAIL transaction, Postfix sends an SMFIC_ABORT command to all Milters, to ensure that they are in a knwn state for the next MAIL transaction. The Sendmail::PMilter code comes with a description of the Milter protocol that says: COMMAND CODES ... 'A' SMFIC_ABORT Abort current filter checks Expected response: NONE ... Yet, when the Sendmail::PMilter receives SMFIC_ABORT, it sends a response (SMFIR_CONTINUE). Evidence from PMilter logging: Fri Dec 9 20:14:15 2022 PID=13886 Context.pm(215): main(eval): got command=[A] Fri Dec 9 20:14:15 2022 PID=13886 Context.pm(508): call_hooks: (non-existent callback=[abort]) write =>c<= >< The command=[A] is SMFIC_ABORT, and the =>c<= response is SMFIR_CONTINUE. Because of this "extra" response, Postfix and Sendmail::PMilter are now out of step, and eventually Postfix complains about a protocol error. Wietse
Re: milter - wrong ordering of responses on pipelining
lists+post...@sad.lv: > Hello ! > > I met an issue with milter when multiple messages pushed within single > smtp session (using pipelining indeed): > warning: milter unix:/run/t.socket: unexpected filter response > SMFIR_ADDHEADER after event SMFIC_MAIL > > It looks similar for > https://www.mail-archive.com/postfix-users@postfix.org/msg13652.html This was caused by a bug in Sendmail::PMilter. Background: the SMTP protocol supports multiple MAIL transactions per SMTP connection. After each successful or unsuccessful MAIL transaction, Postfix sends an SMFIC_ABORT command to all Milters, to ensure that they are in a knwn state for the next MAIL transaction. The Sendmail::PMilter code comes with a description of the Milter protocol that says: COMMAND CODES ... 'A' SMFIC_ABORT Abort current filter checks Expected response: NONE ... Yet, when the Sendmail::PMilter receives SMFIC_ABORT, it sends a response (SMFIR_CONTINUE). Evidence from PMilter logging: Fri Dec 9 20:14:15 2022 PID=13886 Context.pm(215): main(eval): got command=[A] Fri Dec 9 20:14:15 2022 PID=13886 Context.pm(508): call_hooks: (non-existent callback=[abort]) write =>c<= >< The command=[A] is SMFIC_ABORT, and the =>c<= response is SMFIR_CONTINUE. Because of this "extra" response, Postfix and Sendmail::PMilter are now out of step, and eventually Postfix complains about a protocol error. Wietse
Re: milter - wrong ordering of responses on pipelining
You claim almost 100% reproduction, but your Perl script has multiple errors, and you did not provide all the inputs to reproduce the problem. First, the Perl script. 1 - When I run the script in your email message, it does not compile. $ perl your-script syntax error at your-script line 5, near "0) " syntax error at your-script line 6, near "; }" 2 - After I 'fix' that, the script logs an error when it adds a message header. $ perl your-script addheader: no header value 3 - The above error happens because the script has an undefined variable. When I add a line with "use strict;", this is the warning: $ perl your-script Global symbol "@args" requires explicit package name (did you forget to declare "my @args"?) at your-script line 16. Can you provide the following: - A script that reproduces the problem. - The complete command line for running your script that reproduces the problem. - Complete Postfix SMTP server input that reproduces the problem, and HOW that input is sent to the Postfix SMTP server. For example, the problem does not reproduce when I store an entire SMTP session with multiple messages in a file, and feed that with netcat into Postfix (nc -w 5 127.0.0.1 25
Re: milter - wrong ordering of responses on pipelining
lists+post...@sad.lv: > Dec 3 15:22:35 srv postfix/cleanup[168510]: event: SMFIC_BODYEOB; > macros: i=23FA51A1BA9 > Dec 3 15:22:35 srv postfix/cleanup[168510]: reply: SMFIR_CONTINUE data > 0 bytes > Dec 3 15:22:35 v/cleanup[168510]: free milter unix:/run/smilter/t.socket > > Dec 3 15:22:36 srv postfix/smtpd[168502]: reply: SMFIR_ADDHEADER data > 17 bytes Postfix logging suggests that the Milter replies to SMFIC_BODYEOB with SMFIR_CONTINUE. Is that what the milter sends? Can you make a recording of the postfix-milter network communication? If using tcpdump you may need to switch the milter to use TCP sockets instead of unix-domain. Wietse
