Merge pull request 'Issue 335: a build that passed its gate was failed and put back by the first machine's later reports' (#227) from issues/335-a-passed-gate-was-failed-by-later-reports into main

2026-10-08 19:51:27 +00:00
parent a1c85c6de5 bbbaf943e8
commit 4955a663d3
2 changed files with 118 additions and 0 deletions
@@ -0,0 +1,58 @@
+---
+status: resolved
+opened: 2026-10-08
+located-in: [mesh-controller cmd/mesh-controller (release_plan.go, nextRollout and failFirstSend)]
+fixed-by: mesh-controller#165, mesh-lab#72
+replay: R335
+amended-design:
+---
+
+# 335. A build that passed its gate was failed and put back by the first machine's later reports
+
+## What was observed
+
+On 2026-10-08 a person released a delivery of the catalogue that the group check (issue 316) had held. Its
+walk had one tier with one module, `dunst`, which runs on the laptop and the workstation. The walk sent the
+new build to the laptop first, and the gate passed it there:
+
+> dunst passed its gate on the laptop (healthy 3 times over 2m5s); the rest are sent
+
+Twenty-eight minutes later the same walk said the opposite, about the same gate:
+
+> dunst failed its gate on the laptop in tier 0: healthy 3 times over 2m5s; put back dunst to ea462666 on
+> the laptop, in one send; the workstation left as it was
+
+`plans` showed the gate as `passed` and the module as `failed its gate` on the same line. The controller
+raised `build.dunst.<laptop>.rolled-back` and kept saying it every five minutes. The build was recorded as
+failed at its gate, so nothing sends it again on its own, and the operator's new build (its font size and
+width now settings) reached neither machine.
+
+## Why it is an issue
+
+A gate's pass is a verdict (ADR 0236): the first machine is judged once, and then the rest are sent. Here a
+verdict was overturned by something that happened after it, with the pass's own words given as the
+reason for a failure. That is a failure that says nothing true about why it happened. It also put back a
+build that worked, recorded it as failed, and so blocked its delivery until a newer merge.
+
+## Fix
+
+The controller judged the first machine's report again on every step of the walk, also after the gate had
+passed (see `01-diagnosis.md`). The fix merged in mesh-controller pull request 165 (8170fc5), with its
+replay in mesh-lab pull request 72.
+
+- Once a module's gate has passed, the first machine's later reports no longer decide anything about it:
+  the walk sends the rest.
+- A module carried by another module's send takes over that pass before its step is read.
+- A guard, not reached with the two changes above: should a later path still stop a walk at a module whose
+  gate passed, that module is not put back and its build is not marked failed. The walk stops with the
+  reason, and the module is left sent to its first node only, which `plans retry` takes up again.
+
+## How it is checked
+
+`TestReplay335` in the controller replays the live case with only what the controller had before the fix:
+a passed gate on the laptop, the laptop's later report not about this build (or a failure of another
+send), and the walk 30 minutes and 9 seconds after the first send. A second test drives the walk over a
+tier of two modules, the second carried by the first's send, and fails if the carried module's step is read
+before it takes over the pass. On the commit before the fix it fails
+with "laptop did not report it applied within 30m0s", and the passed build reaches the put-back. It is R335
+in mesh-lab's replays register, proved to fail before the fix and pass on it.
@@ -0,0 +1,60 @@
+# 335. Diagnosis
+
+## 2026-10-08
+
+**The record.** A search of the records for "failed its gate", "rolled-back" and "gate passed rolled back"
+found ADR 0236 (what a rollback is), issue 318 (a wait for a login failing a gate) and issue 279, none of
+them about a gate that passed and was then failed.
+
+**The walk's own lines.** The controller's journal on the control-node said, for this walk (times UTC):
+
+| time | what the controller said |
+|---|---|
+| 16:44:45 | tier 0 built; sent dunst to the laptop first, the rest once its gate passes |
+| 16:44:55 | the laptop applied what it was sent |
+| 16:46:52 | dunst passed its gate on the laptop (healthy 3 times over 2m5s); the rest are sent |
+| 16:46:53 | sending dunst to the workstation refused: a build of `build-agent` waits there for its gate, which another walk sends |
+| 16:49:12 | the other walk (the controller's own merge, tier 1) sent `build-agent` to the control-node, the laptop and the workstation |
+| 17:14:54 | dunst failed its gate on the laptop: healthy 3 times over 2m5s; put back on the laptop; the workstation left as it was |
+
+The laptop's node-engine logged `applied` at 16:44:55 and nothing more until 18:01:58. It did not report
+on the 16:49:12 send for over an hour. Why it did not is not yet known; the laptop did not sleep until
+18:01. That is a separate question, and this issue does not depend on its answer.
+
+**The arithmetic.** 17:14:54 is 30 minutes and 9 seconds after the first send at 16:44:45. The controller
+waits 30 minutes (`planWaitBound`) for a first machine to report what it was sent. The failure came at that
+bound and not at the gate's.
+
+**The code path.** In `advanceOnce` (`release_plan.go`), every step of a walk reads
+`nextRollout(state, …)` before anything else, for every module in the tier not yet sent to the rest. For a
+module sent first, `nextRollout` looks at the first machine's last report. If that report is not about the
+declaration the machine was last sent (`Current` false), it waits; past the bound it answers
+`failed: <machine> did not report it applied within 30m0s`. Nothing in it looked at the gate's verdict.
+
+After the pass at 16:46:52, the send to the rest was refused (the error returns, and the walk tries again on
+the next step). At 16:49:12 the other walk's send made the laptop's last report no longer current. From
+then on `nextRollout` waited for a report it would never get about this build. At the bound it failed, and
+`advanceOnce` called `failFirstSend`.
+
+`failFirstSend` chooses between putting the module back or keeping it by the gate's `Failing` list. A passed
+gate has an empty `Failing`, and the condition `len(g.Failing) == 0` sent it to `gateFailed`. `gateFailed`
+does not overwrite a verdict already written, so it kept the pass's why ("healthy 3 times over 2m5s") as the
+failure's reason. It then recorded the build as failed, restored the previous build and sent it to the
+laptop. That is the line seen at 17:14:54.
+
+**Ruled out.**
+- The gate itself (`judgeMoves`) decided `passed` and nothing changed that verdict.
+- The person-wait of issue 318 (ADR 0254), `putBackBroken` and the carried-module paths: the plan had one
+  module, nothing was carried, and nothing was found broken.
+- Sleep: the laptop did not sleep until 18:01, and the failure was at 17:14:54.
+- The release itself (`mesh-delivery.release`): it let the walk go at 16:44, and the walk ran as any other.
+
+**Located.** mesh-controller, `cmd/mesh-controller/release_plan.go`: `nextRollout` judged a passed gate's
+first machine again, and `failFirstSend` put back a module whose gate had passed. The path has been there
+since the gate was added (ADR 0236). It shows only when the send to the rest does not happen on the same
+step as the pass and another send reaches the first machine before the 30-minute bound.
+
+**What it needs to deliver dunst.** The build is recorded as failed at its gate, and the controller does
+not send a build marked that way again on its own. The registered build is back at the one before. Once the
+fix is delivered, a new build of dunst (`rebuild dunst`, or a newer merge of it) is judged at the gate
+again and walked to both machines.