Issue 175: an announcement queued behind a long build came back, and the build ran again

2026-09-30 21:38:45 +02:00
parent 598f6a8952
commit 8bd0ca0bdc
1 changed files with 62 additions and 0 deletions
@@ -0,0 +1,62 @@
+---
+status: resolved
+opened: 2026-09-30
+located-in: [mesh-controller internal/broker/streams.go (the controller's EVENTS consumer), mesh-controller internal/link/receive_nats.go]
+fixed-by: mesh-controller PR 173 (MaxAckPending 1 on the controller's events consumer); the packaging module's rebuild record and the status count remain open in the text below
+amended-design:
+---
+
+# 175 — An announcement queued behind a long build comes back, and the build runs again
+
+## What was observed
+
+On the evening of 2026-09-30 five merges landed within minutes. The controller's log then showed the
+same four announcements — two into this repository, one into the catalogue, one into the controller's
+own — arriving again every couple of minutes, and each arrival of the controller's rebuilt the two
+modules that package its source. The builder built `builder` and `route-proxy` five times over for one
+merge, the control node was pushed after each, and every other message the controller handles waited
+behind the builds. It looked like a slow mesh; it was a loop.
+
+Earlier the same evening, at a lower rate, the log already carried duplicated lines — a merge seen
+twice, a module "moved" twice — that nobody read as a symptom.
+
+## Why
+
+The controller acts on what it consumes in **one loop, one message at a time**, and a merge's handler
+builds every module the merge changed before it returns — minutes of work. The bus's acknowledgement
+window is thirty seconds. That contradiction was met once already: the message being worked on is kept
+alive by a heartbeat while its handler runs
+([issue 127](../127-a-shared-delivery-subject-is-not-a-per-consumer-queue/00-report.md)'s stretch,
+controller PR 122). **The heartbeat covers one message.** The consumer is a push consumer with no
+bound on what it may have outstanding, so the client is handed everything that is waiting at once; the
+messages queued behind the one being built time out unacknowledged, come back after thirty seconds,
+and are handled again when the loop gets to them — including the merge whose builds are already done,
+which builds them again. A module that only *packages* another repository's source has no record of
+which commit it was last rebuilt for, so nothing says "already done".
+
+## Why it matters beyond this instance
+
+The design permits work to be done twice, silently, and the doubling scales with how busy the mesh
+is: the busier the builder, the longer the queue, the more that comes back. A push to a machine is
+idempotent and a rebuild produces the same digest, so nothing broke — but every merge cost several
+builds, the control node was pushed after each, and a person watching saw a mesh that would not
+settle. It was the redelivery storm of 2026-09-28 in a narrower form, one layer out.
+
+## What would have prevented it
+
+- **A consumer that is handled one at a time is delivered one at a time.** `MaxAckPending: 1` on the
+  controller's events consumer: the server holds the rest, nothing times out behind a build, and the
+  heartbeat that keeps one message alive is then keeping *the* message alive.
+- **A packaging module records the commit it was last rebuilt for**, so a replayed announcement is
+  "already built from it", the answer the source-built modules already give.
+- **A log line that appears twice with the same commit is a symptom**, and the check is cheap: the
+  same announcement acted on twice within its window is a count worth exposing in `status`.
+
+## Resolved on the first remedy, 2026-09-30
+
+`MaxAckPending: 1` on the controller's events consumer (mesh-controller PR 173): the server hands the
+controller one announcement at a time and holds the rest, so nothing times out behind a build. The
+existing consumer is brought to that configuration by the assertion the controller makes at start.
+The second and third remedies — a packaging module recording the commit it was last rebuilt for, and
+a doubled announcement counted in `status` — are not built; they would make the same fault visible
+and cheaper should the first ever be undone, and they are left here as what to reach for then.