143 lines
15 KiB
Markdown
143 lines
15 KiB
Markdown
# Review A — correctness and runtime behaviour
|
||
|
||
- Date: 2026-10-13/14 (interrupted by an API usage limit, resumed)
|
||
- Scope: the whole repository at the state of the first implementation; read-only
|
||
- Lens: counting rules vs plan/Lua, Redis store, UTC day, concurrency and lifecycle, resource use, error paths
|
||
- Proof tests: `_proof_tests/a/` (see `_proof_tests/README.md`)
|
||
- Verification by the coordinating agent and the merged ranking: `README.md`
|
||
|
||
The report below is the reviewer's text as delivered. Paths under `/tmp/review_a` refer to its scratch copy, which no longer exists.
|
||
|
||
---
|
||
|
||
Findings, most severe first. The repo was not modified. All scratch work is in /tmp/review_a: test files `internal/server/review_test.go`, `internal/store/review_test.go`, `internal/counting/review_test.go`, `internal/txlog/review_bench_test.go`, and a daemon build in `run/`. I started Redis on port 16401 and have killed it, along with any daemon processes I started.
|
||
|
||
---
|
||
|
||
**F1 — high — correctness/lifecycle: a client disconnect cancels the Redis write**
|
||
- location: `internal/server/server.go:156` (`s.d.Counter.Execute(r.Context(), plan)`)
|
||
- summary: Counting uses the request context. When mailqueuer closes the connection or its client times out before the reply, Go cancels that context and go-redis aborts before sending the MULTI (pool `waitTurn`, dial and retry backoff all check `ctx.Done()`). The increment is lost.
|
||
- failure scenario: A fire-and-forget client writes POST /in and closes the socket, or uses a short timeout while Redis or Sentinel is slow. The handler then logs "redis error: context canceled (nothing counted)" and the counter is never incremented. Because mailqueuer never retries, the loss is silent and permanent.
|
||
- evidence: `TestReview_ClientDisconnectNoDelay` sends 300 raw POST /in requests that close right after writing; the counter ends at "21", so 93% were lost. `TestReview_ClientDisconnectLosesCount`, with 50 ms of latency before Redis, loses 20 of 20. The txlog shows `redis error: redis incr: context canceled (nothing counted)`.
|
||
- verdict: CONFIRMED. How often it bites depends on how the not-yet-written mailqueuer client behaves.
|
||
- fix: `ctx, cancel := context.WithTimeout(context.WithoutCancel(r.Context()), budget)` for `Execute`, so the work does not depend on the caller staying connected.
|
||
|
||
**F2 — medium — counting rules / contract: master/token logins on /out get a 400, so nothing is counted**
|
||
- location: `internal/api/validate.go:29,84` (`requiredEmail("auth_user")`, exactly one `@`)
|
||
- summary: mizu puts the raw SASL login in X-Auth-User (`mizu/pkg/smtp/server.go:2065` passes `s.authenticatedUser`). For master/token logins (Sora support access, remotelookup tokens) that login is `user@dom@SUFFIX`, which NormalizeEmail rejects.
|
||
- failure scenario: `{"auth_user":"x@yagolivas.com@SUPPORTTOKEN","recipient":"y@yagolivas.com"}` returns 400 `auth_user: invalid e-mail address`. Neither the sender's outgoing A/D/O nor the hosted recipient's incoming A/D/O is counted. The counting log has no line for it, and the warn log omits trace_id, which the plan requires.
|
||
- evidence: `TestReview_MasterLoginAndOddSenders` prints `-> 400`, and the Redis keys are `[]`. mizu `CLAUDE.md:471-501` documents the `user@domain@SUFFIX` logins.
|
||
- verdict: CONFIRMED (rejection). How frequent these logins are is PLAUSIBLE, not measured.
|
||
- fix: Normalise auth_user by stripping a second `@SUFFIX` and counting the base address (`local@domain`). Log rejections to the counting log with the trace_id.
|
||
|
||
**F3 — medium — counting rules: a `mail_from` the sender controls can suppress counting of the recipient**
|
||
- location: `internal/api/validate.go:35,49` (`optionalEmail("mail_from")` fails the whole request)
|
||
- summary: mail_from is used only for the exempt check, yet a syntactically "invalid" envelope sender returns 400 for the whole request. go-smtp (the migadu fork used by mizu, `parse.go:173-238`) accepts these senders: it unquotes quoted local parts (`"a b"@x` becomes `a b@x`, `"a@b"@x` becomes `a@b@x`), and it accepts address literals, UTF-8 domains and trailing dots. mailqueuer passes X-Mail-From through unchanged.
|
||
- failure scenario: Inbound spam with `MAIL FROM:<"a b"@spammer.example>` (or `<u@[192.0.2.1]>`, `<u@münchen.de>`, `<u@example.com.>`) gets a 400 on /in, so the hosted recipient's incoming limits are never counted. The same applies to /out for allowed_from regex or wildcard senders.
|
||
- evidence: the same test: all five /in variants return 400 `mail_from: invalid e-mail address`, and no keys are written.
|
||
- verdict: CONFIRMED (rejection). That mizu accepts such senders end-to-end is PLAUSIBLE (shown in the parser only).
|
||
- fix: Treat an unparseable mail_from as unknown: log it, don't match it against the exempt list, and count anyway. Validate strictly only the fields that are counted.
|
||
|
||
**F4 — medium — Redis store: ambiguous Redis failures are logged as "nothing counted" and the crossing notification is lost**
|
||
- location: `internal/store/store.go:128-137`, `internal/server/server.go:156-166`, `internal/txlog/txlog.go:111`
|
||
- summary: `TxPipelined` returns an error in two cases where the increments may already be committed:
|
||
- (a) A read timeout after MULTI/EXEC was written. go-redis does not retry (`txPipelineProcessCmds` returns canRetry=false), but Redis executes the transaction.
|
||
- (b) A per-command error inside EXEC (non-integer or WRONGTYPE key). The other INCRBYs are applied.
|
||
|
||
In both cases the service answers 503, logs "nothing counted" and skips crossing detection. The one increment that crossed is consumed, so that level/id/flow is not notified again that day.
|
||
- failure scenario:
|
||
- (a) A/o=99 with limit 100 and the master stalls for more than `timeout_ms` (500 ms). Redis applies 100, the service returns 503, and no notification is sent.
|
||
- (b) The O key holds "garbage" and A/o=19 with limit 20. A becomes 20 and D becomes 1, but the response is 503 "nothing counted" and 0 notifications are sent.
|
||
- evidence: `TestReview_TimeoutAfterWriteStillCounts` against real Redis 8.6 with `DEBUG SLEEP 1`: `Incr error: ... i/o timeout`, then `key after the 'failed' Incr: 100`. `TestReview_PartialExecFailure` (miniredis): `status 503 ... ERR value is not an integer`, `A/o=20 (limit 20 crossed) D/o=1`, `address notifications sent: 0`.
|
||
- verdict: CONFIRMED
|
||
- fix:
|
||
- Use the per-command results: go-redis sets each cmd's error, so commands that succeeded can still be evaluated for crossing.
|
||
- On a timeout after the write, re-read the keys from the master and run crossing detection on any key now at or above its limit. Alternatively, raise the read timeout for EXEC.
|
||
- Log "outcome unknown" instead of "nothing counted".
|
||
|
||
**F5 — medium — resource use: huge CDB values are re-parsed (and their keys sorted) on every request**
|
||
- location: `internal/domains/domains.go:154-167` (`ParseRecord` per lookup), `internal/txlog/txlog.go:215-229` (`summarize` sorts every key per request)
|
||
- summary: boxmailhere.com (193 KB, 9,798 overrides) is read, split into a map of about 9.8k entries, then key-sorted for every /in or /out request that touches it.
|
||
- failure scenario: Sustained inbound mail to boxmailhere.com costs about 2.6 ms of CPU and 1.6 MB of garbage per request on an M2, so 100 req/s comes to roughly 160 MB/s of allocations and a quarter of a core. An /out between two such domains doubles it.
|
||
- evidence: `go test ./internal/txlog -bench Review` gives:
|
||
|
||
| benchmark | time/op | memory/op | allocs/op |
|
||
|---|---|---|---|
|
||
| LookupSmall | 1.6 µs | 544 B | 9 |
|
||
| LookupHuge | 908 µs | 1.43 MB | 88 |
|
||
| InRequestHuge (plan + txlog) | 2.64 ms | 1.60 MB | 266 |
|
||
| Open (count iteration) | 85 ms | – | – |
|
||
- verdict: CONFIRMED
|
||
- fix: Cache parsed records per DB generation, dropping the cache on swap. Or resolve limits lazily: extract only `O/,D/,A/` and `<local>@/<flow>` from the raw value. Pre-sort the base keys once.
|
||
|
||
**F6 — low — counting rules / spec deviation: a malformed CDB row fails the whole request instead of being skipped**
|
||
- location: `internal/domains/domains.go:116-123`, `internal/counting/counting.go:172-179`
|
||
- summary: The README and plan say "Malformed CDB rows are skipped, not fatal" (the Lua plugin and stats-merger both treat them as not hosted). Here a bad org id surfaces as a lookup error and the request is answered 503.
|
||
- failure scenario: A recipient row `|A/i=5` (empty org id), with sender x@good.example. PlanOut returns an error, the server answers 503 "domain lookup failed", and the valid sender's outgoing counters are not counted either. Every request touching that domain fails.
|
||
- evidence: `TestReview_MalformedRowFailsWholeRequest`: `plan=<nil> err=lookup recipient domain bad.example: domain bad.example: invalid org id ""`.
|
||
- verdict: CONFIRMED. There are no malformed rows in the current fixture.
|
||
- fix: In `Lookup`, map a ParseRecord error to ErrNotFound (or a distinct "malformed, not counted" result) plus a warning, and continue with the other party.
|
||
|
||
**F7 — low — spec deviation: override keys are not lowercased**
|
||
- location: `internal/domains/domains.go:54,74`
|
||
- summary: The plan says parsing follows stats-merger, where keys are lowercased (stats-merger `quota.go:103,118`). The code only trims keys, while the local part is lowercased by `normalize`.
|
||
- failure scenario: A CDB value with `Info@/o=5` and mail to or from `info@domain` gets A/o (for example 100) instead of 5. The per-mailbox limit is silently ignored.
|
||
- evidence: code trace. ParseLimits stores `k` as given, and Limit looks up `localPart+"@/"+flow` with a lowercased localPart. The fixture has 0 mixed-case overrides out of 22,995.
|
||
- verdict: CONFIRMED (code path). Impact with today's data is nil.
|
||
- fix: `strings.ToLower(strings.TrimSpace(k))` in ParseLimits.
|
||
|
||
**F8 — low — lifecycle: SIGHUP during startup kills the daemon**
|
||
- location: `cmd/migadu_counters/main.go:76-101` (`signal.Notify` runs only after newApp, the up-to-2 s Redis ping, Listen and Serve)
|
||
- summary: Go's default action for SIGHUP is to exit, so a reload or newsyslog HUP during startup terminates the process.
|
||
- failure scenario: The daemon starts while Redis is slow or unreachable (the ping can take up to 2 s), and `service reload` or newsyslog sends HUP. The process exits with status 129, and requests already being served are dropped.
|
||
- evidence: Redis on 16401 was held with `DEBUG SLEEP 3`, the daemon started, and HUP was sent after 0.3 s: `daemon exited with status 129`. The app log stops after "domains db loaded".
|
||
- verdict: CONFIRMED
|
||
- fix: Call `signal.Notify` (or `signal.Ignore(SIGHUP)`) first thing in `run`, before newApp.
|
||
|
||
**F9 — low — notifications: in-memory notifications are dropped on restart or short outages; log is misleading**
|
||
- location: `internal/notify/notify.go:148-185,217-223`
|
||
- summary:
|
||
- `Shutdown` closes `quit`, which aborts every pending retry immediately instead of using the 30 s drain.
|
||
- Retries hold a semaphore slot during backoff (1+2+4+8 s), so at most 8 events are delivered every 15 s or more while the web app fails.
|
||
- The total retry window is about 15 s plus attempt timeouts.
|
||
- When a retry is cut off by shutdown, the Failed hook still reports "after 5 attempts".
|
||
- failure scenario: A web app deploy lasting about 30 s, or a migadu_counters restart, while limits are crossed. Those crossings never notify, because the counter has already passed the limit and only a reset re-arms it.
|
||
- evidence: code trace. `case <-n.quit: ... attempt = n.cfg.Attempts`, then `Failed(ev, u, n.cfg.Attempts, ...)`.
|
||
- verdict: PLAUSIBLE
|
||
- fix: Let the shutdown deadline, not `quit`, bound retries. Release the semaphore while sleeping. Report the real attempt count. Consider a persistent or replayable record of reached-but-undelivered events, for example a Redis list.
|
||
|
||
**F10 — low — TimeoutHandler/shutdown interplay: lingering handlers misreport**
|
||
- location: `internal/server/server.go:95,181-183`, `cmd/migadu_counters/main.go:322-332`
|
||
- summary:
|
||
- After `http.TimeoutHandler` sends its 503, the handler goroutine keeps running, so the request is usually counted and notified despite the 503.
|
||
- These goroutines are not tracked by `http.Server.Shutdown`. If one finishes after `notifier.Shutdown`, its crossing is dropped and logged as "no address_url configured, not notifying", with `notifications_total{result="disabled"}`.
|
||
- A panic after the timeout is swallowed with no log, because TimeoutHandler's recover sends it into a channel nobody reads.
|
||
- verdict: PLAUSIBLE (code trace)
|
||
- fix: Give `Execute` its own context and budget (see F1). Track in-flight executions with a WaitGroup that Shutdown waits on before stopping the notifier. Distinguish "notifier closed" from "disabled".
|
||
|
||
---
|
||
|
||
**Checked, no issue found**
|
||
- **A/D/O planning:** /out counts sender A/D/O outgoing on auth_user's row and hosted recipient A/D/O incoming on the recipient's row. /in counts the recipient only. No duplicate keys in one MULTI, including self-sends and same-org cases.
|
||
- **Exempt and junk:** auth_user, mail_from and recipient (lowercased) are checked per the plan. Junk is skipped unless `count_junk`. Unknown domains are skipped. The behaviour changes against Lua are the ones the plan documents.
|
||
- **`<local>@/<flow>` override:** the override wins over `A/<flow>`. A duplicate key resolves last-wins, as in Lua. Empty or non-numeric values are skipped.
|
||
- **Limit 0 and negative limits:** limit 0 never crosses. This matches the web app, which strips `=0` overrides as "unlimited" (`config.ex` cdb_domain_limits). There are no zero or negative limits in the fixture.
|
||
- **Crossing detection:** old < limit ≤ new on atomic INCRBY, exactly once under concurrency. After the web app's DEL it re-fires, and the web app's own once-per-day guard (`limit_exceeded_at`) suppresses the duplicate email.
|
||
- **Key format:** matches `redis_sentinel.ex` (`cnt/<L>/<id>/d/YYYY-MM-DD/<i|o>`, DB 0, lowercased ids). TTL is refreshed in the same MULTI.
|
||
- **UTC day:** the date is computed once per plan, so all keys in a request share the same day. `/counters`, counterctl and the txlog all use UTC.
|
||
- **go-redis behaviour:**
|
||
- TxPipeline is not retried after the write, so there is no double counting.
|
||
- READONLY, OOM or NOREPLICAS during queueing turn into EXECABORT, which is all-or-nothing.
|
||
- ReplicaOnly falls back to the master. Sentinel address slices are copied.
|
||
- MGET parsing treats nil as 0.
|
||
- **MULTI per-command error semantics:** handled as reported in F4, nothing beyond that.
|
||
- **CDB swap:** the parsed Domain is a copy. Lookups happen right after `Load`, so the 30 s grace is enough. Reloads are serialised by reloadMu.
|
||
- **fsnotify on kqueue:** a rename-over produces Remove followed by Create, so the reload fires. The `.tmp` file is ignored.
|
||
- **File handles on reload:** a failed `cdb.Open` leaks the *os.File only until the GC finalizer closes it. Open with its count iteration takes about 85 ms.
|
||
- **Watcher shutdown:** Stop and debounce races are harmless; a late reload only affects a process that is already exiting.
|
||
- **Logging:** LogWriter Reopen and Write are mutex-safe. A SIGHUP during shutdown is ignored. The fatal channel is buffered for both servers.
|
||
- **Notifier:** wg.Add happens under the closed-check lock, so there is no Add-after-Wait race. URL escaping and `$LEVEL`/`$LIMIT` replacement order are correct, and all six web-app params are present in the example config.
|
||
- **Panics:** a panic before the timeout is recovered with a 500. Indexing in `/counters` and the address split is guarded by validation.
|
||
- **Plus-addressing:** counted as a separate address, same as Lua.
|
||
- **Tooling:** `go vet ./...` is clean, and all existing tests pass in the scratch copy.
|