From eb2f35d7740c1db55f7de0233a6d29de7354cd90 Mon Sep 17 00:00:00 2001 From: scgopi Date: Mon, 7 Sep 2026 07:11:40 -0700 Subject: [PATCH] Record a presence read that ran out of time (#322) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `drain-stall` fires only past `drainLeaseDuration`, which is 300s, while a presence read is bounded at 45s. So a drain stalled by a hung read released long before the threshold and left no line at all — the stall that actually happens was the one nothing recorded. That is how #311 stayed invisible for a day: frozen and working looked identical from outside. An end-to-end rerun of that wedge against the shipped 0.1.64 found delivery correctly recovering at the deadline and, in the same runs, zero drain-stall and zero delivery-stall lines. The only trace was a `handle_ms` on a command that happened to be riding the wedged drain; a wedge the presence poller hits with no client command in flight left nothing. The timeout is the event, and the lease is only the backstop, so the line belongs where the read gives up. It carries the node whose backend stopped answering and the bound it broke — a UUID and a duration, never a title or any other user text, matching what `delivery-stall` already records. Any deadline shorter than the stall threshold it feeds is invisible by construction; this was the one that mattered because the presence poll runs without a client command to carry its timing. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01BP43ags4cn8fq2ZZdv85J9 --- GraphcodeKit/Sources/GraphStore.swift | 22 ++++++++++++++-- graphcode/Tests/DrainWedgeTests.swift | 36 +++++++++++++++++++++++++++ 2 files changed, 56 insertions(+), 2 deletions(-) diff --git a/GraphcodeKit/Sources/GraphStore.swift b/GraphcodeKit/Sources/GraphStore.swift index 3f383c8b..bb296441 100644 --- a/GraphcodeKit/Sources/GraphStore.swift +++ b/GraphcodeKit/Sources/GraphStore.swift @@ -368,8 +368,26 @@ public actor GraphStore { private func presenceReading(of node: LoopNode) async -> PresenceReading? { guard let onReadPresence else { return nil } let path = graph.project.path - return await withDeadline(presenceReadDeadline) { await onReadPresence(node, path) } - ?? .unknown + // The closure is passed rather than trailing: a trailing closure in a `guard let` + // condition is read as the guard's own body. + let read = await withDeadline(presenceReadDeadline, { await onReadPresence(node, path) }) + guard let reading = read else { + // The timeout is the event; the lease is only the backstop. `drain-stall` fires + // past `drainLeaseDuration`, and a read bounded well below that never reaches it — + // so the stall that actually happens was the one nothing recorded, which is how + // issue #311 stayed invisible for a day. A read that ran out of time says a + // backend is not answering, and that is worth a line whether or not a drain was + // waiting on it: the presence poll hits this with no client command in flight, + // and used to leave no trace at all. + DaemonLog.shared.record( + "presence-stall", + DaemonRequestContext.fields + [ + ("node", node.id.uuidString), + ("deadline_ms", DaemonLog.milliseconds(presenceReadDeadline.timeInterval)), + ]) + return .unknown + } + return reading } private func recordMemory(_ nodeID: UUID, _ entry: String) { diff --git a/graphcode/Tests/DrainWedgeTests.swift b/graphcode/Tests/DrainWedgeTests.swift index 45ad7497..bffbe0b2 100644 --- a/graphcode/Tests/DrainWedgeTests.swift +++ b/graphcode/Tests/DrainWedgeTests.swift @@ -147,6 +147,42 @@ struct DrainWedgeTests { _ = await wedging.value } + /// Issue #322: the stall that actually happens is the one nothing recorded. + /// + /// `drain-stall` fires only past `drainLeaseDuration`, and a presence read bounded far + /// below that never reaches it — so a read that timed out left no line at all, and the + /// presence poll hits this with no client command in flight to carry a `handle_ms`. + /// That is how #311 stayed invisible for a day: frozen and working looked identical. + @Test + func aTimedOutPresenceReadIsRecorded() async { + let fixture = fixture() + let lines = LockIsolated<[String]>([]) + let tap = DaemonLog.shared.tap { line in lines.withValue { $0.append(line) } } + defer { DaemonLog.shared.untap(tap) } + let store = GraphStore( + graph: fixture.graph, + onDeliverMessage: { _, _, _ in true }, + onReadPresence: { _, _ in + // Longer than the deadline, so the read is abandoned rather than answered. + try? await Task.sleep(for: .seconds(5)) + return PresenceReading(presence: .idle, confidence: .reported) + }, + // Last, because that is where `GraphStore.init` declares it and Swift matches an + // argument list in declaration order. + presenceReadDeadline: .milliseconds(50)) + + await store.handle( + .messageNode(fixture.bystander, text: "needs a presence read", from: nil, followUp: true)) + + #expect( + lines.value.contains { $0.contains("event=presence-stall") }, + "a presence read that ran out of time left no line: \(lines.value)") + // The node it could not read, so a reader can tell which backend stopped answering, + // and the bound it broke — never a title or any other user text. + #expect(lines.value.contains { $0.contains(fixture.bystander.uuidString) }) + #expect(lines.value.contains { $0.contains("deadline_ms=") }) + } + /// What the deadline cannot reach, and the reason the guard is a lease. /// /// `deliverToSession` is the same `PTYProcessSession` chain as the presence read and