diff --git a/04-ISSUES/266-a-merge-on-the-bus-was-never-handed-to-the-controller/00-report.md b/04-ISSUES/266-a-merge-on-the-bus-was-never-handed-to-the-controller/00-report.md new file mode 100644 index 0000000..c15b8b2 --- /dev/null +++ b/04-ISSUES/266-a-merge-on-the-bus-was-never-handed-to-the-controller/00-report.md @@ -0,0 +1,104 @@ +--- +status: located +opened: 2026-10-06 +located-in: [mesh-catalog, mesh-controller] +fixed-by: +amended-design: +--- + +# 266. A merge on the bus was never handed to the controller + +## Symptom + +A pull request was merged into the tools repository, which the runtime and the console are built +from. Nothing was built. The runtime was then built by hand. + +The forge's poll said in its journal that it announced the merge, 19 seconds after it was made. The +controller's journal has no line for it: no plan, and no "nothing the mesh holds reads it". The +controller did log the merges just before and just after it, to other repositories, as it always +does. It had restarted three minutes earlier, when a new controller was rolled out. + +## Evidence + +- **The announcement is on the bus.** The events stream holds it, on the merge subject, with the + merge commit and the files it changed. +- **The controller's consumer is past it and holds nothing.** The controller's durable consumer on + the events stream has nothing pending and nothing unacknowledged. Its delivered and acknowledged + positions are past the announcement. +- **It was never handed over.** Since the controller connected, the stream took 25 messages on the + consumer's subjects. The server's own count for the controller's subscription is 24 deliveries. + The consumer hands over one message at a time, and the next message, a build outcome, was handed + over and acted on 20 seconds after the merge. So the merge was not handed over and then lost by + the controller. No other subscriber to the consumer's delivery subject existed, then or since. +- **Every way the controller could take it logs.** Acting on a merge, or refusing one, writes a line + in every case. An announcement the controller could not read, or one it did not recognise, would + be taken without a line, but this one has the subject and the body the controller expects. A + merge announced into another repository 8 minutes later was acted on and logged. +- **It is not the first.** Across three days, 23 merges the poll announced have no matching line in + the controller's journal. Most of them fall in windows when the bus or the controller was being + replaced. This one does not. + +## Cause + +The bus server ran **nats 2.10.29**. On that release, a JetStream consumer with **more than one +filter subject** sometimes moves its position past a matching message without delivering it. It +does not count the message as pending, and it does not redeliver it. The controller's consumer has +seven filters: merges, build outcomes, catalogue upgrades, a catalogue's catch-up, and the two +provider standings. The controller acts only on what that consumer hands it. Nothing compares what +was announced with what was acted on, so a skipped merge is silent. + +Reproduced outside the mesh with the server library. A stream shaped like the events stream, with +a consumer configured exactly like the controller's, receives traffic like the mesh's: mostly build +logs on new subjects, with the followed events among them. + +- On 2.10.29, a few percent of the followed events are never delivered, and the consumer has + nothing pending. +- On the same release, a consumer with a single filter received every message. +- On 2.11.17, 2.12.15 and 2.14.5, every message was delivered. + +Every module consumer with more than one filter on that bus is exposed in the same way. That +includes the catalogue's consumer of build outcomes and every provider's consumer of provisioned and +deprovisioned events. + +## Fix + +1. **mesh-catalog: the bus server runs 2.11.17.** The nats module's image is pinned by its + multi-architecture index digest. The Dockerfile now also states the release that digest is, + because a digest does not state it. 2.11.17 is the smallest step that delivers every message in + the reproduction. Moving to 2.11 is a one-way upgrade of the stream store, so plan it for when the + bus can be restarted. +2. **mesh-controller: missed merges are caught up.** Every five minutes the controller reads the + last day of merge announcements back from the events stream. It reads them on an ordered consumer + of its own, filtered on the merge subject alone, which acknowledges nothing. For each announcement + older than ten minutes, it judges the merge the way acting on it would. A merge that was already + acted on reads as history, because acting marks every module the merge moved as looked at since. + A merge that would still move a module was never acted on. The controller says so, naming the + repository, the commit, how late it is and which modules are behind, and then acts on it. So no + record of which merges were handled is needed. + + It only considers modules built from the merged repository. Modules that only package source + from that repository have no record that acting touched them, so they would always read as never + acted on. A merge that moves both kinds is caught through the first kind, and acting on it also + rebuilds the second. A merge older than a day is left to a person, because rebuilding it days + later would be a surprise. + +## How it is checked + +- mesh-catalog, `modules/nats/cmd/nats-tools`. + `TestAConsumerWithSeveralFiltersIsHandedEveryMessage` runs the reproduction above against the + server release the module's tests pin. It fails on 2.10.29 and passes on 2.11.17. + `TestTheImageIsTheServerTestedHere` fails if the release named in the Dockerfile differs from the + tested server's version. The first test is therefore a statement about the server the mesh runs. +- mesh-controller, `cmd/mesh-controller`. + `TestAMergeTheBusNeverHandedOverIsActedOnLate` replays this incident: an announcement the + controller never acted on, among others that were acted on or that nothing reads. It is left to + the controller's own consumer for ten minutes. Then it is said and acted on once, and never + again. `TestAMissedMergeThatCouldNotBeActedOnIsTriedAgain` and + `TestAMergeOlderThanTheLookBackIsLeftAlone` check the edges. Reading the stream back was also + checked against an embedded 2.10.29 server holding exactly the controller's bus permissions. + +## Not covered + +If the forge's poll never announces a merge at all, the catch-up has nothing to read. The poll keeps +its own record of what it announced, so a restart of the poll does not lose merges. A poll that is +down for longer than a day would still lose them.