logtail: Inbound log takes Postfix's own tail, not a recipient's (audit M2)

Security audit 2026-10-17, finding M2, stage 0 - proven on the live server:
Postfix quotes a refused recipient in its reply in internal form (quotes
removed, "; < > =" kept: extract_addr, tok822_internalize), so
RCPT TO:<"; from=<ceo@…> to=<board@…> proto=ESMTP helo=<x>; "@domain>
spelled a whole tail inside the reply, and inboundRejectRe, whose reply
ended at the FIRST "; from=<", took the stranger's sender, recipient and
inbound domain for the row.

Now the reply is greedy and the tail anchored: "; from=<…> to=<…>
proto=\S+", a HELO name holding none of Postfix's NEUTER_CHARACTERS
(smtpd.c:1634, helo_cmd neuters ` <>()\";@`), and one-word SASL fields to
the end of the line (a `.*` SASL tail would have let a quoted MAIL FROM
spell the whole tail). Belt and braces: a reply that still holds
"; from=<" - a line with two tails - makes no row, so neither a recipient
nor an un-neutered HELO name can choose one. The quote/bracket/space
filter on from/to stays.

Tests: TestInboundRecipientCannotWriteTheRow (the live line's shape, and
with a forged MAIL FROM too); TestInboundHeloCannotWriteTheRow now feeds
HELO names as Postfix logs them (neutered) and expects no row for the
un-neutered ones. go test ./internal/logtail on Windows (the three known
Windows-only Follow failures aside).

Docs: security.md § Mail path; CHANGELOG; plan line ticked.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
mix
2026-10-17 21:33:12 +03:00
co-authored by Claude Opus 5.5
parent f2ef705470
commit 683fdafc6d
5 changed files with 90 additions and 24 deletions
+24 -8
View File
@@ -101,15 +101,24 @@ type Inbound struct {
// addresses), and a pattern that could start anywhere would let him write
// journal rows.
//
// For the same reason the reply is the shortest text before "; from=<", and
// the HELO name - the last thing on the line but the SASL fields above, which
// Postfix logs as the client wrote it, spaces and brackets included - is
// whatever is left. Taking the longest reply instead would let a HELO name
// that itself spells
// "; from=<…> to=<…> proto=…" supply the sender, the recipient and the reply
// of the row (security review, 2026-10-12).
// The reply is the client's text too: a refusal quotes the refused
// recipient, and Postfix quotes it in internal form - quotes removed, "; < >
// =" kept (extract_addr(), tok822_internalize(); smtpd_check_reject() applies
// only printable()) - so a stranger's RCPT TO:<"; from=<x> to=<y> ..."@d>
// spells a whole "; from=<…> to=<…> proto=…" inside the reply. The shortest
// reply ended there, and the row's sender, recipient and domain were the
// stranger's (security audit 2026-10-17, M2, proven on the test server).
// What the client cannot spell is the end of the line: the HELO name is
// logged with a space and ` <>()\";@` turned into "?" (src/smtpd/smtpd.c,
// helo_cmd(), NEUTER_CHARACTERS), and an address that holds "; from=<" or a
// ">" needs a quoted local part, whose quote then stands inside what the
// pattern would take for the sender or the recipient - which the filter
// below refuses. So the reply is the longest text before a "; from=<…>
// to=<…> proto=…" that runs to the end of the line, the HELO name holds none
// of the neutered characters, and each SASL field (never written on port 25)
// is one word. A line it does not fit leaves no row.
var (
inboundRejectRe = regexp.MustCompile(`^\S+ postfix/(inbound/smtpd|cleanup)\[\d+\]: ([0-9A-Za-z]+): (reject|milter-reject|milter-discard): \S+ from [^\[\s]*\[([0-9A-Fa-f:.]+)\]: (.*?); from=<([^>]*)> to=<([^>]*)> proto=\S+(?: helo=<.*>)?(?: sasl_(?:method|username|sender)=.*)?$`)
inboundRejectRe = regexp.MustCompile(`^\S+ postfix/(inbound/smtpd|cleanup)\[\d+\]: ([0-9A-Za-z]+): (reject|milter-reject|milter-discard): \S+ from [^\[\s]*\[([0-9A-Fa-f:.]+)\]: (.*); from=<([^>]*)> to=<([^>]*)> proto=\S+(?: helo=<[^ <>()\\";@]*>)?(?: sasl_method=\S*)?(?: sasl_username=\S*)?(?: sasl_sender=\S*)?$`)
inboundClientRe = regexp.MustCompile(`^\S+ postfix/inbound/smtpd\[\d+\]: ([0-9A-Za-z]+): client=`)
// A queue id stops being port 25's when the message is queued (qmgr takes
// it: the filter let it through), when cleanup removes the queue file of
@@ -211,6 +220,13 @@ func (j *inboundJournal) handle(line string, now time.Time, catchingUp bool) {
if strings.ContainsAny(from, "\"<> ") || strings.ContainsAny(to, "\"<> ") {
return
}
// A reply that still holds "; from=<" is a line with two tails, one of
// them written by the client - a refused recipient quoted in the reply
// (audit 2026-10-17, M2) or a HELO name Postfix failed to neuter. Which
// is Postfix's is then a guess the journal does not make.
if strings.Contains(reason, "; from=<") {
return
}
if program == "cleanup" {
if _, ok := j.port25[queueID]; !ok {
return // a submission-port message, or one opened before this run
+45 -10
View File
@@ -256,12 +256,14 @@ func TestInboundHoldIsTheMiltersRow(t *testing.T) {
}
}
// The HELO name is the last thing on the line and is logged as the client
// wrote it. It cannot supply the row: the reply ends at the first "; from=<",
// which is Postfix's own.
// The HELO name is the last thing on the line. Postfix logs it with a space
// and ` <>()\";@` turned into "?" (src/smtpd/smtpd.c, helo_cmd()), so one
// that tried to spell another refusal arrives neutered and the row is
// Postfix's own; a HELO name with those characters left in is no line
// Postfix writes, and makes no row.
func TestInboundHeloCannotWriteTheRow(t *testing.T) {
j, st := inboundFixture()
j.handle(head+"postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <nobody@in.example.com>: Recipient address rejected: User unknown in relay recipient table; from=<real@example.net> to=<nobody@in.example.com> proto=ESMTP helo=<x 5.7.1 Refused by this server's deny list; from=<victim@bank.example> to=<ceo@in.example.com> proto=ESMTP helo=<y>", tailNow, false)
j.handle(head+"postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <nobody@in.example.com>: Recipient address rejected: User unknown in relay recipient table; from=<real@example.net> to=<nobody@in.example.com> proto=ESMTP helo=<x?5.7.1?Refused?by?this?server's?deny?list??from=?victim?bank.example??to=?ceo?in.example.com??proto=ESMTP?helo=?y?>", tailNow, false)
if len(st.rows) != 1 {
t.Fatalf("rows = %+v", st.rows)
}
@@ -271,23 +273,56 @@ func TestInboundHeloCannotWriteTheRow(t *testing.T) {
t.Errorf("row = %+v", got)
}
// A HELO name with a closing bracket in it does not lose the line either.
j, st = inboundFixture()
j.handle(head+"postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <nobody@in.example.com>: no; from=<real@example.net> to=<nobody@in.example.com> proto=ESMTP helo=<a>b>", tailNow, false)
if len(st.rows) != 1 || st.rows[0].From != "real@example.net" {
t.Errorf("rows = %+v", st.rows)
// Un-neutered, which Postfix never writes: a line with two tails makes
// no row, and above all not the one the HELO name spells.
for _, line := range []string{
head + "postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <nobody@in.example.com>: Recipient address rejected: User unknown in relay recipient table; from=<real@example.net> to=<nobody@in.example.com> proto=ESMTP helo=<x 5.7.1 Refused by this server's deny list; from=<victim@bank.example> to=<ceo@in.example.com> proto=ESMTP helo=<y>",
head + "postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <nobody@in.example.com>: no; from=<real@example.net> to=<nobody@in.example.com> proto=ESMTP helo=<a>b>",
} {
j, st = inboundFixture()
j.handle(line, tailNow, false)
if len(st.rows) != 0 {
t.Errorf("a line with an un-neutered HELO name wrote %+v", st.rows)
}
}
// The same on a verdict line: the filter's reply is not extended by the
// HELO name, so a stranger cannot make a refusal look like the deny list's.
j, st = inboundFixture()
j.handle(head+"postfix/inbound/smtpd[41]: Q1: client=x[203.0.113.9]", tailNow, false)
j.handle(head+"postfix/cleanup[52]: Q1: milter-reject: END-OF-MESSAGE from x[203.0.113.9]: 5.7.1 Spam message rejected; from=<real@example.net> to=<b@in.example.com> proto=ESMTP helo=<x this server's deny list; from=<spoofed@example.org> to=<b@in.example.com> proto=ESMTP helo=<y>", tailNow, false)
j.handle(head+"postfix/cleanup[52]: Q1: milter-reject: END-OF-MESSAGE from x[203.0.113.9]: 5.7.1 Spam message rejected; from=<real@example.net> to=<b@in.example.com> proto=ESMTP helo=<x?this?server's?deny?list??from=?spoofed?example.org??to=?b?in.example.com??proto=ESMTP?helo=?y?>", tailNow, false)
if len(st.rows) != 1 || st.rows[0].Detail != "5.7.1 Spam message rejected" || st.rows[0].From != "real@example.net" {
t.Errorf("rows = %+v", st.rows)
}
}
// The refused recipient is quoted in the reply in internal form - quotes
// removed, "; < > =" kept - so it can spell a whole "; from=<…> to=<…>
// proto=…" there. The line below is the shape mail.log on the test server
// held on 2026-10-17 for such a RCPT TO sent from outside (the audit's probe
// used a domain that is not inbound; here it is one). It writes no row in
// the stranger's words (security audit 2026-10-17, M2).
func TestInboundRecipientCannotWriteTheRow(t *testing.T) {
forged := `; from=<ceo@example.net> to=<board@in.example.com> proto=ESMTP helo=<x>; `
for name, line := range map[string]string{
"recipient unknown": head + `postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <` + forged + `@in.example.com>: Recipient address rejected: User unknown in relay recipient table; from=<probe@example.net> to=<"` + forged + `"@in.example.com> proto=ESMTP helo=<audit.example>`,
"forged sender also in MAIL FROM": head + `postfix/inbound/smtpd[41]: NOQUEUE: reject: RCPT from x[203.0.113.9]: 550 5.1.1 <` + forged + `@in.example.com>: Recipient address rejected: User unknown in relay recipient table; from=<"x; from=<ceo@example.net"@a.example> to=<"` + forged + `"@in.example.com> proto=ESMTP helo=<audit.example>`,
} {
j, st := inboundFixture()
j.handle(line, tailNow, false)
if len(st.rows) != 0 {
t.Errorf("%s: a line with two tails wrote %+v", name, st.rows)
}
}
// A plain refusal is still read whole, its reply up to Postfix's tail.
j, st := inboundFixture()
j.handle(unknownRcp, tailNow, false)
if len(st.rows) != 1 || st.rows[0].From != "a@example.net" || st.rows[0].To != "nobody@in.example.com" {
t.Errorf("rows = %+v", st.rows)
}
}
// A queue id is port 25's only until the message is queued, cleanup removes
// it unqueued, or the id is opened again by another listener - Postfix reuses
// ids.