diff --git a/04-ISSUES/296-a-plans-clock-restarted-at-every-save/00-report.md b/04-ISSUES/296-a-plans-clock-restarted-at-every-save/00-report.md new file mode 100644 index 00000000..d3235741 --- /dev/null +++ b/04-ISSUES/296-a-plans-clock-restarted-at-every-save/00-report.md @@ -0,0 +1,43 @@ +--- +status: located +opened: 2026-10-07 +located-in: [mesh-controller cmd/mesh-controller (release_plan.go, watchdogs.go, status.go)] +fixed-by: mesh-controller PR #119 +amended-design: +--- + +# 296. A plan's clock restarted at every save + +## Symptom + +On 2026-10-07 the controller's `plans` verb showed one plan for a merge to the catalogue repository +(commit `3ad22356`) as "tier 1 of 1, building for 1s". Read again over the next several minutes, it +said "building for 4s", then "building for 9s". The build had been requested at 19:48:41 and sat queued +for minutes. The line said it had only just started. + +The same clock decides whether the line ends in " โ€” LATE", and whether `status` counts the plan as +waiting past its bound. A plan whose clock goes back to zero every few seconds is never late. So +`plans` and `status` could not say that a plan was stuck. The design says a stuck plan is a warning +(to-be 45, S3). + +## Where it lives + +In the controller. The line counted from the plan's last save, not from when the plan entered its tier. +The plan was saved after every step the controller took on it, whether or not the step changed +anything. Those steps run on a 30-second timer and again after every build outcome anywhere on the +mesh. The trail is in [01-diagnosis.md](01-diagnosis.md). + +## How it is checked + +Two tests in the controller, each shown to fail on the commit before the fix: + +- A plan saved three seconds ago that has been in its tier for forty minutes reads "building for 40m0s" + and LATE. LATE and the stalled condition agree on both sides of a measured bound. +- Against a real store, advancing a plan whose build is outstanding three times leaves its revision and + its last-save time where its last real change left them. Before the fix, its revision went from 3 to 6. + +Live: during a plan whose tier waits on a queued build, `plans` counts up from when the tier was entered, +and the plan's revision does not move until something about it does. + +At resolution this core issue names its replay, or says in `replay-none:` why none is possible +(ADR 0237). diff --git a/04-ISSUES/296-a-plans-clock-restarted-at-every-save/01-diagnosis.md b/04-ISSUES/296-a-plans-clock-restarted-at-every-save/01-diagnosis.md new file mode 100644 index 00000000..a70a6dc6 --- /dev/null +++ b/04-ISSUES/296-a-plans-clock-restarted-at-every-save/01-diagnosis.md @@ -0,0 +1,56 @@ +# 296 โ€” diagnosis + +## 2026-10-07: the line's clock + +The `plans` line for an open plan counted from the plan's `updated` column. The store sets that column +to the current time on every save. The same save also increments the plan's revision, which is used for +compare-and-set (to-be 45 ยง6). The " โ€” LATE" marker compared this count against a fixed 30-minute bound. +The JSON from `status` did the same, and so did the count of late plans. + +The watchdog that raises a plan's `stalled` condition (S3) counts differently. It starts from when the +plan entered its current tier, a time the save stamps only when the tier changes. Its bound comes from +the tier durations measured for the repository: three times their ninetieth percentile, and never less +than 30 minutes. So the watchdog and the line a person reads used different start times and could use +different bounds. The line was the one that was wrong. + +The line for a walk waiting on its delivery's word had the same flaw. It said "for" the time since the +last save. The watchdog for that wait (S16) counts from when the walk was opened. + +Ruled out: a clock difference between the machine running the verb and the store. The count was small +and kept growing again from zero, which only a column being rewritten explains. + +## 2026-10-07: why a plan standing still was saved every few seconds + +The controller moves plans forward in one loop. That loop runs on startup, every 30 seconds, and after +every build outcome on the mesh, from any plan or none. For each open plan it takes one step and then +saves the plan. It saved even when the step reported that nothing had moved. When a step failed, it +rewrote the same "tried again" note and saved that too. + +A plan whose only module was asked and still queued at the build seat changes nothing on such a step. +The step reads the build records, finds no outcome, and returns. The save came anyway: a new `updated` +time, a new revision, and a `plan-moved` event on the bus (ADR 0239) about a plan that had not moved. On +a busy mesh, with outcomes arriving for other repositories' builds as well as the 30-second timer, that +meant a save every few seconds. + +The same loop has a second form of this. A plan can have a step refused, for example because builds on +a machine are waiting for their own gate. When that happens, the loop logged the refusal and saved the +plan with the same "tried again" note on every tick. The controller's log showed one line, word for word +the same, every 30 seconds for each such plan. + +The write was not needed. Nothing reads `updated` as a heartbeat, and the save is not what keeps a plan +alive. The tier stamp, the revision check and the build records do not depend on a save that changes +nothing. + +## Fix (mesh-controller) + +- The line, the `since` and `late` fields of `status --json`, and the count of late plans all start from + when the plan entered its tier. If the delivery let the walk go after that, they start from the go. A + walk still waiting for its delivery's word counts from when it was opened, as S16 does, and is never + called late. A plan read without the tier stamp falls back to its last save. +- LATE uses the bound the watchdog uses: the measured bound for the plan's repository, or the 30-minute + floor when nothing has been measured. The watchdog's start time and bound now come from the same two + functions, so the line and the condition cannot disagree about a plan. +- The loop compares the plan before and after each step and saves only when they differ. The fields the + store stamps itself are left out of that comparison. +- A refused step is logged and saved only when its note is new. The refusal's wording called the gated + walk a "release plan", a name the glossary retires; it now says "walk".