Acknowledged messages are replayed again into a running session, so a lead can act on the same instruction twice #127

Closed
opened 2026-08-26 14:15:31 +00:00 by jlxq0 · 2 comments
Owner

Observed by Mantis, 2026-08-26 evening: the same twenty messages replayed into one running session four times in a few minutes, with mark_read called on the newest event each time and returning success. Same event ids, arriving repeatedly, after acknowledgement.

Documented behaviour is that unacknowledged events are re-delivered at the next session start. This is re-delivery within one running session, of events already marked read.

Four replays is four session initializes, and that may not be our bug

Replay is not on a timer. on_initialized spawns replay_missed (src/mcp.rs:7131-7140) and nothing else calls it, so four replays in a few minutes is four initialize requests in a few minutes, into what the user experienced as one running session. That is an inference from the call graph rather than a log of four handshakes, and it is the only path by which a replay can happen.

That number corroborates jlxq0/caldav-mcp#21, where twenty-four calendar events cost twenty-four initialize requests and the reading was that the connector opens a fresh session per tool call. That issue says plainly that it is "a well-supported reading of a count, not a measurement". This is a second, independent sighting from a different server and a different signal, and m365-mcp has a third.

It reframes this issue rather than closing it. If reconnection is normal and frequent, then a watermark that goes stale between initializes is not an occasional annoyance, it is a defect that fires on ordinary use, and the fix is more urgent rather than less.

One thing to establish before the three sightings are treated as one phenomenon. caldav-mcp#21 is about the MCP connector on claude.ai. The mount here is a Claude Code channel session. If those are different clients, then two clients show the same shape, which is a stronger fact about the ecosystem and a weaker one about any single implementation. If they are the same client, it is one bug seen from three angles. Nobody has checked which, and the two conclusions differ.

What would turn the inference into a measurement, and it is the same thing caldav-mcp#21 asks for: log the initialize requests with their session ids, and show consecutive ones carrying different ids within one conversation. Cheap here, and it also settles the client question, since the two clients present differently.

The cost is #125's cost, with a wider input

#125 is an edit arriving as a second message. This is any message arriving as a second message. A session that cannot tell a replay it has already handled from a new instruction will act twice, and these carry replayed="true" on content that has already been acted on. It was harmless tonight because the session recognised the messages; a lead meeting an old instruction it has not seen before will not.

What the source already settles, so nobody re-derives it

The replay query does consult the receipt. replay_room loads the watermark at src/channel.rs:977-982 via load_user_receipt(StoredReceiptType::Read, ReceiptThread::Unthreaded, user_id) and walks backwards from the newest event, breaking at it (src/channel.rs:996-1005). So this is not "the acknowledgement is inert because the query ignores it".

The receipt type matches. mark_read sends ReceiptType::Read with ReceiptThread::Unthreaded (src/mcp.rs:4618-4620), which is the pair replay_room loads. Not the published-identifier-versus-accepted-identifier mismatch that would make it fail forever.

Replay fires on every session initialize. on_initialized spawns replay_missed (src/mcp.rs:7131-7140). It is not on a timer, so four replays in a few minutes means four initializes — the mount reconnecting. replay_missed holds a per-identity lock (src/channel.rs:934-947) which prevents two concurrent passes and does nothing about four sequential ones.

No receipt is sent by the push paths themselves, live or replay, by design: the agent's mark_read is what retires an event (src/channel.rs:1655).

What is left, and it is two different fixes with one observable

The write may not be locally visible in time. send_single_receipt sends the receipt to the homeserver; load_user_receipt reads the local state store. If the store is only updated when the receipt comes back down /sync, then a re-initialize seconds later reads a stale watermark and replays everything again — and every return value along the way is honest. Whether matrix-sdk 0.17 echoes it into the store synchronously is unverified and is the thing to check first.

Or the write does not land at all. mark_read returning Ok is not evidence that anything was written. Today has three instances of exactly that shape in this fleet: a JMAP notCreated under an HTTP 200, a formatter allowlist discarding what the app logged, and a docker status tick that is a skip.

The diagnostic that separates them, from Mantis and it is the right one: one mark_read, then a direct read of load_user_receipt for that room, before any replay happens. Receipt absent → the write. Receipt present and the batch still arrives → the query, or the staleness above. It needs to be run against a live homeserver, not reasoned about; the two branches are indistinguishable from the observable alone.

Worth measuring in the same pass: how long after mark_read the local store reflects it, since a fix that waits for the echo needs a number rather than a guess, and a fixed sleep is the wrong shape.

  • #125, the same failure with edits as the input.
  • #124, the replay path not carrying what it holds.
  • jlxq0/caldav-mcp#21, the connector opening a fresh session per tool call, and #20 there for why raising a limiter's ceiling hides it. Raising a limit or suppressing a replay both stop the symptom without anyone finding this.
Observed by Mantis, 2026-08-26 evening: **the same twenty messages replayed into one running session four times in a few minutes**, with `mark_read` called on the newest event each time and returning success. Same event ids, arriving repeatedly, after acknowledgement. Documented behaviour is that unacknowledged events are re-delivered at the **next session start**. This is re-delivery within one running session, of events already marked read. ## Four replays is four session initializes, and that may not be our bug Replay is not on a timer. `on_initialized` spawns `replay_missed` (`src/mcp.rs:7131-7140`) and nothing else calls it, so **four replays in a few minutes is four `initialize` requests in a few minutes, into what the user experienced as one running session.** That is an inference from the call graph rather than a log of four handshakes, and it is the only path by which a replay can happen. That number corroborates **jlxq0/caldav-mcp#21**, where twenty-four calendar events cost twenty-four `initialize` requests and the reading was that the connector opens a fresh session per tool call. That issue says plainly that it is "a well-supported reading of a count, not a measurement". This is a second, independent sighting from a different server and a different signal, and `m365-mcp` has a third. **It reframes this issue rather than closing it.** If reconnection is normal and frequent, then a watermark that goes stale between initializes is not an occasional annoyance, it is a defect that fires on ordinary use, and the fix is more urgent rather than less. **One thing to establish before the three sightings are treated as one phenomenon.** `caldav-mcp#21` is about the MCP connector on claude.ai. The mount here is a Claude Code channel session. If those are different clients, then two clients show the same shape, which is a stronger fact about the ecosystem and a weaker one about any single implementation. If they are the same client, it is one bug seen from three angles. Nobody has checked which, and the two conclusions differ. **What would turn the inference into a measurement**, and it is the same thing `caldav-mcp#21` asks for: log the `initialize` requests with their session ids, and show consecutive ones carrying different ids within one conversation. Cheap here, and it also settles the client question, since the two clients present differently. ## The cost is #125's cost, with a wider input #125 is an edit arriving as a second message. This is *any* message arriving as a second message. A session that cannot tell a replay it has already handled from a new instruction will act twice, and these carry `replayed="true"` on content that has already been acted on. It was harmless tonight because the session recognised the messages; a lead meeting an old instruction it has not seen before will not. ## What the source already settles, so nobody re-derives it **The replay query does consult the receipt.** `replay_room` loads the watermark at `src/channel.rs:977-982` via `load_user_receipt(StoredReceiptType::Read, ReceiptThread::Unthreaded, user_id)` and walks backwards from the newest event, breaking at it (`src/channel.rs:996-1005`). So this is not "the acknowledgement is inert because the query ignores it". **The receipt type matches.** `mark_read` sends `ReceiptType::Read` with `ReceiptThread::Unthreaded` (`src/mcp.rs:4618-4620`), which is the pair `replay_room` loads. Not the published-identifier-versus-accepted-identifier mismatch that would make it fail forever. **Replay fires on every session initialize.** `on_initialized` spawns `replay_missed` (`src/mcp.rs:7131-7140`). It is not on a timer, so four replays in a few minutes means four initializes — the mount reconnecting. `replay_missed` holds a per-identity lock (`src/channel.rs:934-947`) which prevents two *concurrent* passes and does nothing about four sequential ones. **No receipt is sent by the push paths themselves**, live or replay, by design: the agent's `mark_read` is what retires an event (`src/channel.rs:1655`). ## What is left, and it is two different fixes with one observable **The write may not be locally visible in time.** `send_single_receipt` sends the receipt to the homeserver; `load_user_receipt` reads the local state store. If the store is only updated when the receipt comes back down `/sync`, then a re-initialize seconds later reads a stale watermark and replays everything again — and every return value along the way is honest. Whether matrix-sdk 0.17 echoes it into the store synchronously is unverified and is the thing to check first. **Or the write does not land at all.** `mark_read` returning `Ok` is not evidence that anything was written. Today has three instances of exactly that shape in this fleet: a JMAP `notCreated` under an HTTP 200, a formatter allowlist discarding what the app logged, and a `docker` status tick that is a skip. **The diagnostic that separates them**, from Mantis and it is the right one: one `mark_read`, then a direct read of `load_user_receipt` for that room, before any replay happens. Receipt absent → the write. Receipt present and the batch still arrives → the query, or the staleness above. It needs to be run against a live homeserver, not reasoned about; the two branches are indistinguishable from the observable alone. Worth measuring in the same pass: how long after `mark_read` the local store reflects it, since a fix that waits for the echo needs a number rather than a guess, and a fixed sleep is the wrong shape. ## Related - #125, the same failure with edits as the input. - #124, the replay path not carrying what it holds. - jlxq0/caldav-mcp#21, the connector opening a fresh session per tool call, and #20 there for why raising a limiter's ceiling hides it. Raising a limit or suppressing a replay both stop the symptom without anyone finding this.
Author
Owner

A single event now reproduces it, which removes every question about batching.

$35EIP1_W-d_Pz-qSTE98X3DIcJ_uFAU1JRDyaPGVkN4 was delivered to one session three times. mark_read was called on that exact id after the second delivery, returned success, and the event arrived again after that call.

As a test: call mark_read with a specific event_id, receive success, receive the same event again. One id, one acknowledgement, one repeat. Nothing about watermark walking, ordering, truncation or REPLAY_MAX is involved, so none of it has to be excluded first.

It also lands squarely on the branch this issue had narrowed to. send_single_receipt writes to the homeserver; load_user_receipt reads the local state store. If the store is only updated when the receipt returns via /sync, the second replay reads a watermark that predates the acknowledgement and every return value along the path is honest.

The diagnostic is now two calls rather than a replay cycle. mark_read on that id, then load_user_receipt for that room, read directly. Receipt absent immediately after a success is the write. Receipt present and the event still delivered is the query or the staleness. Either answer arrives without waiting for a reconnection.

Worth taking in the same pass, since it decides the shape of the fix rather than merely confirming it: how long after mark_read the local store reflects it. A fix that waits for the echo needs a number, and a fixed sleep chosen without one is the wrong shape.

CI note for whoever runs it: this needs a live homeserver. It is not reachable from the unit suite, and reasoning about matrix-sdk's store semantics from the source is what produced the two branches rather than an answer.

**A single event now reproduces it, which removes every question about batching.** `$35EIP1_W-d_Pz-qSTE98X3DIcJ_uFAU1JRDyaPGVkN4` was delivered to one session three times. `mark_read` was called on that exact id after the second delivery, returned success, and the event arrived again after that call. As a test: **call `mark_read` with a specific `event_id`, receive success, receive the same event again.** One id, one acknowledgement, one repeat. Nothing about watermark walking, ordering, truncation or `REPLAY_MAX` is involved, so none of it has to be excluded first. It also lands squarely on the branch this issue had narrowed to. `send_single_receipt` writes to the homeserver; `load_user_receipt` reads the local state store. If the store is only updated when the receipt returns via `/sync`, the second replay reads a watermark that predates the acknowledgement and every return value along the path is honest. **The diagnostic is now two calls rather than a replay cycle.** `mark_read` on that id, then `load_user_receipt` for that room, read directly. Receipt absent immediately after a success is the write. Receipt present and the event still delivered is the query or the staleness. Either answer arrives without waiting for a reconnection. Worth taking in the same pass, since it decides the shape of the fix rather than merely confirming it: **how long after `mark_read` the local store reflects it.** A fix that waits for the echo needs a number, and a fixed sleep chosen without one is the wrong shape. CI note for whoever runs it: this needs a live homeserver. It is not reachable from the unit suite, and reasoning about matrix-sdk's store semantics from the source is what produced the two branches rather than an answer.
Author
Owner

Closing as a duplicate of #140, which carries the worse consequence.

Same defect: events re-delivered after mark_read returned success on those same ids. #140 adds what makes it dangerous rather than merely noisy, that two of the four replayed events were authorisations, and a replayed authorisation is indistinguishable from a fresh one.

The observation here is not lost and belongs on #140: the same twenty messages replayed into one running session four times in a few minutes, with mark_read called on the newest event each time and returning success. Documented behaviour is re-delivery at the next session start; this is re-delivery within one session.

Work it on #140.

**Closing as a duplicate of `#140`, which carries the worse consequence.** Same defect: events re-delivered after `mark_read` returned success on those same ids. `#140` adds what makes it dangerous rather than merely noisy, that **two of the four replayed events were authorisations**, and a replayed authorisation is indistinguishable from a fresh one. **The observation here is not lost and belongs on `#140`**: the same twenty messages replayed into one running session **four times in a few minutes**, with `mark_read` called on the newest event each time and returning success. Documented behaviour is re-delivery at the next session start; this is re-delivery within one session. Work it on `#140`.
jlxq0 closed this issue 2026-08-31 03:30:04 +00:00
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
jlxq0/matrix-mcp#127
No description provided.