Owner, 2026-10-18: "Фиаско, что очередь не была сделана. Как мы это допустили? Исправляем!" The mockups out-queue and in-queue (design629de5e, guards8525e8e). - postfix: postqueue -j gives each message's size and each recipient's delay_reason (src/postqueue/showq_json.c, format_json(): "delay_reason" only when LEN(why) > 0); QueueListing reads it with the page's 5 s, QueueMessages keeps the notifier's 30 s. - view: one Queue page type for both directions (queue.go), one polled box (queue_body.html): a row per recipient, oldest first, cut at 200 with a foot; the head "N messages · size", "Refreshes on its own" while empty; Last reply is the delay reason, or where the message is (active, hold, incoming) before there was one. Inbound has no Details: an inbound message has no page of its own. - handlers: one read of the queue, split by the recipient's domain against the inbound domains; an outbound recipient is linked to its send-log row (store.SendLogRefsByQueueID, through idx_send_log_queue_id, plan pinned in TestSendLogQueriesUseTheirIndexes), matched without regard to case, else the message's first row. Both pages are the global role's; the inbound one 404s with the relay off. Routes /inbound/queue (+ /fragment), menu, touch menu and sibling strip. - Overview: Queues · Both empty · outbound and inbound with the relay on. - Help: the queue topic rewritten, an Inbound queue topic (word for word with the mockup; domain administrators do not see it, as with the lists). - TestUnbuiltScreensAreOnTheRoadmap and its rule in development.md: an exempted screen must be named in roadmap.md; queue-table leaves the roadmap; guide, architecture, panel-redesign.md updated. Tests: go vet; go test ./internal/web/... ./internal/store ./internal/postfix ./internal/notify pass. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
678 lines
29 KiB
Go
678 lines
29 KiB
Go
package store
|
||
|
||
import (
|
||
"database/sql"
|
||
"errors"
|
||
"fmt"
|
||
"strings"
|
||
"time"
|
||
)
|
||
|
||
// Send-log status values (architecture.md § Persistence). "queued" is written
|
||
// by the journal-milter when a message is accepted; the log-tailer advances it
|
||
// to one of the final states as Postfix reports delivery per recipient.
|
||
const (
|
||
StatusQueued = "queued"
|
||
StatusSent = "sent"
|
||
StatusDeferred = "deferred"
|
||
StatusBounced = "bounced"
|
||
// StatusRejected marks a message the relay refused, and the row of that
|
||
// refusal. The journal-milter refuses at MAIL FROM with a 4xx when a level-2
|
||
// rate limit or the application's client-address list says no (Reason is
|
||
// ReasonLimit or ReasonClient; such a row has no queue-id). The sender check
|
||
// refuses a From: or Sender: line that is not the application's with a
|
||
// 550 (ReasonFrom, ReasonSender; its row has the queue-id). Every refused row is left out of the level-2
|
||
// message count (it was never sent).
|
||
StatusRejected = "rejected"
|
||
)
|
||
|
||
// SendLogEntry is a single queued send-log row. The journal-milter creates one
|
||
// per (queue-id, recipient) pair at end-of-message (architecture.md §
|
||
// Persistence); every field except the status/timestamps comes from the
|
||
// accepted message.
|
||
type SendLogEntry struct {
|
||
QueueID string
|
||
Domain string
|
||
AppLogin string
|
||
From string
|
||
To string
|
||
Subject string
|
||
// Reason and HeaderFrom are set on refused rows only: why the message
|
||
// was refused (Reason*), and for ReasonFrom and ReasonSender the address
|
||
// of the line refused (the column's name is from before Sender: was).
|
||
Reason string
|
||
HeaderFrom string
|
||
// ClientIP is the client a refusal at MAIL FROM came from (InsertRejected
|
||
// only), which Postfix's line about it names.
|
||
ClientIP string
|
||
}
|
||
|
||
// loginDomainID is the domain_id a row is written with: the domain of the
|
||
// application whose login it is, NULL for a login that is no application's
|
||
// (audit 2026-10-12, L12). The domain name of the row stays what the
|
||
// envelope said.
|
||
//
|
||
// The login is matched exactly (BINARY): it reaches the milter and the log in
|
||
// the case it is stored in, because Cyrus SASL 2.1.28 looks it up as given -
|
||
// lib/canonusr.c _canonuser_internal() only trims spaces and appends a realm,
|
||
// sasldb/allockey.c _sasl_alloc_key() copies it byte for byte into the key.
|
||
const loginDomainID = `(SELECT a.domain_id FROM applications a WHERE a.login = ?)`
|
||
|
||
// InsertQueued records an accepted message in the send log with status
|
||
// "queued". It is called from the journal-milter hot path, so it returns any
|
||
// error for the caller to log rather than deciding policy here; the milter
|
||
// must stay fail-open regardless (architecture.md § Persistence).
|
||
func (s *Store) InsertQueued(e SendLogEntry) error {
|
||
now := time.Now().UTC().Format(time.RFC3339)
|
||
_, err := s.db.Exec(
|
||
`INSERT INTO send_log
|
||
(queue_id, domain, app_login, from_addr, to_addr, subject, status, created_at, updated_at, domain_id)
|
||
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, `+loginDomainID+`)`,
|
||
e.QueueID, e.Domain, e.AppLogin, e.From, e.To, e.Subject, StatusQueued, now, now, e.AppLogin,
|
||
)
|
||
if err != nil {
|
||
return fmt.Errorf("insert send_log: %w", err)
|
||
}
|
||
return nil
|
||
}
|
||
|
||
// InsertTestMessage records the panel's own test message (Server › Health,
|
||
// test-email) as queued, before it is handed to Postfix: from postmaster@ the
|
||
// hostname, under the hostname as its domain, with no application and no
|
||
// queue id yet - cleanup assigns one, and SetSendLogQueueID puts it on the
|
||
// row once the tailer reads it. It returns the row's id.
|
||
func (s *Store) InsertTestMessage(domain, from, to, subject string) (int64, error) {
|
||
now := time.Now().UTC().Format(time.RFC3339)
|
||
res, err := s.db.Exec(
|
||
`INSERT INTO send_log (queue_id, domain, app_login, from_addr, to_addr, subject, status, created_at, updated_at)
|
||
VALUES ('', ?, '', ?, ?, ?, ?, ?, ?)`,
|
||
domain, from, to, subject, StatusQueued, now, now,
|
||
)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("insert test message: %w", err)
|
||
}
|
||
return res.LastInsertId()
|
||
}
|
||
|
||
// SetSendLogQueueID gives a row that has none the queue id Postfix assigned
|
||
// its message. A row that has one keeps it.
|
||
func (s *Store) SetSendLogQueueID(id int64, queueID string) error {
|
||
if _, err := s.db.Exec(`UPDATE send_log SET queue_id = ? WHERE id = ? AND queue_id = ''`, queueID, id); err != nil {
|
||
return fmt.Errorf("set queue id of send_log %d: %w", id, err)
|
||
}
|
||
return nil
|
||
}
|
||
|
||
// CloseUnmatchedTestMessages closes the test messages written before then
|
||
// that never learned a queue id - the panel restarted between the hand-over
|
||
// and cleanup's line, or the line was missed: nothing will ever report on
|
||
// them. They are closed as the sweep closes a row (bounced, reason
|
||
// reconcile), so their page says the panel decided it.
|
||
func (s *Store) CloseUnmatchedTestMessages(before time.Time) (int64, error) {
|
||
now := time.Now().UTC().Format(time.RFC3339)
|
||
res, err := s.db.Exec(
|
||
`UPDATE send_log SET status = ?, reason = ?, updated_at = ?
|
||
WHERE queue_id = '' AND app_login = '' AND status = ? AND created_at < ?`,
|
||
StatusBounced, ReasonReconcile, now, StatusQueued, before.UTC().Format(time.RFC3339))
|
||
if err != nil {
|
||
return 0, fmt.Errorf("close test messages with no queue id: %w", err)
|
||
}
|
||
return res.RowsAffected()
|
||
}
|
||
|
||
// DeleteSendLogRow removes one row: a test message Postfix did not take.
|
||
func (s *Store) DeleteSendLogRow(id int64) error {
|
||
if _, err := s.db.Exec(`DELETE FROM send_log WHERE id = ?`, id); err != nil {
|
||
return fmt.Errorf("delete send_log %d: %w", id, err)
|
||
}
|
||
return nil
|
||
}
|
||
|
||
// CountTestMessagesSince counts the test messages sent from addr since then:
|
||
// rows from that address with no application, the shape InsertTestMessage
|
||
// writes.
|
||
func (s *Store) CountTestMessagesSince(addr string, since time.Time) (int, error) {
|
||
var n int
|
||
err := s.db.QueryRow(`SELECT COUNT(*) FROM send_log WHERE from_addr = ? AND app_login = '' AND created_at >= ?`,
|
||
addr, since.UTC().Format(time.RFC3339)).Scan(&n)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("count test messages: %w", err)
|
||
}
|
||
return n, nil
|
||
}
|
||
|
||
// InsertRejected records a refused message (StatusRejected), so the refusal is
|
||
// visible in the send-log UI with its reason. The journal-milter writes its
|
||
// MAIL FROM refusals with only the fields known there (domain, sender, app
|
||
// login, client address): no queue-id, no recipient. The sender check writes
|
||
// its From: refusals with the queue-id and the first recipient.
|
||
func (s *Store) InsertRejected(e SendLogEntry) error {
|
||
now := time.Now().UTC().Format(time.RFC3339)
|
||
_, err := s.db.Exec(
|
||
`INSERT INTO send_log
|
||
(queue_id, domain, app_login, from_addr, to_addr, subject, status, reason, header_from, client_ip, created_at, updated_at, domain_id)
|
||
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, `+loginDomainID+`)`,
|
||
e.QueueID, e.Domain, e.AppLogin, e.From, e.To, e.Subject, StatusRejected, e.Reason, e.HeaderFrom, e.ClientIP, now, now, e.AppLogin,
|
||
)
|
||
if err != nil {
|
||
return fmt.Errorf("insert rejected send_log: %w", err)
|
||
}
|
||
return nil
|
||
}
|
||
|
||
// UpdateStatus advances the delivery status of the send-log rows matching a
|
||
// (queue-id, recipient) pair, which the log-tailer parses out of mail.log.
|
||
// Recipient matching is case-insensitive. Postfix keeps the case the client
|
||
// wrote, and the milter's row holds it as Postfix logs it
|
||
// (milter.recipientAsLogged); but a recipient repeated in another case is
|
||
// one recipient to Postfix - cleanup drops the second, comparing folded
|
||
// (Postfix 3.10.13, src/cleanup/cleanup_out_recipient.c, been_here() with
|
||
// BH_FLAG_FOLD) - and one row to the milter, spelt as first given, and
|
||
// log_adhoc() writes orig_to= only when it differs from to= other than in
|
||
// case (src/global/log_adhoc.c, strcasecmp_utf8()). Assumptions D-S20. It
|
||
// returns the
|
||
// number of rows updated so the caller can tell whether the line matched a
|
||
// journal entry.
|
||
//
|
||
// Only the newest row of the pair is updated. Postfix reuses a short queue id
|
||
// once the message has left the queue, and a row outlives that by months; a
|
||
// line about today's message must not rewrite an old one (audit 2026-10-12,
|
||
// review of stage 1).
|
||
//
|
||
// A row the reconcile sweep closed (reason "reconcile") that a delivery line
|
||
// now speaks of was closed on a guess the log could have settled: the log's
|
||
// status wins, the reason becomes "reconcile-contradicted" - which row, and
|
||
// updated_at says when - and the day's reconcile_contradicted counts it
|
||
// (delivery_log_days), once, since the row no longer reads "reconcile".
|
||
//
|
||
// The transaction's first statement is a write. A transaction that reads
|
||
// first and then writes fails at once with "database is locked" when another
|
||
// connection - the dmarc-ingest process opens the same file - commits in
|
||
// between, and the line would be lost; a write first takes the write lock,
|
||
// and the busy timeout waits for it. SQLite 3.53.4, btree.c btreeBeginTrans():
|
||
// the busy handler is retried only while the connection has no transaction
|
||
// open, so the upgrade of a read transaction fails with SQLITE_BUSY at once -
|
||
// also while the other connection merely holds the write lock - and with
|
||
// SQLITE_BUSY_SNAPSHOT after it committed (https://sqlite.org/rescode.html#busy_snapshot).
|
||
// Every other transaction of this package opens with a write for this reason.
|
||
func (s *Store) UpdateStatus(queueID, recipient, status string) (int64, error) {
|
||
now := time.Now().UTC()
|
||
tx, err := s.db.Begin()
|
||
if err != nil {
|
||
return 0, fmt.Errorf("update send_log status: %w", err)
|
||
}
|
||
defer tx.Rollback()
|
||
// A refused row carries the queue id it was given, and that id may be the
|
||
// next message's: a delivery line is never about a refusal.
|
||
const newest = `id = (SELECT MAX(id) FROM send_log WHERE queue_id = ? AND to_addr = ? COLLATE NOCASE AND status <> 'rejected')`
|
||
marked, err := tx.Exec(
|
||
`UPDATE send_log SET reason = ? WHERE `+newest+` AND reason = ?`,
|
||
ReasonReconcileContradicted, queueID, recipient, ReasonReconcile,
|
||
)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("update send_log status: %w", err)
|
||
}
|
||
contradicted, _ := marked.RowsAffected()
|
||
res, err := tx.Exec(
|
||
`UPDATE send_log SET status = ?, updated_at = ? WHERE `+newest,
|
||
status, now.Format(time.RFC3339), queueID, recipient,
|
||
)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("update send_log status: %w", err)
|
||
}
|
||
if contradicted > 0 {
|
||
if _, err := tx.Exec(
|
||
`INSERT INTO delivery_log_days (day, reconcile_contradicted) VALUES (?, ?)
|
||
ON CONFLICT (day) DO UPDATE SET reconcile_contradicted = reconcile_contradicted + excluded.reconcile_contradicted`,
|
||
now.Local().Format(dayLayout), contradicted,
|
||
); err != nil {
|
||
return 0, fmt.Errorf("update send_log status: count the contradicted sweep: %w", err)
|
||
}
|
||
}
|
||
if err := tx.Commit(); err != nil {
|
||
return 0, fmt.Errorf("update send_log status: %w", err)
|
||
}
|
||
n, _ := res.RowsAffected()
|
||
return n, nil
|
||
}
|
||
|
||
// CloseUnreported is the reconcile sweep's close of one row, by its id:
|
||
// "bounced", marked reason "reconcile" so it is known who decided it
|
||
// (architecture.md § Log tailer). Only a row still open - "queued" or
|
||
// "deferred" - is closed; a final result the log wrote an instant earlier
|
||
// stands (audit 2026-10-12, H3). It returns the number of rows closed, 0 or 1.
|
||
func (s *Store) CloseUnreported(id int64) (int64, error) {
|
||
now := time.Now().UTC().Format(time.RFC3339)
|
||
res, err := s.db.Exec(
|
||
`UPDATE send_log SET status = ?, reason = ?, updated_at = ? WHERE id = ? AND status IN (?, ?)`,
|
||
StatusBounced, ReasonReconcile, now, id, StatusQueued, StatusDeferred,
|
||
)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("close unreported send_log row: %w", err)
|
||
}
|
||
n, _ := res.RowsAffected()
|
||
return n, nil
|
||
}
|
||
|
||
// ExpireMessage closes the rows of a message Postfix gave up on at the end of
|
||
// its queue lifetime: each recipient's newest row with that queue id, if it
|
||
// is still open ("queued" or "deferred"), becomes "bounced" - Postfix returns
|
||
// the message to its sender. Postfix 3.10.13, src/qmgr/qmgr_active.c,
|
||
// qmgr_active_done_25_generic(), logs expiry once per message, "<id>:
|
||
// from=<..>, status=expired, returned to sender", with no line per
|
||
// recipient: the recipients' last lines say "deferred" (assumptions A-8). It
|
||
// returns the number of rows closed.
|
||
func (s *Store) ExpireMessage(queueID string) (int64, error) {
|
||
now := time.Now().UTC().Format(time.RFC3339)
|
||
res, err := s.db.Exec(
|
||
`UPDATE send_log SET status = ?, updated_at = ?
|
||
WHERE status IN (?, ?) AND id IN (
|
||
SELECT MAX(id) FROM send_log WHERE queue_id = ? AND status <> 'rejected'
|
||
GROUP BY to_addr COLLATE NOCASE)`,
|
||
StatusBounced, now, StatusQueued, StatusDeferred, queueID,
|
||
)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("expire send_log rows of %s: %w", queueID, err)
|
||
}
|
||
n, _ := res.RowsAffected()
|
||
return n, nil
|
||
}
|
||
|
||
// openRows selects the rows still open, StatusQueued and StatusDeferred
|
||
// written as literals: a term the same as the WHERE of the partial index
|
||
// idx_send_log_open (migration 0010) is what lets SQLite use it
|
||
// (https://sqlite.org/partialindex.html § 3), and a bound parameter is not.
|
||
const openRows = `status IN ('queued', 'deferred') AND queue_id <> ''`
|
||
|
||
// listOpenQuery is ListOpenOlderThan's. The unary + on the order keeps SQLite
|
||
// from walking the whole table in id order instead of the index
|
||
// (https://sqlite.org/optoverview.html § 18): the open rows are few, and
|
||
// sorting them is nothing.
|
||
const listOpenQuery = `SELECT id, queue_id, to_addr FROM send_log
|
||
WHERE ` + openRows + ` AND created_at < ?
|
||
ORDER BY +id`
|
||
|
||
// QueuedDelivery is a send-log row still waiting for a delivery result,
|
||
// reduced to what the log-tailer's reconcile sweep needs to look it up in the
|
||
// Postfix queue and, failing that, to close it (architecture.md § Log tailer).
|
||
type QueuedDelivery struct {
|
||
ID int64
|
||
QueueID string
|
||
To string
|
||
}
|
||
|
||
// ListOpenOlderThan returns the rows still open - "queued", or "deferred"
|
||
// and waiting for the next attempt - that were accepted before cutoff, old
|
||
// enough that Postfix should long since have reported a result for them or
|
||
// still hold the message. Rows without a queue-id are skipped: the milter
|
||
// refused those before Postfix ever saw the message, so the queue has
|
||
// nothing to say about them. A deferred row is among them because Postfix
|
||
// can drop a deferred message without a line per recipient: at expiry (one
|
||
// line per message, ExpireMessage) and by postsuper -d (only "removed").
|
||
//
|
||
// created_at is stored as RFC3339 UTC, so a lexical comparison against the same
|
||
// format is chronologically correct. SQLite 3.53.4 compares TEXT with the
|
||
// BINARY collation, memcmp() (https://sqlite.org/datatype3.html § 7), and
|
||
// time.RFC3339 of a UTC time is fixed-width, YYYY-MM-DDTHH:MM:SSZ.
|
||
func (s *Store) ListOpenOlderThan(cutoff time.Time) ([]QueuedDelivery, error) {
|
||
rows, err := s.db.Query(listOpenQuery, cutoff.UTC().Format(time.RFC3339))
|
||
if err != nil {
|
||
return nil, fmt.Errorf("list queued send_log rows: %w", err)
|
||
}
|
||
defer rows.Close()
|
||
|
||
var out []QueuedDelivery
|
||
for rows.Next() {
|
||
var d QueuedDelivery
|
||
if err := rows.Scan(&d.ID, &d.QueueID, &d.To); err != nil {
|
||
return nil, fmt.Errorf("scan queued send_log row: %w", err)
|
||
}
|
||
out = append(out, d)
|
||
}
|
||
return out, rows.Err()
|
||
}
|
||
|
||
// SendLogRow is one row as returned to the monitoring UI (architecture.md §
|
||
// Persistence): a SendLogEntry plus the fields that only exist once a row has
|
||
// been written (id, current status, timestamps).
|
||
type SendLogRow struct {
|
||
ID int64
|
||
QueueID string
|
||
Domain string
|
||
// DomainID is the domain the row belongs to; 0 when it is nobody's but
|
||
// the global role's (its domain was deleted, or its login was none).
|
||
DomainID int64
|
||
AppLogin string
|
||
From string
|
||
To string
|
||
Subject string
|
||
Status string
|
||
// Reason and HeaderFrom: see SendLogEntry.
|
||
Reason string
|
||
HeaderFrom string
|
||
// RefusalLine is Postfix's line about a refusal that has no queue id
|
||
// (migration 0009); "" for every other row, and for one refused before.
|
||
RefusalLine string
|
||
// Recovered is a refusal row the log tailer wrote from mail.log because
|
||
// the panel stopped before it wrote the row itself.
|
||
Recovered bool
|
||
CreatedAt time.Time
|
||
// UpdatedAt is when the status last changed — the log-tailer's report of
|
||
// the delivery attempt. It equals CreatedAt while a row is still queued.
|
||
UpdatedAt time.Time
|
||
}
|
||
|
||
// attachRefusalLineQuery is AttachRefusalLine's. The refused row is found by
|
||
// its time among the refused rows
|
||
// (idx_send_log_rejected: the status a literal, and the unary + keeps
|
||
// SQLite from walking every refusal without a queue id instead), and the
|
||
// line by idx_send_log_refusal_line (migration 0010; the second term is that
|
||
// index's WHERE) - https://sqlite.org/partialindex.html § 3,
|
||
// optoverview.html § 18.
|
||
const attachRefusalLineQuery = `UPDATE send_log SET refusal_line = ?1 WHERE id = (
|
||
SELECT id FROM send_log
|
||
WHERE status = 'rejected' AND +queue_id = '' AND refusal_line = ''
|
||
AND reason IN ('', ?2, ?3) AND from_addr = ?4 COLLATE NOCASE AND client_ip = ?5
|
||
AND app_login = ?9 COLLATE NOCASE
|
||
AND created_at BETWEEN ?6 AND ?7
|
||
ORDER BY ABS(julianday(created_at) - julianday(?8)), id
|
||
LIMIT 1)
|
||
AND NOT EXISTS (SELECT 1 FROM send_log WHERE refusal_line = ?1 AND refusal_line <> '')`
|
||
|
||
// AttachRefusalLine puts Postfix's line about a refusal at MAIL FROM on the
|
||
// row the journal milter wrote for it (audit 2026-10-12, stage 2b). Such a
|
||
// refusal has no queue id, and the line names no login, so the row is found
|
||
// by what the line says: a refused row of that client, login and sender
|
||
// without a line yet - the login is smtpd's sasl_username= on the line, so
|
||
// two applications behind one address sending as one sender are told apart
|
||
// (assumptions A-21) - written within two minutes of the line's time; the nearest in
|
||
// time, the oldest of equals, when there are several - lines are read in the
|
||
// order the rows were written, so two refusals of one second take one line
|
||
// each in turn (review of stage 2b). A line already on a row - read again
|
||
// after a restart - goes on no other. It reports whether a row took the line.
|
||
//
|
||
// SQLite 3.53.4: the choice and the write are one UPDATE, a write transaction
|
||
// from its start (https://sqlite.org/lang_transaction.html § 2.1); julianday()
|
||
// reads YYYY-MM-DDTHH:MM:SSZ, the T and the Z included (lang_datefunc.html
|
||
// § 2); NOCASE folds ASCII only (datatype3.html § 7.1); ?1 is bound once and
|
||
// used twice (lang_expr.html § 4).
|
||
func (s *Store) AttachRefusalLine(clientIP, login, from string, at time.Time, line string) (bool, error) {
|
||
// An empty line is what "no line" is on a row; the statement's second
|
||
// term would let it through, the old statement did not (review of stage
|
||
// 3). No caller passes one.
|
||
if line == "" {
|
||
return false, nil
|
||
}
|
||
res, err := s.db.Exec(attachRefusalLineQuery,
|
||
line, ReasonLimit, ReasonClient, from, clientIP,
|
||
at.Add(-refusalLineWindow).UTC().Format(time.RFC3339),
|
||
at.Add(refusalLineWindow).UTC().Format(time.RFC3339),
|
||
at.UTC().Format(time.RFC3339),
|
||
login,
|
||
)
|
||
if err != nil {
|
||
return false, fmt.Errorf("attach refusal line: %w", err)
|
||
}
|
||
n, _ := res.RowsAffected()
|
||
return n > 0, nil
|
||
}
|
||
|
||
// RecoverRefusal writes the row of a message the sender check refused for its
|
||
// From: line, from Postfix's line about it, when the panel stopped before it
|
||
// wrote the row itself (audit 2026-10-12, stage 2b): the check answers 550
|
||
// and writes the row through a buffer a moment later. The message had a queue
|
||
// id; a refused row with that id from around at means the row was written,
|
||
// and nothing is. The domain is the login's, or - when the tailer did not see the login, its
|
||
// client= line read before a restart - the envelope's, so the row is still
|
||
// its domain's administrator's (review of stage 2b). It reports whether it
|
||
// wrote one: the check and the insert are one statement (see
|
||
// CreateGlobalUser), and an INSERT ... SELECT of no row reports 0.
|
||
func (s *Store) RecoverRefusal(e SendLogEntry, at time.Time) (bool, error) {
|
||
stamp := at.UTC().Format(time.RFC3339)
|
||
res, err := s.db.Exec(
|
||
`INSERT INTO send_log
|
||
(queue_id, domain, app_login, from_addr, to_addr, subject, status, reason, header_from, recovered, created_at, updated_at, domain_id)
|
||
SELECT ?, ?, ?, ?, ?, '', ?, ?, ?, 1, ?, ?,
|
||
COALESCE(`+loginDomainID+`, (SELECT d.id FROM domains d WHERE d.name = ?))
|
||
WHERE NOT EXISTS (SELECT 1 FROM send_log
|
||
WHERE queue_id = ? AND status = ? AND created_at BETWEEN ? AND ?)`,
|
||
e.QueueID, e.Domain, e.AppLogin, e.From, e.To, StatusRejected, e.Reason, e.HeaderFrom, stamp, stamp, e.AppLogin, e.Domain,
|
||
e.QueueID, StatusRejected,
|
||
at.Add(-refusalLineWindow).UTC().Format(time.RFC3339), at.Add(refusalLineWindow).UTC().Format(time.RFC3339),
|
||
)
|
||
if err != nil {
|
||
return false, fmt.Errorf("recover refusal %s: %w", e.QueueID, err)
|
||
}
|
||
n, _ := res.RowsAffected()
|
||
return n > 0, nil
|
||
}
|
||
|
||
// refusalLineWindow is how far apart a refusal's row and its log line may be
|
||
// dated: the milter writes the row at MAIL FROM, Postfix the line a moment
|
||
// later, and the log's stamps are whole seconds.
|
||
const refusalLineWindow = 2 * time.Minute
|
||
|
||
// ErrSendLogNotFound is returned by GetSendLog for an id that no longer exists.
|
||
// Send-log rows are pruned on the retention window, so a bookmarked delivery
|
||
// disappearing is expected, not a fault.
|
||
var ErrSendLogNotFound = errors.New("send-log entry not found")
|
||
|
||
// GetSendLog returns a single send-log row by id, for the delivery detail page
|
||
// the log links each row to.
|
||
func (s *Store) GetSendLog(id int64) (SendLogRow, error) {
|
||
var (
|
||
row SendLogRow
|
||
createdAt, updatedAt string
|
||
)
|
||
err := s.db.QueryRow(
|
||
`SELECT id, queue_id, domain, COALESCE(domain_id, 0), app_login, from_addr, to_addr, subject, status, reason, header_from, refusal_line, recovered, created_at, updated_at
|
||
FROM send_log WHERE id = ?`, id,
|
||
).Scan(&row.ID, &row.QueueID, &row.Domain, &row.DomainID, &row.AppLogin, &row.From, &row.To,
|
||
&row.Subject, &row.Status, &row.Reason, &row.HeaderFrom, &row.RefusalLine, &row.Recovered, &createdAt, &updatedAt)
|
||
if errors.Is(err, sql.ErrNoRows) {
|
||
return SendLogRow{}, ErrSendLogNotFound
|
||
}
|
||
if err != nil {
|
||
return SendLogRow{}, fmt.Errorf("get send_log %d: %w", id, err)
|
||
}
|
||
row.CreatedAt, _ = time.Parse(time.RFC3339, createdAt)
|
||
row.UpdatedAt, _ = time.Parse(time.RFC3339, updatedAt)
|
||
return row, nil
|
||
}
|
||
|
||
// SendLogFilter narrows QuerySendLog/CountSendLog. It carries two kinds of
|
||
// narrowing, and they behave in opposite ways on purpose.
|
||
//
|
||
// Domain and AppLogin are the operator's own filters, chosen in the UI: an
|
||
// empty field matches everything.
|
||
//
|
||
// DomainIDs and AllDomains are the authorization scope, which no query
|
||
// parameter may widen. DomainIDs is the exhaustive set of domains the caller
|
||
// is entitled to read, by id - a row whose domain was deleted is nobody's
|
||
// (audit 2026-10-12, L12) - applied as an IN constraint; AllDomains lifts that
|
||
// restriction and is the only way to read the whole journal. A zero-valued
|
||
// filter therefore matches *no* rows: a caller that forgets to state a scope
|
||
// gets an empty log rather than every tenant's mail, which is the failure mode
|
||
// this struct exists to make impossible.
|
||
type SendLogFilter struct {
|
||
Domain string
|
||
AppLogin string
|
||
DomainIDs []int64
|
||
AllDomains bool
|
||
// Status is a row's status, and Since and Until are days: from the
|
||
// first's midnight up to, not including, midnight after the last, in the
|
||
// container's zone.
|
||
// Zero values do not narrow.
|
||
Status string
|
||
Since, Until time.Time
|
||
}
|
||
|
||
// sendLogPageQuery is a page of the rows where selects, newest first. A page
|
||
// of one domain or one application reads its rows off idx_send_log_domain_id
|
||
// or idx_send_log_app_login (migration 0010), already in id order; a scope of
|
||
// several domains is sorted, keeping only the page.
|
||
func sendLogPageQuery(where string) string {
|
||
return `SELECT id, queue_id, domain, COALESCE(domain_id, 0), app_login, from_addr, to_addr, subject, status, reason, header_from, created_at, updated_at
|
||
FROM send_log` + where + `
|
||
ORDER BY id DESC
|
||
LIMIT ? OFFSET ?`
|
||
}
|
||
|
||
// QuerySendLog returns send-log rows matching filter, newest first, for the
|
||
// monitoring screen's server-side pagination (product.md's send-log view).
|
||
// The filter's authorization scope is mandatory: see SendLogFilter.
|
||
func (s *Store) QuerySendLog(filter SendLogFilter, limit, offset int) ([]SendLogRow, error) {
|
||
where, args := sendLogWhere(filter)
|
||
args = append(args, limit, offset)
|
||
rows, err := s.db.Query(sendLogPageQuery(where), args...)
|
||
if err != nil {
|
||
return nil, fmt.Errorf("query send_log: %w", err)
|
||
}
|
||
defer rows.Close()
|
||
|
||
var out []SendLogRow
|
||
for rows.Next() {
|
||
var (
|
||
row SendLogRow
|
||
createdAt, updatedAt string
|
||
)
|
||
if err := rows.Scan(&row.ID, &row.QueueID, &row.Domain, &row.DomainID, &row.AppLogin,
|
||
&row.From, &row.To, &row.Subject, &row.Status, &row.Reason, &row.HeaderFrom, &createdAt, &updatedAt); err != nil {
|
||
return nil, fmt.Errorf("scan send_log row: %w", err)
|
||
}
|
||
row.CreatedAt, _ = time.Parse(time.RFC3339, createdAt)
|
||
row.UpdatedAt, _ = time.Parse(time.RFC3339, updatedAt)
|
||
out = append(out, row)
|
||
}
|
||
return out, rows.Err()
|
||
}
|
||
|
||
// CountSendLog returns how many send-log rows match filter, so the monitoring
|
||
// screen can render page numbers/next-prev links.
|
||
func (s *Store) CountSendLog(filter SendLogFilter) (int64, error) {
|
||
where, args := sendLogWhere(filter)
|
||
var n int64
|
||
if err := s.db.QueryRow(`SELECT COUNT(*) FROM send_log`+where, args...).Scan(&n); err != nil {
|
||
return 0, fmt.Errorf("count send_log: %w", err)
|
||
}
|
||
return n, nil
|
||
}
|
||
|
||
func sendLogWhere(f SendLogFilter) (string, []any) {
|
||
var clauses []string
|
||
var args []any
|
||
if !f.AllDomains {
|
||
// No scope is not "no restriction": a domain administrator whose last
|
||
// assignment was deleted owns nothing in the journal and must see
|
||
// nothing, and the same clause catches a caller that never set a scope.
|
||
if len(f.DomainIDs) == 0 {
|
||
return " WHERE 1 = 0", nil
|
||
}
|
||
marks := make([]string, len(f.DomainIDs))
|
||
for i, id := range f.DomainIDs {
|
||
marks[i] = "?"
|
||
args = append(args, id)
|
||
}
|
||
clauses = append(clauses, "domain_id IN ("+strings.Join(marks, ", ")+")")
|
||
}
|
||
if f.Domain != "" {
|
||
clauses = append(clauses, "domain = ?")
|
||
args = append(args, f.Domain)
|
||
}
|
||
if f.AppLogin != "" {
|
||
clauses = append(clauses, "app_login = ?")
|
||
args = append(args, f.AppLogin)
|
||
}
|
||
if f.Status != "" {
|
||
clauses = append(clauses, "status = ?")
|
||
args = append(args, f.Status)
|
||
}
|
||
// created_at is RFC3339 UTC, so comparing it as text against the same
|
||
// format is comparing moments (as InboundSpamFilter's days).
|
||
if !f.Since.IsZero() {
|
||
y, m, d := f.Since.Date()
|
||
clauses = append(clauses, "created_at >= ?")
|
||
args = append(args, time.Date(y, m, d, 0, 0, 0, 0, time.Local).UTC().Format(time.RFC3339))
|
||
}
|
||
if !f.Until.IsZero() {
|
||
y, m, d := f.Until.Date()
|
||
clauses = append(clauses, "created_at < ?")
|
||
args = append(args, time.Date(y, m, d+1, 0, 0, 0, 0, time.Local).UTC().Format(time.RFC3339))
|
||
}
|
||
if len(clauses) == 0 {
|
||
return "", nil
|
||
}
|
||
return " WHERE " + strings.Join(clauses, " AND "), args
|
||
}
|
||
|
||
// DeleteSendLogBefore removes send-log rows created before cutoff,
|
||
// implementing the configurable retention window (architecture.md §
|
||
// Persistence, SEND_LOG_RETENTION_DAYS). It returns the number of rows pruned.
|
||
// created_at is stored as RFC3339 UTC, so a lexical comparison against the
|
||
// same format is chronologically correct (see ListOpenOlderThan).
|
||
func (s *Store) DeleteSendLogBefore(cutoff time.Time) (int64, error) {
|
||
res, err := s.db.Exec(
|
||
`DELETE FROM send_log WHERE created_at < ?`,
|
||
cutoff.UTC().Format(time.RFC3339),
|
||
)
|
||
if err != nil {
|
||
return 0, fmt.Errorf("prune send_log: %w", err)
|
||
}
|
||
n, _ := res.RowsAffected()
|
||
return n, nil
|
||
}
|
||
|
||
// SendLogRef is one send-log row as Outbound › Queue needs it: the row's id,
|
||
// for the link to its page, and the recipient, to tell the rows of one
|
||
// message apart.
|
||
type SendLogRef struct {
|
||
ID int64
|
||
To string
|
||
}
|
||
|
||
// sendLogRefsChunk keeps one query's parameters well under SQLite's limit
|
||
// (SQLITE_MAX_VARIABLE_NUMBER, 32766 since 3.32.0, https://sqlite.org/limits.html).
|
||
const sendLogRefsChunk = 500
|
||
|
||
// sendLogRefsQuery reads the rows of n queue ids, through idx_send_log_queue_id
|
||
// (TestSendLogQueriesUseTheirIndexes).
|
||
func sendLogRefsQuery(n int) string {
|
||
marks := strings.TrimSuffix(strings.Repeat("?,", n), ",")
|
||
return `SELECT id, queue_id, COALESCE(to_addr, '') FROM send_log WHERE queue_id IN (` + marks + `) ORDER BY id`
|
||
}
|
||
|
||
// SendLogRefsByQueueID returns the send-log rows of each of the queue ids, in
|
||
// row order: what Outbound › Queue links a waiting recipient to. An id with no
|
||
// row - the panel's own mail, a bounce, a row past the retention - is absent.
|
||
func (s *Store) SendLogRefsByQueueID(queueIDs []string) (map[string][]SendLogRef, error) {
|
||
out := make(map[string][]SendLogRef)
|
||
for start := 0; start < len(queueIDs); start += sendLogRefsChunk {
|
||
chunk := queueIDs[start:min(start+sendLogRefsChunk, len(queueIDs))]
|
||
args := make([]any, len(chunk))
|
||
for i, id := range chunk {
|
||
args[i] = id
|
||
}
|
||
rows, err := s.db.Query(sendLogRefsQuery(len(chunk)), args...)
|
||
if err != nil {
|
||
return nil, fmt.Errorf("send-log rows by queue id: %w", err)
|
||
}
|
||
for rows.Next() {
|
||
var (
|
||
ref SendLogRef
|
||
queueID string
|
||
)
|
||
if err := rows.Scan(&ref.ID, &queueID, &ref.To); err != nil {
|
||
rows.Close()
|
||
return nil, fmt.Errorf("send-log rows by queue id: %w", err)
|
||
}
|
||
out[queueID] = append(out[queueID], ref)
|
||
}
|
||
err = rows.Err()
|
||
rows.Close()
|
||
if err != nil {
|
||
return nil, fmt.Errorf("send-log rows by queue id: %w", err)
|
||
}
|
||
}
|
||
return out, nil
|
||
}
|