For a while now, Postfix has logged that clients send commands
ahead of time (unauthorized pipelining) but I didn't have code to
log what those clients actually sent, because those commands haven't
been read yet - they still sit in the input buffer.
Meanwhile I have been puzzled by this message that is occasionally
logged in my maillog file:
postfix/postscreen[ddddd]: COMMAND PIPELINING from [d.d.d.d]:d after :
Pipelining after what? A week ago I figured out a "clean" way to
log "unread" commands in smtpd(8) and postscreen(8). Yesterday,
that logging solved the mystery.
Feb 12 19:59:50 spike postfix/postscreen[55805]: CONNECT from
[125.69.73.41]:3921
Feb 12 19:59:50 spike postfix/dnsblog[56626]: addr 125.69.73.41 listed by
domain b.barracudacentral.org as 127.0.0.2
Feb 12 19:59:50 spike postfix/postscreen[55805]: PREGREET 14 after 0.34 from
[125.69.73.41]:3921: HELO bojonca\r\n
Feb 12 19:59:51 spike postfix/postscreen[55805]: NOQUEUE: reject: RCPT from
[125.69.73.41]:3921: 550 5.5.1 Protocol error;
from=<horacemalabarfar...@porcupine.org>,
to=<horacemalabarfar...@porcupine.org>, proto=SMTP, helo=<bojonca>
Feb 12 19:59:51 spike postfix/postscreen[55805]: COMMAND PIPELINING from
[125.69.73.41]:3921 after : .\r\nQUIT\r\n
Feb 12 19:59:51 spike postfix/postscreen[55805]: DISCONNECT [125.69.73.41]:3921
Apparently, this spamware ends the SMTP session with
<CR><LF>.<CR><LF>QUIT<CR><LF>
even when it does not go into the DATA phase. Logging of unread
pipelined command input was introduced 20110205, in smtpd(8) and
postscreen(8).
Wietse
