diff --git a/docs/architecture.md b/docs/architecture.md index 19b2a95..d4ca974 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -278,7 +278,10 @@ server itself. starts without one). At start the time since the mark is the check's downtime - counted from Postfix's own start if that was later, and not at all when supervisord says Postfix is not running, since mail was then - stopped for another reason. The log tailer counts the mail: Postfix + stopped for another reason. Supervisord is asked for half a minute; when it + does not answer, the time since the mark is taken as an upper bound and the + day is marked estimated (`sender_check_days.estimated`), which the card + shows as ≈. The log tailer counts the mail: Postfix writes a warning naming the socket and then, from the same smtpd process, `milter-reject: … 451 4.7.1 Service unavailable` from the connection on (the client is told `454 4.3.0` at `AUTH` and leaves), so what is counted @@ -291,14 +294,17 @@ server itself. unix:: can't read SMFIC_HEADER reply packet header` and refuses the message with `4.7.1` (seen on the e2e stand with the panel frozen). One cleanup process serves message after message, so each such warning is - counted as a message. Both go into - `sender_check_days`, a - row per UTC day kept a year, and Server › Health shows today, 30 days and - 12 months. The second figure also sees a panel that is running and not - answering, which the mark does not. Downtime is cut at the UTC midnights - it crossed. A log read again after an unclean stop does not count again: - while the tailer catches up, a warning no later than the last one counted - is passed over. + counted as a message. The two are counted apart (the owner, 2026-10-14): + connections turned away in `deferred`, messages deferred mid-message in + `messages` of `sender_check_days`, a row per UTC day kept a year, and + Server › Health shows today, 30 days and 12 months in a column each. The + counts also see a panel that is running and not answering, which the mark + does not. Downtime is cut at the UTC midnights it crossed. A log read again + after an unclean stop does not count again: the count and the place in the + log it reached (the file's fingerprint and the offset past the line) are + saved in one transaction, and while the tailer catches up a warning at or + before that place in the same file is passed over - a second warning of + the same second is not lost; in another file the time decides. - **Why it is not a process of its own.** Decided with the owner: measure first. The role has a socket of its own so that the journal stays fail-open, and moving it out later changes where it is started and nothing @@ -396,13 +402,35 @@ name), and a pattern that could start there let a stranger's HELO name file a delivery (audit 2026-10-12, M12). **Read offset is persisted** (`logtail_state` table, in the baseline schema): the -tailer stores its position plus a fingerprint of the log's first 512 bytes, and -on start resumes from it, parsing the tail written while the panel was down. If -the fingerprint no longer matches (rotated or recreated in the meantime) it reads -the current file from the start; re-parsing lines is harmless because -`UpdateStatus` writes the same status onto the same row. Only a first-ever start, -with nothing stored, begins at end-of-file, so installing the panel does not -replay a pre-existing log. +tailer stores its position plus a fingerprint of the log - the hash of its first +512 bytes and the file's device and inode, so two logs that begin alike are two +files and a renamed file keeps its fingerprint - and on start resumes from it, +parsing the tail written while the panel was down. If the fingerprint no longer +matches, the log was rotated in the meantime: the tailer first opens +`mail.log.1` (left plain by `delaycompress`), and if that is the file the saved +place belongs to it reads it from there to its end, then the new file from its +start - what Postfix wrote between the stop and the rotation is not lost. A +`mail.log.1` that is another file (rotated twice) is logged with the time from +which nothing was read. Re-parsing lines is harmless because `UpdateStatus` +writes the same status onto the same row. Only a first-ever start, with nothing +stored, begins at end-of-file, so installing the panel does not replay a +pre-existing log. + +**A refusal's line, and a refusal the panel did not write.** A message refused +for its `From:` line has a queue id (cleanup gives one before the headers are +judged); the sender check writes it on the row, and the message's page shows +the lines stored under it - only those of the minutes around the refusal, since +Postfix frees the id at once. A message the journal milter refused at +`MAIL FROM` has none: the tailer reads smtpd's `NOQUEUE: milter-reject: MAIL +from …; from=<…>` and puts it on the newest refused row of that sender (and +login, when the line names it) within two minutes (`send_log.refusal_line`), +retrying for 30 s when the row is not written yet. The sender check writes its +row through a buffer after answering 550; a panel stopped in between wrote +none. The tailer remembers each queue id's login from smtpd's `client=` line, +and 30 s after cleanup's `milter-reject: END-OF-MESSAGE … 5.7.1 From:` line it +writes the row from the line if no refused row of that id exists +(`send_log.recovered`, shown on the page). It reads from its saved offset, so +a kill is covered as well as a clean stop. **Queue reconcile** is the backstop for what the log cannot explain at all: a row still `queued` more than two minutes after it was accepted, whose queue id diff --git a/docs/audit-2026-10-12.md b/docs/audit-2026-10-12.md index 60d3660..254f842 100644 --- a/docs/audit-2026-10-12.md +++ b/docs/audit-2026-10-12.md @@ -834,7 +834,7 @@ order - each stands on the one before. M13 fix on, not yet deployed when this was decided. The mockup `health` and help topic `sender-check` first (`design:` commit), then the page and `view/help.go`, word for word. - **Sonnet** -- [ ] Docs: architecture § Log tailer (the rotated file, the saved place, a +- [x] Docs: architecture § Log tailer (the rotated file, the saved place, a refusal's line and a recovered row), guide § Outbound log and § Health, schema-migrations.md for the mark on `sender_check_days`. — **Sonnet** diff --git a/docs/guide.md b/docs/guide.md index d390e3d..199eafd 100644 --- a/docs/guide.md +++ b/docs/guide.md @@ -404,14 +404,16 @@ readings, in the order of what stops mail first: sockets** (OpenDKIM, the sender check and the journal-milter). - **Sender check** — what the strict check of the `From:` line has cost today, in the last 30 days and in the last 12 months: for how long the - panel did not answer while Postfix was running, and how many messages - Postfix deferred because of it (see [Who an application may send + panel did not answer while Postfix was running, how many connections + Postfix turned away because of it, and how many messages it deferred in + the middle (see [Who an application may send as](#who-an-application-may-send-as)). A restart of the whole container is - not counted: mail was stopped for another reason then. What is counted as - a message is a connection Postfix turned away - it refuses before a - message is offered - so a monitor that only connects during an outage is - counted too; and when the panel hangs instead of stopping, the message it - hung on. Days are UTC days. The card warns when + not counted: mail was stopped for another reason then. A connection turned + away is refused before a message is offered, so a monitor that only + connects during an outage is counted too; a message deferred in the middle + is one the panel stopped answering for after it had begun. A time marked ≈ + is at most what it shows: at that start supervisord could not say since + when Postfix ran. Days are UTC days. The card warns when a message was deferred in the last 24 hours. If these numbers do not stay at nothing, the panel is in the way of your mail more than it should be - report it. @@ -1271,7 +1273,11 @@ refused row says why in its tag: `rate-limited` (a [level-2 rate limit](#rate-limiting--level-2-domain-and-application)), `wrong client` (the application's client IP list) or `wrong From` (see [Who an application may send as](#who-an-application-may-send-as)); a row refused before `2.4.0` -says `rejected`; +says `rejected`. A refused message's page shows what Postfix wrote about the +refusal: for `wrong From` the lines of the queue id the message had, for the +other two the one `NOQUEUE` line; a row refused before `2.5.1` says the line +was not kept, and one the panel wrote from `mail.log` after a restart - it +had stopped before writing the refusal itself - says so; *Details* opens that row's own page (`/outbound/log/{id}`). That page carries the sending domain, the application it was submitted under, the Postfix queue id and the journal id, beside the message's history — when it was diff --git a/docs/roadmap.md b/docs/roadmap.md index 1819bd7..f6ba7dd 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`, stages 1+2 `2.5.0`; next stage 2b → `2.5.1`) | 29/62 | [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`, stages 1+2 `2.5.0`; next stage 2b → `2.5.1`) | 30/62 | [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