Merge pull request 'Issue 175: an announcement queued behind a long build came back, and the build ran again' (#234) from fix/one-announcement-at-a-time into main
This commit was merged in pull request #234.
This commit is contained in:
@@ -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.
|
||||||
Reference in New Issue
Block a user