From 63520f1678bf87601a3f364e350cb04a6ffba60d Mon Sep 17 00:00:00 2001 From: Mix Date: Wed, 14 Oct 2026 14:22:03 +0300 Subject: [PATCH] logtail: deliveryRe anchored at the head of the line (audit M12) The pattern that writes a row's status matched anywhere in a line: a port-25 reject line ending helo=, status=sent> parsed as (ID, victim, sent). parseDelivery now takes the stamp off with SplitTimestamp and matches `^host program[pid]: : to=<...>, ... status=`, as queueLineRe and the inbound patterns do. Tests: the probed HELO line, the same text in a quoted sender on a qmgr line, the text after an smtpd line's queue id - none parse; a syslog-stamped line as Postfix 3.7 writes it parses. The existing cases unchanged. CHANGELOG [Unreleased], audit plan line ticked, roadmap 11/61. Evidence: go test ./internal/logtail ok but for TestFollowTailsAndRotates (Windows); the server run of the stage follows before the push. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 7 +++++++ docs/audit-2026-10-12.md | 2 +- docs/roadmap.md | 2 +- internal/logtail/logtail.go | 12 ++++++++++-- internal/logtail/logtail_test.go | 28 ++++++++++++++++++++++++++++ 5 files changed, 47 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 61ee4b5..bb0c70d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,6 +21,13 @@ Format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/); version rewrite an old row of the same recipient. The close is now conditional on the row still being `queued`, and the row it closes carries the reason `reconcile` (audit 2026-10-12, H3). +- **A stranger's HELO name no longer reads as a delivery result.** The + pattern that turns a `mail.log` line into a status matched anywhere in the + line, so a port-25 client whose HELO name read + `: to=
, status=sent` could mark the matching row delivered. It + is now matched only at the head of the line, after the host and the + program, as the other patterns of the log tailer are (audit 2026-10-12, + M12). ### Added diff --git a/docs/audit-2026-10-12.md b/docs/audit-2026-10-12.md index ff0076a..3cafb21 100644 --- a/docs/audit-2026-10-12.md +++ b/docs/audit-2026-10-12.md @@ -627,7 +627,7 @@ has already run is never edited — the next file is added; the published grown for a tick and the new file has a line). Both are fixes to the tailer's blindness and stay on the list whatever the sweep's fate; their priority follows `tailer_blind_seconds`. -- [ ] **Anchor `deliveryRe`** at the head of the line like its two siblings; +- [x] **Anchor `deliveryRe`** at the head of the line like its two siblings; test with the probed HELO and quoted-sender lines. — **Opus** - [ ] **TLS re-copy** (H2): `postfix-cert-reload.sh` compares the mounted files to the copy and re-copies before `postfix reload` (atomically, same modes); diff --git a/docs/roadmap.md b/docs/roadmap.md index 8ecec57..3b1a0d5 100644 --- a/docs/roadmap.md +++ b/docs/roadmap.md @@ -42,7 +42,7 @@ in `git log` and [CHANGELOG.md](../CHANGELOG.md). | from-header-binding | Hold a message's `From:` header against the application that sends it | shipped `2.4.0` | 9/9 | [plans/from-header-binding.md](plans/from-header-binding.md) | | panel-redesign | Panel redesign (accepted mockups, design contract) | shipped `2.0.0` | 27/27 | [plans/panel-redesign.md](plans/panel-redesign.md) | | schema-squash | Squash SQLite migrations into a 2.x baseline | built in panel-redesign (stage 1) | — | [plans/panel-redesign.md](plans/panel-redesign.md) | -| audit-2026-10-12 | Follow-ups of the 2026-10-12 full-tree code audit, seven stages | in progress (stage 0 shipped `2.4.2`; next stages 1+2 → `2.5.0`) | 10/61 | [audit-2026-10-12.md](audit-2026-10-12.md) | +| audit-2026-10-12 | Follow-ups of the 2026-10-12 full-tree code audit, seven stages | in progress (stage 0 shipped `2.4.2`; next stages 1+2 → `2.5.0`) | 11/61 | [audit-2026-10-12.md](audit-2026-10-12.md) | **Recommended order** (not binding; owner, 2026-10-09: feature order follows development convenience): **panel-redesign** shipped as `2.0.0` (2026-10-11) and diff --git a/internal/logtail/logtail.go b/internal/logtail/logtail.go index 226ff0b..f509bca 100644 --- a/internal/logtail/logtail.go +++ b/internal/logtail/logtail.go @@ -88,17 +88,25 @@ type RetentionDays func() int // The ": to=, …, status=" shape is specific to the // delivery agents; qmgr/smtpd/cleanup lines do not match. // +// It is matched at the head of the line - the host name, "program[pid]:", +// then the queue id - after SplitTimestamp has taken the stamp off, like +// queueLineRe and the inbound patterns. Anywhere else the text is a +// stranger's: a port-25 reject line ends with the client's HELO name, which +// once parsed as a delivery result when it read ": to=<…>, status=sent" +// (audit 2026-10-12, M12). +// // The run before status= is lazy on purpose. Postfix appends the remote // server's reply verbatim, so a greedy match would take the *last* status= on // the line — and that one can come from the reply text, which the far end // controls. A bounce whose reply quoted "status=sent" would then be filed as a // success. The real field is always the first one after to=<…>. -var deliveryRe = regexp.MustCompile(`\b([0-9A-Za-z]+): to=<([^>]*)>,.*?\bstatus=(\w+)`) +var deliveryRe = regexp.MustCompile(`^\S+ [^\s\[]+\[\d+\]: ([0-9A-Za-z]+): to=<([^>]*)>,.*?\bstatus=(\w+)`) // parseDelivery extracts (queue-id, recipient, status) from a mail.log line. // ok is false for lines that are not recognised delivery results. func parseDelivery(line string) (queueID, recipient, status string, ok bool) { - m := deliveryRe.FindStringSubmatch(line) + _, rest := SplitTimestamp(line) + m := deliveryRe.FindStringSubmatch(rest) if m == nil { return "", "", "", false } diff --git a/internal/logtail/logtail_test.go b/internal/logtail/logtail_test.go index cf6fc46..c9b514e 100644 --- a/internal/logtail/logtail_test.go +++ b/internal/logtail/logtail_test.go @@ -116,6 +116,34 @@ func TestParseDelivery(t *testing.T) { line: "host postfix/cleanup[12]: BEEF03: message-id=", wantOK: false, }, + { + // The stamp Postfix 3.7's postlogd writes, as on the stand. + name: "syslog stamp", + line: "Oct 14 11:05:51 mail postfix/smtp[26]: 41E862C00D9E: to=, relay=x, dsn=2.0.0, status=sent (250 OK)", + wantOK: true, + queueID: "41E862C00D9E", + recipient: "a@example.net", + status: store.StatusSent, + }, + { + // A stranger's HELO name at the end of a port-25 reject line, as + // probed for the 2026-10-12 audit: it must not file a delivery. + name: "a delivery result in a HELO name is not one", + line: "Oct 14 11:05:51 mail postfix/inbound/smtpd[372]: NOQUEUE: reject: RCPT from unknown[203.0.113.7]: 554 5.7.1 : Relay access denied; from= to= proto=ESMTP helo=<41E862C00D9E: to=, status=sent>", + wantOK: false, + }, + { + // The same text in a quoted sender address, on a line that does + // have a queue id at its head. + name: "a delivery result in a quoted sender is not one", + line: `Oct 14 11:05:51 mail postfix/qmgr[10]: 5B4A2C1D3E: from=<"41E862C00D9E: to=, status=sent"@stranger.example>, size=500, nrcpt=1 (queue active)`, + wantOK: false, + }, + { + name: "an smtpd line with the text after its queue id is not one", + line: "Oct 14 11:05:51 mail postfix/smtpd[10]: 5B4A2C1D3E: client=unknown[203.0.113.7], sasl_username=41E862C00D9E: to=, status=sent", + wantOK: false, + }, } for _, c := range cases { t.Run(c.name, func(t *testing.T) {