f1d90a2a1bfa11247bbf338ae07fb77362f8e3cd
7
Commits
| Author | SHA1 | Message | Date | |
|---|---|---|---|---|
|
|
463d4ff3fe |
log tailer: the rotated mail.log read until postlogd lets it go
test / test (push) Canceled after 0s
postlogd opens maillog_file once per process (Postfix 3.7.11,
src/postlogd/postlogd.c, pre_jail_init()) and leaves it only when it
exits: at "postfix reload" master closes the service's status pipe
(src/master/master_service.c, master_restart_service() ->
master_status_cleanup()) and dgram_server_abort() exits on reading its end
(src/master/dgram_server.c). logrotate renames and creates, then runs the
reload (build/logrotate-mail.conf postrotate; logrotate 3.21.0,
logrotate.c, rotateLogSet(), after rotateSingleLog()), so lines go to the
renamed file in between, and the tailer, already on the new one, never
read them (assumptions A-33). follow() now keeps the renamed file open as a
rotatedTail and reads it on each tick for rotatedGrace (a minute, far
longer than the gap); its places are never saved as the resume point, so a
restart still reads the rotated file through readRotated. A truncated file
is not kept.
The RFC 3339 stamp goes (A-12): it was written for a maillog_file_format
said to arrive in Postfix 3.9; there is none in 3.7.11 nor in the 3.12
snapshot of 2026-09-25 (proto/postconf.proto; msg_logger.c,
msg_logger_print() keeps strftime("%b %d %H:%M:%S ")). Every fixture now
carries the stamp Postfix writes; logtail's TestMain fixes time.Local to
UTC, since the stamp is local time and this PC is UTC+3.
Tests: TestFollowReadsTheRotatedFileAfterTheSwitch (Linux: a line appended
to the renamed file after the switch reaches the store). Stand
(2026-10-14): go vet and go test ./... pass on the server (23 packages);
make e2e exit 0, delivery_log_survives_rotation included. The tested tree
was this commit plus the previous one; the CHANGELOG entry was written
after the run, and a comment's logrotate citation corrected
(rotateLogSet runs postrotate, not rotateSingleLog).
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
||
|
|
0ed03b2094 |
log tailer: expiry, Postfix's time values and refusal lines as Postfix writes them
test / test (push) Canceled after 0s
Expiry (assumptions A-8). Postfix 3.7.11 logs the end of a message's queue lifetime once per message, "<id>: from=<..>, status=expired, returned to sender" (src/qmgr/qmgr_active.c, qmgr_active_done_25_generic()), with no line per recipient; the tailer waited for "to=..., status=expired", which no Postfix writes, and the sweep closed only queued rows, so such rows stayed deferred. The tailer now reads qmgr's line (ExpireMessage: each recipient's newest open row of the id becomes bounced); the sweep closes a deferred row too when Postfix no longer holds the message, and counts as missed only a final line (sent, bounced, expiry). The queue listing's '#' (forced expiry, showq_compat.c showq_message()) is read as a flag (B-PQ1). Time values (B-PQ10, B-PQ11): conv_time() ported - one number, one lower-case unit, the parameter's default unit when none (get_def_time_unit: d for the lifetimes, h for delay_warning_time), the rest ignored; postconf -h -x expands $name; bounce_queue_lifetime capped at maximal_queue_lifetime as qmgr_post_init() caps it, so LongestLifetime is the queue lifetime. Refusals (A-21, A-23, A-24, A-15): smtpd_whatsup() ends the NOQUEUE line with sasl_username=<login> on an authenticated session; the line is now matched to its row by client, login and sender, and a line without a login is no application's. The client= line's login ends at the comma. The "IPv6:" trim goes (namaddr is built from state->addr). A row recovered from cleanup's line says that line names the last recipient only. Stand (2026-10-14, make e2e, exit 0): new expired_message_is_closed - defer_transports=smtp makes the retry service defer the message, postsuper -e and postqueue -i force its expiry; mail.log has "<id>: from=<alerts@sender.e2e.test>, status=force-expired, returned to sender" and the row goes deferred -> bounced; refusals_show_postfixs_line passes with the login match. go vet and go test ./... pass on the server. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> |
||
|
|
af130e268a |
findings of the reviews of audit stage 2b
Technical review (Opus) and security review (Fable) of 5be109b..5154bba;
reports in the session's scratchpad. Nothing above low from security; one
bug and three risks from the technical review. Migration 0009 is not
deployed, so it was extended.
- Bug: two refusals of one second swapped their NOQUEUE lines (each line
went to the newest lineless row). AttachRefusalLine now matches the
client address too (send_log.client_ip, written by the journal milter -
Postfix's line names the client and the sender, never the login: the
sasl_username part of the pattern never matched and could be fed by HELO,
security F1/F2), takes the nearest row in time and the oldest of equals,
and a line already on a row goes on no other (security F6).
- Waiting lines and recoveries lived only in memory while the saved offset
moved past them: a stop within 30 s lost them. The tracker now never saves
an offset past the oldest waiting item in its file (tracker.hold,
refusalLines.oldest) - for a recovery, the client= line that names its
login - so they are read again; the "once" guards make that harmless.
- A recovered row whose login the tailer did not see was nobody's: its
domain_id falls back to the envelope domain's.
- The fingerprint's file identity is the inode alone: the device number can
change across a host reboot and make the same log look rotated.
- A refused row carries its queue id; UpdateStatus's "newest row" now skips
refused rows, so a later message with that id does not flip it to sent.
- The alive mark: its age is read first and kept from then on, so asking
supervisord for 30 s cannot make it stale; the entrypoint removes it with
the sockets - a container restart is not the check's downtime, and a mark
from before would have counted the whole outage as "≈".
- Security F3: the sender check prints no ";" of the client's in the From:
text of its reply, and the tailer reads the envelope after the first ";"
- Postfix's own text.
- A refused row with a queue id and no stored lines says so (it was told the
mail.log text of 2.2.0); the fact's em dash is the house hyphen.
- Docs: architecture (client address, no login), guide § Health (warns on
either count), help topics log and sender-check (design
|
||
|
|
415334c2cc |
message page: a row the sweep closed says the panel closed it (stage 2b)
The History step of every bounced row said the receiving server refused
the message permanently or Postfix gave up, "the reason is in the delivery
log below" - for a row the reconcile sweep closed (reason "reconcile")
neither is known and the log has nothing (review of stage 1). Such a row's
step is now "Closed by the panel - Postfix no longer held the message and
mail.log never said what became of it ... rather than show a delivery it
cannot evidence." The help topic log names the case (design
|
||
|
|
e166a2ebd6 |
refused messages: the page shows what Postfix wrote (stage 2b, 0009)
The Delivery log box of every refused row said "This message never reached
the queue, so Postfix wrote no delivery lines for it" - untrue: Postfix
wrote a line for each. The owner, 2026-10-13: the box is required on every
message page. Pictured for him first (dev/shots, the refused variant of
out-message: wrong From with its queue id lines, rate-limited with the
NOQUEUE line); the variant has no mockup screen of its own - the guard ties
screens to pages, and its outline is out-message's.
- Wrong From: cleanup gives the message a queue id before the headers are
judged; the sender check reads {i} at end-of-headers and writes it on the
refused row. Its lines - stored under the id like any other's - are on the
page, but only those from 10 minutes before to 1 minute after the refusal
(store.SendLogLines for a rejected row): Postfix frees the id at once, and
a later message with it lends nothing. No mail.log fallback for a refused
row, for the same reason.
- Rate-limited and wrong client: refused at MAIL FROM, no queue id. Migration
0009 adds send_log.refusal_line; logtail.refusalLines matches smtpd's
"NOQUEUE: milter-reject: MAIL from ...; from=<...>" (not port 25's, not
CONNECT/EHLO) and store.AttachRefusalLine puts it on the newest refused row
of that sender (and login, when the line names it) within two minutes; a
line whose row is not written yet waits up to 30 s (retried at each pass).
- The page: the queue id fact says "given, the message was not queued" or
"none - refused at MAIL FROM, before one is given"; the box's caption is
"The line from mail.log for this refusal" for the latter; a row from
before says the line was not kept. LogLineLevel colours a refusal by its
reply: 5xx red, 4xx amber (IPv6 clients included). The id in the fact is
not muted as in the picture: the kit has no muted inline.
Tests: store (attach by sender, login, time; not a queued row, not one an
hour off; a refused row's lines are its own minutes); logtail (attach, wait
and retry, port 25 and other lines ignored); milter (the refused row carries
{i}); view (facts, caption, line levels); handlers (the line on the page,
the sentence without it). e2e refusals_show_postfixs_line: a client-address
refusal made there, and the pages of a wrong From, a rate-limited and a
wrong client refusal each show Postfix's line.
schema-migrations row 9, CHANGELOG [Unreleased], audit plan line ticked,
roadmap 25/62.
Evidence on the test server for this tree: make e2e exit 0 (the new case
in 5.4 s); go test ./... ok but for two schema tests, fixed after the run
(the schema at 0009) - store tests ok locally; the full run follows before
the push.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
||
|
|
a618ffb0e4 |
send log: rows belong to a domain by id (audit L12, 0008)
A domain user's log, the message page, a domain's statistics, the level-2 count and the notifier's refusal count picked send-log rows by domain name, so a domain deleted and re-added under its old name showed its earlier mail to the next assignee and went on counting it. Migration 0008 (not run on the live database yet, so extended here): send_log.domain_id and inbound_spam_log.inbound_domain_id, REFERENCES ... ON DELETE SET NULL, filled once by name from the registry as it is at migration time, each with an (id, created_at) index. - Writes: InsertQueued / InsertRejected set domain_id to the domain of the row's login (loginDomainID) - the journal milter and the sender check's refusal rows both go through them; the inbound journal sets inbound_domain_id from the inbound domain's name at insert. - Reads: SendLogFilter.DomainIDs (was Domains, by name) and InboundSpamFilter.DomainIDs are the scope; the global role still reads everything. The message page checks row.DomainID against the user's domains. DomainSendStats and CountMessages keep their name argument and select domain_id = (SELECT id FROM domains WHERE name = ?). The notifier joins send_log.domain_id to the domain and its application. - DMARC reports stay by name on purpose (a report is about the DNS name). Tests: store - scope by ids; a re-added domain's log, level-2 count and statistics hold its own row only, the global log both; inbound scope by ids. Handlers - the new assignee gets 404 for the old row's page and does not see it in the log, the global role sees both. Tests that wrote rows for a login that is no application now register it (a row is a domain's through its application). Schema at 0008 with the two columns and indexes. schema-migrations row 8, CHANGELOG [Unreleased], audit plan line ticked, roadmap 19/62. Evidence: go vet ./... clean; go test ./... ok locally but for the two Windows-only tests; the server run follows before the push. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> |
||
|
|
f9e75de8d1 |
store: users saved in one transaction, the last global kept inside it (audit M7, M9)
M7: DeleteUser counted the global users and then deleted; the handler's demotion and CreateGlobalUser checked and then wrote. MaxOpenConns(1) serialises statements, not pairs: two globals deleting or demoting each other at once could leave none. Now: - DeleteUser: a transaction that deletes first (taking the write lock) and then requires a global left (requireAGlobal) - ErrLastGlobal rolls back. - SaveUser: likewise for a demotion, the count inside the transaction after the write. The handler's early count stays only to answer before hashing a password; SaveUser decides, and ErrLastGlobal maps to the same message. - CreateGlobalUser: INSERT ... SELECT ... WHERE NOT EXISTS (SELECT 1 FROM users), one statement. M9: submitUserUpdate made five writes in a row (UpdateUser, sessions, SetUserRole, ClearUserReach with its error only logged, SetUserReach). store.SaveUser(UserChange) writes name, hash, e-mail, role and reach in one transaction (a global user's reach cleared); sessions end after it commits. The create path had the same flaw - user, reach and then e-mail in three writes - and now goes through AddUser, one transaction; CreateUser stays as a wrapper for its many test callers. SetUserRole is gone; writeUserReach is the reach write inside a transaction. Tests: store - two globals demoting, and deleting, each other from two goroutines: exactly one refused, one global left; a refused SaveUser (taken name, a reach to no domain, nothing assigned) changes nothing; promoted to global loses the reach; AddUser with a bad reach leaves no user; four setups at once create one user. Handlers (the users pages, direct): the whole change saved, back to domain with a reach; the last global not demoted and the typed rename not written; a domain user with nothing assigned refused, nothing changed; create with e-mail and reach. CHANGELOG [Unreleased], audit plan lines ticked (two), roadmap 17/62. Evidence: go vet ./... clean; go test ./internal/store ok; the users tests of ./internal/web/handlers ok; the server run follows before the push. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> |