Merge pull request 'Issues 326-330: research 036's live bus faults, measured again and diagnosed' (#217) from issues/036-bus-faults into main
This commit was merged in pull request #217.
This commit is contained in:
@@ -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).
|
||||
|
||||
+21
@@ -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.
|
||||
|
||||
@@ -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.
|
||||
+43
@@ -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.
|
||||
+71
@@ -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
|
||||
<verb>`), and the build agent names its own as the build agent.
|
||||
- The `nats` module gains the closed-connection tool above.
|
||||
+44
@@ -0,0 +1,44 @@
|
||||
# 327 — Diagnosis
|
||||
|
||||
## 2026-10-08
|
||||
|
||||
**A verb is a fresh process.** The controller serves its seat's verbs (`mesh-controller.<verb>`) 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.
|
||||
@@ -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.
|
||||
+24
@@ -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.
|
||||
+72
@@ -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 `<machine>_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 `<machine>_<module>` 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.
|
||||
+30
@@ -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.** `<machine>_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.
|
||||
@@ -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.
|
||||
+29
@@ -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.
|
||||
Reference in New Issue
Block a user