From c64a7b3d4a4784a96a91f5800f62e54dd149b848 Mon Sep 17 00:00:00 2001 From: jochen Date: Thu, 8 Oct 2026 16:27:34 +0200 Subject: [PATCH] Issues 326-330: register research 036's live bus faults, each diagnosed The bus's own numbers were unexplained and raised by nothing. Measured again read-only: mesh-delivery rewrites unchanged deliveries (326), every controller verb dials its own connection (327), API errors have no reader (328), event consumers outlive their declaration (329), and design 25's dead-letter stream was never built (330). The two slow consumers join issue 270, whose missing system account they share. --- .../036-everything-over-nats/00-overview.md | 11 +++ .../00-report.md | 21 ++++++ .../00-report.md | 65 +++++++++++++++++ .../01-diagnosis.md | 43 +++++++++++ .../00-report.md | 71 ++++++++++++++++++ .../01-diagnosis.md | 44 ++++++++++++ .../00-report.md | 61 ++++++++++++++++ .../01-diagnosis.md | 24 +++++++ .../00-report.md | 72 +++++++++++++++++++ .../01-diagnosis.md | 30 ++++++++ .../00-report.md | 67 +++++++++++++++++ .../01-diagnosis.md | 29 ++++++++ 12 files changed, 538 insertions(+) create mode 100644 04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/00-report.md create mode 100644 04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/01-diagnosis.md create mode 100644 04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/00-report.md create mode 100644 04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/01-diagnosis.md create mode 100644 04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/00-report.md create mode 100644 04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/01-diagnosis.md create mode 100644 04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/00-report.md create mode 100644 04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/01-diagnosis.md create mode 100644 04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/00-report.md create mode 100644 04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/01-diagnosis.md diff --git a/01-RESEARCH/036-everything-over-nats/00-overview.md b/01-RESEARCH/036-everything-over-nats/00-overview.md index 48d1cf8a..9dc49873 100644 --- a/01-RESEARCH/036-everything-over-nats/00-overview.md +++ b/01-RESEARCH/036-everything-over-nats/00-overview.md @@ -88,6 +88,17 @@ the three principles: - 4 688 JetStream API errors; - 4 407 connections in 39 hours, against 16 open; - about 40 writes a second to a delivery bucket of 998 keys. + + *2026-10-08:* measured again and registered as issues + [326](../../04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/00-report.md) (the + delivery bucket's writes), + [327](../../04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/00-report.md) + (the connections), [328](../../04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/00-report.md) + (the API errors), [329](../../04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/00-report.md) + (the stale consumers) and [330](../../04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/00-report.md) + (the dead-letter stream). The slow consumers are recorded under + [issue 270](../../04-ISSUES/270-phase-1-watches-signals-that-come-later-and-hears-only-the-controllers-faults/00-report.md), + whose open question 2 they share. 7. **Smaller gaps:** - Modules' own databases are invisible to views (G6). - Buckets keep one value and events last a week, so history is short (G8). diff --git a/04-ISSUES/270-phase-1-watches-signals-that-come-later-and-hears-only-the-controllers-faults/00-report.md b/04-ISSUES/270-phase-1-watches-signals-that-come-later-and-hears-only-the-controllers-faults/00-report.md index 17841688..715083a0 100644 --- a/04-ISSUES/270-phase-1-watches-signals-that-come-later-and-hears-only-the-controllers-faults/00-report.md +++ b/04-ISSUES/270-phase-1-watches-signals-that-come-later-and-hears-only-the-controllers-faults/00-report.md @@ -81,3 +81,24 @@ own connection only, until the bus has a system account or the controller reads endpoint. Re-checked 2026-10-08: open question 2 still holds — the controller on main subscribes to the bus advisories of its own connection only (`internal/link/advisories.go`: the server publishes the rest only to a system account, which the bus does not have). + +## The two slow consumers of research 036, 2026-10-08 + +[Research 036](../../01-RESEARCH/036-everything-over-nats/01-evidence.md) (gap G7) counted 2 slow +consumers on the bus server since it started (2026-10-06 22:24 UTC), raised by nothing. They are open +question 2 in practice, so they are recorded here rather than as a new issue: the cause they share is that +only a system account, or a reader of the monitoring endpoint, hears another user's slow consumer. + +- The server's log names both: 2026-10-07 12:15:48 and 14:21:04 UTC, each a client on the laptop, "Slow + Consumer Detected: WriteDeadline of 10s exceeded", with 272 KB and 334 KB waiting to be written. The + server closes such a connection. +- The log gives the client's address and connection id, not its user. Nothing keeps closed connections, + so whose connections they were is not known. *I think* the laptop's link stalled for more than ten + seconds (it sleeps and travels behind a VPN client) while a large answer was on its way to it. +- Neither raised a condition. S9 did raise one slow consumer that day, `bus.controller.slow-consumer`, + from 11:02 to 12:02 UTC: a different event, the controller's own client library dropping + `mesh.control.*.tools-alive` heartbeats it could not read fast enough. + +The server's counter (`nats.nats_server`, `slow_consumers`) and its log are the only record. Answering +open question 2 is what makes these heard; issue 327's closed-connection tool would also name the user +of a connection the server closed. diff --git a/04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/00-report.md b/04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/00-report.md new file mode 100644 index 00000000..f7a0be9e --- /dev/null +++ b/04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/00-report.md @@ -0,0 +1,65 @@ +--- +status: located +opened: 2026-10-08 +located-in: [mesh-catalog modules/mesh-delivery (holder.go, keep, moved, settleAndKeep, walkMoved and Reconcile; effects.go, Flush)] +fixed-by: +amended-design: +--- + +# 326. mesh-delivery writes a delivery whether or not it changed + +## Symptom + +[Research 036](../../01-RESEARCH/036-everything-over-nats/01-evidence.md) (§4.3, gap G7) read about +5.7 million messages on the subscription to `$KV.mesh-delivery_deliveries.>` in the bus server's first +39 hours: about 40 a second, for a bucket of about 1 000 keys. + +Measured again on 2026-10-08 with the `nats` module's tools: + +- The bucket `mesh-delivery_deliveries` holds 1 021 keys, keeps one value per key, and has **no + watchers** (`nats_buckets`). +- The subscription the research read has no user: it is the bus server's own subscription that stores + each write into the bucket's stream. Its count is the number of **writes**, not deliveries to a reader. +- From 14:13:18 to 14:21:52 UTC its count rose from 5 689 690 to 5 690 432: 742 writes in 514 seconds, + 1.4 a second, or about 43 every 30 seconds. +- Over the server's whole uptime (39 hours 49 minutes at 14:13 UTC) the average is 39.7 writes a second. + +In that window one walk was in progress, so a few of those writes were real changes. The diagnosis +shows why most were not. + +## Why it is an issue + +A key-value bucket is where the mesh keeps current state, and research 036 makes it the thing a view +watches: a watcher receives every write. A bucket that is rewritten when nothing changed sends that view +a stream of non-changes. Today that stream is 1.4 a second, and it was 40 a second for most of the +server's life. A revision of a key no longer means that the delivery changed, which is what a reader of +the bucket would assume. + +The diagnosis is in [01-diagnosis.md](01-diagnosis.md). + +## Impact + +No delivery is wrong. The cost is noise and load: every write is stored and would be sent to every +watcher, and the write rate cannot be used to see that deliveries are moving. + +## How it is checked + +- **In mesh-delivery's tests:** a reconcile pass over walks that did not change performs no write. The + test's fake store counts writes, and the test fails on any write. +- **Live:** over ten minutes in which no delivery changes state, the write count on + `$KV.mesh-delivery_deliveries.>` (`nats.nats_subscriptions`) rises by no more than the number of + owed effects tried in that time. + +## Core or not + +**Not core.** mesh-delivery is not one of the core repositories that to-be 45 names and `cycle.py` +checks: the controller, the node-engine, the tool runner, the SDK, and the catalogue's bus, forge and +build agent. So it resolves without a replay. The test above is still the proof. + +## Suggested fix + +- `keep` writes only when the delivery differs from the value it last wrote. Either compare the encoded + value with the last one written, or set a changed flag wherever the delivery is changed. +- `Reconcile` skips a walk whose revision the delivery already holds. +- A retry of an owed effect that fails again changes only its try count and next time. Whether that + needs a write at every try is a choice for the fix: the count may stay in memory between writes. diff --git a/04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/01-diagnosis.md b/04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/01-diagnosis.md new file mode 100644 index 00000000..726655f4 --- /dev/null +++ b/04-ISSUES/326-mesh-delivery-writes-a-delivery-whether-or-not-it-changed/01-diagnosis.md @@ -0,0 +1,43 @@ +# 326 — Diagnosis + +## 2026-10-08 + +**Where it writes.** mesh-delivery writes a delivery in one place: `keep` (holder.go). `keep` calls the +store's `PutDelivery` (ports.go), which puts the whole delivery into the `deliveries` state through the +runtime. `keep` does not compare the delivery with what it wrote before. Every call writes. + +**Who calls `keep` without a change.** + +- `moved` records the transitions a delivery took and ends with `keep`. It does this also when the list + of transitions is empty. +- `settleAndKeep` calls `settle` and passes the result to `moved`. A delivery with nothing to move is + still written. +- `walkMoved` takes one walk from the controller, records it on its delivery (`linkWalk`) and calls + `settleAndKeep`. A walk that has not changed since the last pass leaves the delivery as it was, and + the delivery is written anyway. +- `Reconcile` asks the controller's `delivery-walks` for the walks it keeps and calls `walkMoved` for each. + The answer holds every open walk and the last 50 that ended. The ticker in main.go runs `Reconcile` + every 30 seconds. + +So each pass writes about one delivery per walk the controller returns. On 2026-10-08 that was 50 walks +(32 done, 14 superseded, 3 failed, 1 walking), against about 43 writes per pass measured. *I think* the +difference is walks that match no delivery: `walkMoved` keeps those aside in memory and writes nothing. + +**What made it 40 a second before today.** Before mesh-catalog #121 (the fix of +[issue 313](../313-history-was-held-for-a-person-and-its-views-retried-for-ever/00-report.md), merged +2026-10-08 09:36 UTC), `Flush` tried every owed effect on every 10-second tick. A failed try was recorded +on the delivery (`Tries`, `Last`) and the delivery was written with `keep`. Issue 313 counted 688 held +deliveries whose views and statuses the forge refused. At one write per 10 seconds each, that is up to 69 +writes a second. *I think* this is most of the 39.7 a second over the server's life. It is not confirmed: +nothing keeps the write rate per hour, only the running count. The fix spaced the retries out (10 seconds, +doubling to an hour) and ends them after 60 tries. A retry still writes its delivery. + +**Ruled out.** + +- *A watcher reading the bucket.* The bucket has no watchers. The research's "messages delivered on the + subscription" is the server's own subscription that stores the writes. +- *The groups bucket.* `mesh-delivery_groups` has 26 keys, and its subscription counted 719 writes in the + same 39 hours. + +**Located** in mesh-delivery: `keep` writes without comparing, and `Reconcile` passes every walk the +controller keeps through `settleAndKeep` every 30 seconds. diff --git a/04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/00-report.md b/04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/00-report.md new file mode 100644 index 00000000..c6d6698a --- /dev/null +++ b/04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/00-report.md @@ -0,0 +1,71 @@ +--- +status: located +opened: 2026-10-08 +located-in: [mesh-controller cmd/mesh-controller (seatverbs.go, a verb runs as a fresh process; handacts.go onTheBus, acting.go forACommand, queue.go dialTheBus, localDoctor, each opening its own connection; plan_retry.go buildSeatPause, a connection per watchdog tick), mesh-controller internal/broker (jetstream.go Dial, every connection named "mesh-controller")] +fixed-by: +amended-design: +--- + +# 327. Every controller verb opens its own bus connection, so the connection count hides a reconnect loop + +## Symptom + +[Research 036](../../01-RESEARCH/036-everything-over-nats/01-evidence.md) (§4.3, gap G7) read 4 407 +connections to the bus in its first 39 hours, against 16 open. *It thought* a tool runner reconnected +often. + +Measured again on 2026-10-08 with the `nats` module's tools: + +- Between 14:12 and 14:20 UTC (uptime 1 d 15 h 48 m 52 s to 1 d 15 h 56 m 41 s, 469 seconds), the + server's connection total rose from 4 654 to 4 695: **41 connections, 5.2 a minute**, 3 of them the test below. Over the + server's life the average is 117 an hour. +- The open count was 16 at every reading, and the connection list read at 14:12 and at 14:15 UTC held + the same 16 connection ids, while the total rose by 7 between those two readings. So **those + connections did not stay open**: each was opened and closed between two readings, and none was a + long-lived client reconnecting. +- **Three calls of `mesh-controller.conditions` in one second added three connections** (4 692 to + 4 695). Three calls of `mesh-controller.delivery-walks` added none. + +The long-lived connections were young too. At 14:15 UTC the controller's two were 4 minutes old, the +build agents' 2 to 19 minutes, the route proxies' 13 to 17 minutes and the tool runners' 10 minutes to 3 +hours. Two walks were sending new builds of the controller, the build agent and catalogue modules +between 14:00 and 14:20 UTC, and the build agent's container on the control node started at 14:19 UTC. +*I think* those young connections are restarts by deliveries; they are tens, not thousands. + +## Why it is an issue + +The server's connection total is the one number that would show a client reconnecting in a loop, and +research 036 asks for exactly that signal. With hundreds of short connections an hour that are normal, +a loop is invisible in it. Every one of them is also named `mesh-controller`, and so are the build +agents' long-lived connections, so the server's connection list cannot say which is which by name. + +The diagnosis is in [01-diagnosis.md](01-diagnosis.md). + +## Impact + +Nothing fails. Each verb that touches the bus pays a connection, a TLS handshake and a login on the +control node, and a reconnect loop of a real client would be hidden among them. The operator cannot +answer "who is reconnecting" from the bus today. + +## How it is checked + +- **In the controller's tests:** a verb served by the serving controller opens no connection of its + own. A test counts the connections the test server accepts while the verb runs. +- **Live:** the `nats` module reads the server's closed connections (`/connz?state=closed`) and a tool + answers connections opened per user and name per hour. A condition is raised when one user's rate + passes a bound. With this fixed, the rate on a quiet hour is the long-lived clients' reconnects and + nothing else. + +## Core or not + +**Core.** It is located in the controller, so it resolves with a replay in mesh-lab's replays register, +proved to fail on the commit before the fix and to pass on it (`replay:`), or with `replay-none:` saying +why none is possible. + +## Suggested fix + +- A verb that only reads the bus, or writes through the conditions keeper, is served with the serving + controller's connection rather than in a fresh process with its own. +- Where a fresh process stays, its connection is named for what it is (`mesh-controller verb + `), and the build agent names its own as the build agent. +- The `nats` module gains the closed-connection tool above. diff --git a/04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/01-diagnosis.md b/04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/01-diagnosis.md new file mode 100644 index 00000000..cd70adc7 --- /dev/null +++ b/04-ISSUES/327-every-controller-verb-opens-its-own-bus-connection-so-the-connection-count-hides-a-reconnect-loop/01-diagnosis.md @@ -0,0 +1,44 @@ +# 327 — Diagnosis + +## 2026-10-08 + +**A verb is a fresh process.** The controller serves its seat's verbs (`mesh-controller.`) by +running the command the verb names, in a fresh process of its own binary, and answering what it printed +(seatverbs.go). The comment there gives the reason: the logic lives once, in the command, and every +command opens and closes its own stores the way it does from a shell. + +**A process that needs the bus dials it.** A command process has no connection of the serving +controller's, so each place that needs the bus opens one, uses it and closes it: + +- `onTheBus` (handacts.go): the hand-act log, and through `withKeeper` the conditions keeper. It is + used at 19 places, including `conditions`. +- `forACommand` (acting.go): reading the lease and its epoch before an act. +- `dialTheBus` (queue.go): the build queue's commands; `localDoctor`: a self-check run by a + command. +- `sayingOnTheBus` (delivery.go): a delivery's `check`, `go` and `stop`, which mesh-delivery asks for. + +The serving controller dials too. Its watchdogs run every 30 seconds, and while a walk waits for a +build, `buildSeatPause` (plan_retry.go) opens a fresh connection to read whether the build seat's +holders paused, and closes it. `status` does the same. + +**Measured.** Three `conditions` calls in one second added three connections to the server's total. +Three `delivery-walks` calls, which read only the controller's store, added none. This confirms the +mechanism for one verb. It does not say which callers make the 5 a minute measured: the server keeps no +record of closed connections that the `nats` module's tools read (they read `/connz` for open +connections only), and the controller's `calls` bucket records calls, not whether each dialled. Known +callers that dial: the messenger reads `conditions` when it resyncs (at most once a minute), mesh-delivery +asks `delivery-check`, `deliver` and `delivery-stop`, and people and agents call verbs through the mesh +MCP server. + +**One name for all.** Every connection made by `broker.Dial` or `broker.DialPinned` (internal/broker, +jetstream.go) is named `mesh-controller`. The build agent uses the same function (cmd/mesh-builder), so +its long-lived connections are named `mesh-controller` too and are told apart only by their user. + +**Ruled out.** + +- *A long-lived client reconnecting.* The 16 open connections did not change while the total rose. +- *The tool runners.* Their connections were 10 minutes to 3 hours old, so they are not the 5 a + minute. The research's guess came from their age alone. + +**Located** in the controller: one connection per command process that touches the bus, and one per +watchdog tick while a walk waits for a build. diff --git a/04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/00-report.md b/04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/00-report.md new file mode 100644 index 00000000..d7fc0f1a --- /dev/null +++ b/04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/00-report.md @@ -0,0 +1,61 @@ +--- +status: open +opened: 2026-10-08 +located-in: [] +fixed-by: +amended-design: +--- + +# 328. JetStream API errors are counted, and attributed to nothing + +## Symptom + +[Research 036](../../01-RESEARCH/036-everything-over-nats/01-evidence.md) (§4.3, gap G7) read 4 688 +JetStream API errors out of 6.08 million calls in the bus server's first 39 hours. + +Measured again on 2026-10-08 with `nats.nats_server`: + +- From 14:12 to 14:20 UTC the count rose from 4 794 to 4 810: **16 errors in 475 seconds, 2 a + minute.** Over the server's life the average is 120 an hour, out of 6.1 million calls (0.08 %). +- During the same minutes, three `mesh-controller.conditions` calls, three `delivery-walks` calls and a + dozen reads of the `nats` module's tools added no error. + +**Which calls fail, and from whom, cannot be read.** The `nats` module's tools read the server's +totals (`/varz`, `/jsz`). The server publishes one audit advisory per failed API call on +`$JS.EVENT.ADVISORY.API`, inside the mesh's own account, but nothing subscribes to it: the only +advisory subscriptions on the server are the controller's two, for a consumer deleted and a message +given up after its maximum deliveries. The server's log shows no API errors at its level. + +## Why it is an issue + +An API error can be harmless: asking for the last message on a subject that has none is counted as +one. It can also be a refusal that matters: a consumer that could not be made, a stream update the +server refused, a request the account was denied. All of them are in one number that nothing watches, +so a real refusal is hidden among the expected ones. +Design 25 makes the bus the place the mesh happens, and this count has no reader. + +The diagnosis so far is in [01-diagnosis.md](01-diagnosis.md). + +## Impact + +None known. What is not known is whether any of the 120 an hour is a refusal that left a module without +its consumer, its bucket or its grant. + +## How it is checked + +- **Attribution:** a tool (in the `nats` module, which reads the server) answers the API errors of a + window by API subject, error code and user, from the audit advisory. +- **Resolution:** every error code seen over a day is either fixed at its caller or named as expected + (for example, "no message for this subject" on a pause subject). A condition is raised for any error + code not on the expected list. + +## Core or not + +**Not known yet.** It is core if diagnosis locates it in the controller, the node-engine, the tool +runner, the SDK or the catalogue's `nats` module, and then it resolves with a replay (`replay:`) or with +`replay-none:` saying why none is possible. + +## Suggested fix + +Subscribe to `$JS.EVENT.ADVISORY.API` in the `nats` module, keep counts per subject, code and user, +and add the tool and the condition above. Then each caller found is fixed or named as expected. diff --git a/04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/01-diagnosis.md b/04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/01-diagnosis.md new file mode 100644 index 00000000..8a276330 --- /dev/null +++ b/04-ISSUES/328-jetstream-api-errors-are-counted-and-attributed-to-nothing/01-diagnosis.md @@ -0,0 +1,24 @@ +# 328 — Diagnosis + +## 2026-10-08 + +**What was read.** The server's totals, before and after a set of known calls: three +`mesh-controller.conditions`, three `mesh-controller.delivery-walks` and a dozen `nats` tool reads added +calls and no error. The server's log since it started (2026-10-06 22:24 UTC) holds permission +violations, two slow consumers and configuration reloads, and no JetStream API error. The advisory +subscriptions on the server are the controller's two (`CONSUMER.DELETED`, `CONSUMER.MAX_DELIVERIES`); +nothing subscribes to `$JS.EVENT.ADVISORY.API`, the per-call audit. + +**Status open.** No tool answers which call failed, so the owner cannot be named yet. The first step of +the fix is the attribution tool; with it, this diagnosis continues. + +**Leads, not confirmed.** + +- **A holder that never said it paused.** `PausedSaid` (controller, internal/link/queue.go) asks for the + last message on each build holder's pause subject. A holder that never said one gets a not-found + answer, which the server counts as an API error. The serving controller's watchdog reads it every 30 + seconds while a walk waits for a build (issue 327). +- **Short-lived consumers.** The controller heard 495 "consumer deleted" advisories in the first 8 + minutes of its current connection, about one a second. They are short-lived consumers: the controller's + advisory reader (internal/link/advisories.go) ignores them and says why, "every watch of a bucket and + every read-back of a stream makes one, many a minute". A request to delete one that the server already removed would be an API error. diff --git a/04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/00-report.md b/04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/00-report.md new file mode 100644 index 00000000..b1f77515 --- /dev/null +++ b/04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/00-report.md @@ -0,0 +1,72 @@ +--- +status: located +opened: 2026-10-08 +located-in: [mesh-controller cmd/mesh-controller (busobjects.go, moduleConsumers and EnsureConsumer on every send; modules.go, the consumer made when a module's bus user is minted)] +fixed-by: +amended-design: +--- + +# 329. An event consumer a module stops declaring stays on the bus + +## Words + +The glossary has no word for the durable JetStream consumer through which a module hears the events it +`consumes`; its *consumer* is the Provisioning sense (the module that requires a provision). This issue +calls the durable an **event consumer** and proposes that word. + +## Symptom + +[Research 036](../../01-RESEARCH/036-everything-over-nats/01-evidence.md) (§4.3, gap G7) found four +event consumers with nothing to consume. Measured again on 2026-10-08 at 14:15 UTC with +`nats.nats_streams` on the EVENTS stream: + +- Four pull consumers, one per machine, each named `_claude-code`, filter on + `mesh.mod.claude-licence-manager.event.licence.rotated` and `…licence.switched`. +- None has ever delivered a message (no last delivery), none has a waiting pull, and the server's + subscriptions for their next-message requests have received none. +- The licence manager's manifest emits `licence.adopted`, `licence.refused`, `licence.failing` and + `usage.read`. Nothing emits `licence.rotated` or `licence.switched`. +- The claude-code manifest declares no `consumes` at all. + +**Where they came from.** The catalogue commit that moved claude-code onto the bus (2026-10-04) declared +both events in claude-code's `consumes`. A later commit the same day, the licence manager in Go +(ADR 0206), removed them; the licence manager's bindings bucket (ADR 0201) took their place. The +consumers made in between were never removed. + +## Why it is an issue + +The controller creates a module's event consumers from its declaration, on every send. It never removes +one that no declaration asks for any more, and no rule says who may. So the bus keeps every event +consumer the mesh ever made. + +The diagnosis is in [01-diagnosis.md](01-diagnosis.md). + +## Impact + +Today these four cost almost nothing: their filters match nothing that is emitted. The same fault on a +subject that *is* still emitted would leave a consumer collecting a week of events with no reader +(EVENTS keeps seven days). It would then show as behind in `nats_backlog` for ever, and a module that +declared the subject again later would start from that stale position rather than from now (the shape +of [issue 248](../248-the-controllers-event-consumer-replayed-a-week-and-held-every-merge-behind-it/00-report.md)). + +## How it is checked + +- **A self-check probe** compares the event consumers on EVENTS named `_` with the set + the controller derives from the declarations (`moduleConsumers`). Each extra one raises a condition + naming it, its filters and its pending count. The four above raise it until they are removed. +- **In the controller's tests:** a module whose declaration drops a consumed event leaves the derived + set without its consumer, and the probe reports the one on the bus. + +## Core or not + +**Core.** It is located in the controller, so it resolves with a replay in mesh-lab's replays register, +proved to fail on the commit before the fix and to pass on it (`replay:`), or with `replay-none:` saying +why none is possible. + +## Suggested fix + +The probe above, and a controller verb that deletes an event consumer the declarations no longer ask +for, as a hand act that says why. Whether the controller may delete such a consumer by itself when it +has nothing pending is a decision for the operator: [ADR 0230](../../02-DECISIONS/0230-a-consumer-the-mesh-stops-asking-for-is-retired-and-deleted-only-by-a-person.md) +covers a provision's consumer and keeps deletion for a person, and nothing yet says whether an event +consumer follows the same rule. diff --git a/04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/01-diagnosis.md b/04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/01-diagnosis.md new file mode 100644 index 00000000..171d277b --- /dev/null +++ b/04-ISSUES/329-an-event-consumer-a-module-stops-declaring-stays-on-the-bus/01-diagnosis.md @@ -0,0 +1,30 @@ +# 329 — Diagnosis + +## 2026-10-08 + +**Where an event consumer is made.** Two places in the controller: + +- On every send, the bus objects a declaration implies are asserted (busobjects.go): the seats' queues, + then `moduleConsumers`, which derives one event consumer per module that declares `consumes`, and + `EnsureConsumer` for each. The comment says why it runs on every send: modules moved onto the bus were + issued their credentials on the old broker and came up with nothing to bind to (2026-09-28). +- When a module's bus user is minted (`rollout mint`, modules.go), its event consumer is made at once if + the bus is reachable. + +**Where one is removed.** Nowhere for this purpose. The controller's own code (outside its vendored +client library) deletes a consumer only in `consumer-reset` (nodes.go), a person's command that makes one +consumer again from now (issue 248). `EnsureConsumer` creates or updates; nothing lists the consumers on +EVENTS and compares them with what the declarations ask for. + +**Why ADR 0230 does not cover it.** ADR 0230 and the glossary's *retire* are about a provider and the +consumer of a provision: a database, a login, a bucket a provider keeps for a module. An event consumer +on the bus has no provider in that sense; the controller makes it. So no record says who removes one, or +when. + +**The four found.** `_claude-code` on each of the four machines, filtering +`licence.rotated` and `licence.switched` of the licence manager. The catalogue's history shows claude-code +declaring both on 2026-10-04 and dropping them the same day, when the licence manager moved to Go and the +bindings bucket replaced the events. claude-code never pulls from them (no waiting pull, no next-message +request since the server started). + +**Located** in the controller: assertion without comparison, on send and at mint. diff --git a/04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/00-report.md b/04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/00-report.md new file mode 100644 index 00000000..94ea33bb --- /dev/null +++ b/04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/00-report.md @@ -0,0 +1,67 @@ +--- +status: located +opened: 2026-10-08 +located-in: [mesh-controller internal/broker (streams.go, the streams the controller declares; derived.go, each event consumer's maximum), mesh-controller internal/link (advisories.go, the maximum-deliveries advisory)] +fixed-by: +amended-design: +--- + +# 330. The dead-letter stream design 25 promises does not exist + +## Symptom + +[Design 25](../../03-DESIGN/01-to-be/25-the-bus-on-nats.md) says it three times: + +- §1, the traffic table: an event is "delivered to every consumer that declared it; dead-lettered when it + cannot be"; +- §3, the EVENTS row: "after `max-deliver` attempts the advisory feeds `mesh.events.dead` (its own small + stream)"; +- §10, how it is checked: "an event whose consumer keeps failing dead-letters after `max-deliver`". + +[ADR 0042](../../02-DECISIONS/0042-the-shape-of-an-event-on-the-wire.md) decided the dead-letter +destination, and [ADR 0106](../../02-DECISIONS/0106-the-bus-is-nats.md) names dead-lettering in how the +bus is checked. + +On 2026-10-08 at 14:12 UTC, `nats.nats_streams` listed 21 streams. None holds dead letters, and no stream +takes `mesh.events.dead`. + +**It has happened.** On 2026-10-06 between 15:51 and 16:26 UTC, a media server's event consumer gave up +on several messages after five deliveries each (stream messages 442416, 442421, 442962 and 442964 among +them). The controller raised a `max-deliveries` condition for each run and cleared it within minutes, when +the advisories stopped. The messages were kept only in EVENTS, which drops an event after seven days. No +record says which messages were given up, so they can no longer be found or delivered again. + +## Why it is an issue + +The design states a guarantee and a check for it, and nothing enforces either. A reader of design 25 +believes an event that could not be handled is kept. It is not: what remains is a condition that clears +itself while the work it was about was never done. + +The diagnosis is in [01-diagnosis.md](01-diagnosis.md). + +## Impact + +An event a consumer cannot handle is lost after a week, silently once its condition clears. For the +media server this was a download it did not take in; for the controller's own consumer it would be a +merge or a build outcome (its consumer has a maximum of deliveries too). + +## How it is checked + +- **A replay in mesh-lab:** a consumer that never acknowledges an event; after its maximum deliveries the + event is in the dead-letter stream with its consumer and the reason. +- **A self-check probe:** the dead-letter stream exists with the configuration the controller declares. +- **A condition** stays open while the dead-letter stream holds an event nobody has delivered again or + dropped, so it is not cleared by the advisories stopping. + +## Core or not + +**Core.** It is located in the controller, so it resolves with a replay in mesh-lab's replays register, +proved to fail on the commit before the fix and to pass on it (`replay:`), or with `replay-none:` saying +why none is possible. + +## Suggested fix + +The controller declares a small dead-letter stream beside EVENTS. On each maximum-deliveries advisory it +copies the given-up message (the advisory names its stream and sequence) into that stream with the +consumer's name and when. A verb lists what it holds, delivers one again or drops it, as a hand act. If +the operator decides against a stream, design 25 §1, §3 and §10 are amended to say what happens instead. diff --git a/04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/01-diagnosis.md b/04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/01-diagnosis.md new file mode 100644 index 00000000..23cf6826 --- /dev/null +++ b/04-ISSUES/330-the-dead-letter-stream-design-25-promises-does-not-exist/01-diagnosis.md @@ -0,0 +1,29 @@ +# 330 — Diagnosis + +## 2026-10-08 + +**What the controller declares.** The streams on the bus are declared by the controller +(internal/broker, streams.go): EVENTS, CONTROL, ASSIGNMENTS, NODES, the seats' work queues and the +buckets. No dead-letter stream is among them, and nothing else on the bus declares one: the 21 streams +`nats_streams` lists are all the controller's or a module's bucket. + +**What happens at the maximum.** Every event consumer has a maximum of five deliveries. When a message +reaches it, the server publishes `$JS.EVENT.ADVISORY.CONSUMER.MAX_DELIVERIES` with the stream, the +consumer and the message's sequence. The controller subscribes to it (internal/link/advisories.go) and +raises a `max-deliveries` condition that says the message "will not be delivered again". It keeps nothing +else. The condition clears when the advisories stop, which is when the consumer has moved past the +message, not when the message was handled. + +**Words that say otherwise.** The declaration of the controller's own consumer on EVENTS (streams.go) +and of every module's event consumer (derived.go, the consumer's recorded reason) say "after max-deliver +it dead-letters". The tool runner's NATS binding (mesh-tools, broker-nats.ts) says a handler failing for +good "exhausts max-deliver and dead-letters". Each consumer gives up after five deliveries; nothing +receives what it gave up. + +**Why the check did not catch it.** Design 25 §10 lists "an event whose consumer keeps failing +dead-letters after `max-deliver`" as a check, and to-be 28 step 4 lists it for the core speaking the bus. +No test, probe or replay checks it on the bus the mesh runs. The one check that existed, mesh-lab's +events integration test, asserts the dead-letter exchange of the AMQP broker the NATS bus replaced; it was +not carried over. + +**Located** in the controller: the stream is not declared, and the advisory reader keeps nothing.