Skip to content

Commit 74fee72

Browse files
tlongwell-blocknpub1mprnacetjua2xx3p5eddmhxyk6wv929ymm5py8kd2xfxurxahspqqlgytaDawn (sprout agent)
committed
fix(relay): replace active stall probe with passive inbound watchdog
The previous stall watchdog issued a periodic NIP-01 REQ ("are you still there?") and treated a missing EOSE as a stalled socket. That write is the trigger for a much worse failure on Warp / VPN-asleep half-open sockets: the tauri-plugin-websocket `send` command holds the global connection-manager mutex across the underlying `poll_flush`, so a probe parked on a dead socket blocks every subsequent `connect` from registering its writer in the map. The replacement socket's read loop never starts → no AUTH challenge ever reaches JS → 8s AUTH timeout → reset → repeat forever. We've reproduced this as the WARP wedge. Remove the active probe entirely. Track inbound activity instead: `recordInbound()` is called from `handleWsMessage` for every frame (including relay heartbeat pings, which are observable as Channel messages even when not surfaced as nostr-protocol payloads). After 60s with no inbound frame at all we declare a stall and call back into the client, which tears down the socket so the existing reconnect path runs. The watchdog itself performs zero writes, which means it cannot trigger the plugin wedge it's trying to detect. A deterministic Playwright regression in `desktop/tests/e2e/relay-reconnect.spec.ts` simulates the plugin symptom directly by hanging `plugin:websocket|send` in the e2e bridge and verifies the watchdog does not write into the half-open socket while reconnect proceeds. Signed-off-by: Tyler Longwell <109685178+tlongwell-block@users.noreply.github.com> Co-authored-by: npub1mprnacetjua2xx3p5eddmhxyk6wv929ymm5py8kd2xfxurxahspqqlgyta <d8473ee32b973aa31a21a65adddcc4b69cc2a8a4dee8121ecd51926e0cddbc02@sprout-oss.stage.blox.sqprod.co> Co-authored-by: Dawn (sprout agent) <c6237ef84fa537c78dcee78efd2d4e59f728859c7f194da42ac51ededfa0be05@sprout-oss.stage.blox.sqprod.co>
1 parent 8033bd0 commit 74fee72

7 files changed

Lines changed: 167 additions & 183 deletions

File tree

desktop/playwright.config.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@ export default defineConfig({
2424
"**/channel-browser.spec.ts",
2525
"**/messaging.spec.ts",
2626
"**/mentions.spec.ts",
27+
"**/relay-reconnect.spec.ts",
2728
"**/workflows.spec.ts",
2829
],
2930
use: {

desktop/src/shared/api/relayClientSession.ts

Lines changed: 7 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -35,23 +35,11 @@ const RECONNECT_BASE_DELAY_MS = 1_000,
3535
EVENT_BATCH_MS = 16;
3636

3737
/**
38-
* Application-level liveness probe.
39-
*
40-
* Tungstenite auto-pongs and the OS keeps the TCP socket open, so a
41-
* half-open WS (Warp's orange-icon state, an asleep VPN, etc.) presents as
42-
* "fully connected" to the WS layer indefinitely — no Close, no Error.
43-
*
44-
* We work around that by periodically sending a cheap NIP-01 `REQ` with
45-
* `limit: 0` and waiting for the matching `EOSE`. A single missed probe
46-
* (no EOSE within `STALL_PROBE_TIMEOUT_MS`) — or a send-side failure on the
47-
* probe itself — flips state to `stalled` and force-resets the socket so
48-
* the existing reconnect path runs.
49-
*
50-
* The filter intentionally matches nothing real so the relay only ever
51-
* answers with EOSE.
38+
* Passive liveness check. The relay sends heartbeat pings every 30s; if no
39+
* inbound frame arrives for two heartbeat windows, treat the socket as stalled.
5240
*/
53-
const STALL_PROBE_INTERVAL_MS = 20_000;
54-
const STALL_PROBE_TIMEOUT_MS = 10_000;
41+
const STALL_CHECK_INTERVAL_MS = 10_000;
42+
const STALL_IDLE_TIMEOUT_MS = 60_000;
5543

5644
export class RelayClient {
5745
private wsId: number | null = null;
@@ -90,9 +78,8 @@ export class RelayClient {
9078

9179
private connectionStateEmitter = new RelayConnectionStateEmitter("idle");
9280
private stallWatchdog = new RelayStallWatchdog({
93-
intervalMs: STALL_PROBE_INTERVAL_MS,
94-
probeTimeoutMs: STALL_PROBE_TIMEOUT_MS,
95-
sendRaw: (payload) => this.sendRaw(payload),
81+
intervalMs: STALL_CHECK_INTERVAL_MS,
82+
idleTimeoutMs: STALL_IDLE_TIMEOUT_MS,
9683
onStall: (error) => {
9784
this.connectionStateEmitter.set("stalled");
9885
this.resetConnection(error);
@@ -692,6 +679,7 @@ export class RelayClient {
692679

693680
private async handleWsMessage(message: unknown, generation: number) {
694681
if (generation !== this.connectionGeneration) return;
682+
this.stallWatchdog.recordInbound();
695683

696684
if (
697685
typeof message === "object" &&
@@ -813,12 +801,6 @@ export class RelayClient {
813801
}
814802

815803
private handleEose(subId: string) {
816-
if (this.stallWatchdog.handleEose(subId)) {
817-
// Probe round-trip succeeded — silently CLOSE the sub.
818-
void this.closeSubscription(subId).catch(() => {});
819-
return;
820-
}
821-
822804
const subscription = this.subscriptions.get(subId);
823805
if (!subscription) {
824806
return;

desktop/src/shared/api/relayStallWatchdog.test.mjs

Lines changed: 59 additions & 78 deletions
Original file line numberDiff line numberDiff line change
@@ -3,123 +3,104 @@ import test from "node:test";
33

44
import { RelayStallWatchdog } from "./relayStallWatchdog.ts";
55

6-
// Shim `window` to expose the timer + crypto APIs the watchdog uses. The
7-
// real RelayClient runs in a Tauri WebView where `window` exists; under
8-
// node:test we wire it to the same globals.
6+
// Shim `window` to expose the timer APIs the watchdog uses. The real
7+
// RelayClient runs in a Tauri WebView where `window` exists; under node:test we
8+
// wire it to the same globals.
99
if (typeof globalThis.window === "undefined") {
1010
globalThis.window = {
1111
setInterval: (...args) => setInterval(...args),
1212
clearInterval: (id) => clearInterval(id),
13-
setTimeout: (...args) => setTimeout(...args),
14-
clearTimeout: (id) => clearTimeout(id),
1513
};
1614
}
1715

1816
const sleep = (ms) => new Promise((r) => setTimeout(r, ms));
1917

2018
function makeWatchdog(overrides = {}) {
21-
const sends = [];
2219
const stalls = [];
20+
let now = overrides.now ?? 1;
2321
const wd = new RelayStallWatchdog({
24-
intervalMs: overrides.intervalMs ?? 30,
25-
probeTimeoutMs: overrides.probeTimeoutMs ?? 30,
26-
sendRaw:
27-
overrides.sendRaw ??
28-
(async (payload) => {
29-
sends.push(payload);
30-
}),
22+
intervalMs: overrides.intervalMs ?? 20,
23+
idleTimeoutMs: overrides.idleTimeoutMs ?? 50,
3124
onStall: (err) => {
3225
stalls.push(err);
3326
},
34-
now: overrides.now,
27+
now: () => now,
3528
});
36-
return { wd, sends, stalls };
29+
return {
30+
advance: (ms) => {
31+
now += ms;
32+
},
33+
setNow: (value) => {
34+
now = value;
35+
},
36+
stalls,
37+
wd,
38+
};
3739
}
3840

39-
test("first probe carries the expected NIP-01 REQ shape", async () => {
40-
const { wd, sends } = makeWatchdog();
41+
test("does not send probes while watching for stalls", async () => {
42+
const { wd } = makeWatchdog();
4143
wd.start();
42-
// Wait until a probe is observed.
43-
for (let i = 0; i < 50 && sends.length === 0; i++) await sleep(5);
44+
await sleep(45);
4445
wd.stop();
45-
assert.equal(sends.length, 1);
46-
const [verb, subId, filter] = sends[0];
47-
assert.equal(verb, "REQ");
48-
assert.match(subId, /^probe-/);
49-
assert.deepEqual(filter.kinds, [9999]);
50-
assert.equal(filter.limit, 0);
51-
assert.ok(typeof filter.since === "number");
46+
// The passive watchdog has no send callback by construction. This test is a
47+
// regression guard for the WARP bug: liveness checks must not write to a
48+
// socket already suspected of being half-open.
49+
assert.equal(typeof wd.recordInbound, "function");
5250
});
5351

54-
test("EOSE for the current probe clears in-flight + lets the next probe fire", async () => {
55-
const { wd, sends, stalls } = makeWatchdog();
52+
test("idle timeout without inbound frames triggers onStall", async () => {
53+
const { advance, stalls, wd } = makeWatchdog();
5654
wd.start();
57-
for (let i = 0; i < 50 && sends.length === 0; i++) await sleep(5);
58-
const firstSubId = sends[0][1];
59-
// Resolve the probe.
60-
assert.equal(wd.handleEose(firstSubId), true);
61-
// Within the next interval+probe window, another probe should fire.
62-
for (let i = 0; i < 50 && sends.length < 2; i++) await sleep(5);
55+
advance(60);
56+
for (let i = 0; i < 20 && stalls.length === 0; i++) await sleep(5);
6357
wd.stop();
64-
assert.ok(sends.length >= 2, `expected ≥2 probes, got ${sends.length}`);
65-
assert.equal(stalls.length, 0, "no stall expected when EOSE arrives");
66-
});
67-
68-
test("EOSE for a non-probe subId returns false", () => {
69-
const { wd } = makeWatchdog();
70-
assert.equal(wd.handleEose("live-abc"), false);
58+
assert.equal(stalls.length, 1);
59+
assert.match(stalls[0].message, /no inbound frames/i);
7160
});
7261

73-
test("timeout without EOSE triggers onStall", async () => {
74-
const { wd, stalls } = makeWatchdog();
62+
test("inbound frames reset the idle timer", async () => {
63+
const { advance, stalls, wd } = makeWatchdog({ idleTimeoutMs: 50 });
7564
wd.start();
76-
// intervalMs (30) before first send + probeTimeoutMs (30) — wait a bit
77-
// past their sum.
78-
for (let i = 0; i < 50 && stalls.length === 0; i++) await sleep(10);
65+
advance(40);
66+
wd.recordInbound();
67+
advance(40);
68+
await sleep(30);
69+
assert.equal(
70+
stalls.length,
71+
0,
72+
"recent inbound frame should keep socket alive",
73+
);
74+
advance(20);
75+
for (let i = 0; i < 20 && stalls.length === 0; i++) await sleep(5);
7976
wd.stop();
80-
assert.ok(stalls.length >= 1, "expected at least one stall");
81-
assert.match(stalls[0].message, /stalled/i);
77+
assert.equal(stalls.length, 1);
8278
});
8379

84-
test("send-side failure triggers onStall immediately", async () => {
85-
const { wd, stalls } = makeWatchdog({
86-
sendRaw: async () => {
87-
throw new Error("ws is dead");
88-
},
89-
});
90-
wd.start();
91-
for (let i = 0; i < 50 && stalls.length === 0; i++) await sleep(5);
92-
wd.stop();
93-
assert.ok(stalls.length >= 1, "expected stall on send failure");
94-
assert.match(stalls[0].message, /ws is dead/);
80+
test("recordInbound is ignored while stopped", async () => {
81+
const { advance, stalls, wd } = makeWatchdog({ idleTimeoutMs: 50 });
82+
wd.recordInbound();
83+
advance(100);
84+
await sleep(30);
85+
assert.equal(stalls.length, 0);
9586
});
9687

97-
test("stop() cancels a pending stall timeout", async () => {
98-
const { wd, sends, stalls } = makeWatchdog();
88+
test("stop() cancels the idle check", async () => {
89+
const { advance, stalls, wd } = makeWatchdog({ idleTimeoutMs: 50 });
9990
wd.start();
100-
for (let i = 0; i < 50 && sends.length === 0; i++) await sleep(5);
101-
// Probe is in-flight; stop before it can time out.
10291
wd.stop();
103-
// Wait well past the timeout window.
104-
await sleep(80);
105-
assert.equal(stalls.length, 0, "stop() should cancel the pending stall");
92+
advance(100);
93+
await sleep(35);
94+
assert.equal(stalls.length, 0);
10695
});
10796

10897
test("start() is idempotent — does not create duplicate intervals", async () => {
109-
const { wd, sends } = makeWatchdog({ intervalMs: 25, probeTimeoutMs: 200 });
98+
const { advance, stalls, wd } = makeWatchdog({ idleTimeoutMs: 50 });
11099
wd.start();
111100
wd.start();
112101
wd.start();
113-
// Allow one probe to fire and resolve it so the *next* probe can fire if
114-
// the interval was somehow doubled.
115-
for (let i = 0; i < 50 && sends.length === 0; i++) await sleep(5);
116-
wd.handleEose(sends[0][1]);
117-
// Within one more interval window, exactly one more probe should fire
118-
// (not two), which is the contract for `start()` being idempotent.
119-
await sleep(45);
102+
advance(60);
103+
for (let i = 0; i < 20 && stalls.length === 0; i++) await sleep(5);
120104
wd.stop();
121-
assert.ok(
122-
sends.length <= 2,
123-
`expected ≤2 probes despite triple-start(), got ${sends.length}`,
124-
);
105+
assert.equal(stalls.length, 1);
125106
});

0 commit comments

Comments
 (0)