Skip to content

Commit cca0461

Browse files
garethxclaude
andcommitted
fix: a hard crash left no record of the outage, so catch-up skipped it
Found by running the plugin end to end against a real Hookdeck project — real source, real tunnel supervised by the plugin, real events, real retries. `npm run test:e2e` is that harness; ten scenarios, all passing, with every resource named openclaw-e2e-* and deleted afterwards. The defect it found: `lastDisconnectAt` is written when the tunnel child exits, which needs this process alive to notice. A kill -9 takes the handler with it, so the outage most in need of catch-up left no record and catch-up skipped it. Confirmed directly: the cursor file is unchanged across a SIGKILL. The transport now records a liveness marker while running and clears it on a clean shutdown, so finding one at startup means the previous process died without stopping, and its timestamp becomes the start of the outage. Over-shooting by a heartbeat is harmless: the catch-up query matches only requests that produced no event, so anything delivered is excluded by construction. With the fix, a killed gateway now issues its replay on reconnect. Two facts the run established that were previously assumed: Hookdeck rejects an unparseable JSON body AT THE EDGE — 400 with rejection_cause UNPARSABLE_JSON, no event created. The plugin's malformed_json handling is therefore defence in depth rather than a path real traffic takes, and the docs now say so instead of implying it is load-bearing. A CLI destination accepts CUSTOM_SIGNATURE, and Hookdeck signs it with byte-identical HMAC-SHA256/base64 in the same header as its own. That is what makes this harness possible at all: the project signing secret is dashboard-only, so the destination is configured with a secret we choose and the verification path runs unchanged. Also proven end to end rather than against fakes: a signed delivery verified and dispatched with a matching ledger row; a manual retry admitted rather than suppressed; an event arriving with no tunnel stranded rather than lost; doctor's project comparison against the real project; and doctor reading `verified` off real inbound requests. 662 tests. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
1 parent c18e39d commit cca0461

11 files changed

Lines changed: 467 additions & 6 deletions

File tree

README.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -148,6 +148,7 @@ The README covers the common path. Everything else lives in [`docs/`](docs/):
148148
openclaw plugins install --link ./hookdeck-openclaw
149149
npm test # no Gateway or Hookdeck account required
150150
npm run test:package # loads the packed tarball in a real Gateway
151+
npm run test:e2e # real project, real tunnel, real events (needs HOOKDECK_TEST_API_KEY)
151152
```
152153

153154
## Learn more

docs/durability.md

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,3 +23,15 @@ Without `apiKey`, orphans are still detected, settled and dead-lettered — they
2323
`safety.allowRetryCancel` lets the plugin answer `Retry-After: -1` on permanently-invalid input — malformed JSON, a body that will never fit — which tells Hookdeck to stop retrying instead of burning all 50 attempts on something that cannot succeed.
2424

2525
**It is off by default, and that default is deliberate.** A mistake here discards real traffic, and the events are gone once retention lapses (3 days on the free plan). Cancellation is only ever emitted from a closed allowlist of reasons, always dead-letters first, and never fires for anything a config change could fix — a missing secret, an unresolvable secretRef or a storage failure all stay retryable. Turn it on once you have watched the logs and seen what it *would* have cancelled.
26+
27+
## A crash that never ran its shutdown
28+
29+
`lastDisconnectAt` is written when the tunnel's child process exits, which requires this process to be alive to notice. A `kill -9`, an OOM kill or a power cut takes that handler with it, so the outage most in need of catch-up would leave no record of itself at all — and catch-up, finding no disconnect, would skip it.
30+
31+
So while the transport is running the plugin records a liveness marker every `catchUp.heartbeatSeconds` (30 by default), and clears it on a clean shutdown. Finding one at startup means the previous process died without stopping, and its timestamp becomes the start of the outage window.
32+
33+
Over-shooting that window by up to one heartbeat is harmless: the catch-up query matches only requests that produced no event at all, so anything that did deliver is excluded by construction.
34+
35+
## Malformed bodies never reach the plugin
36+
37+
Verified end to end: Hookdeck rejects an unparseable JSON body **at the edge**, answering the sender `400` with `rejection_cause: UNPARSABLE_JSON` and creating no event. The plugin's own `malformed_json` handling is therefore defence in depth rather than a path real traffic takes — it covers a body that survives the edge and fails here, such as one that is valid JSON but not valid UTF-8.

openclaw.plugin.json

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -105,6 +105,11 @@
105105
"maximum": 86400,
106106
"default": 30,
107107
"description": "Below this, an outage is not worth a bulk replay."
108+
},
109+
"heartbeatSeconds": {
110+
"type": "integer",
111+
"default": 30,
112+
"description": "How often to record that the gateway is alive, so a crash that never ran its shutdown is still detectable as an outage."
108113
}
109114
}
110115
},

package.json

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -48,7 +48,8 @@
4848
"typecheck": "tsc --noEmit",
4949
"test:live": "vitest run test/live",
5050
"test:agent": "bash scripts/agent-smoke.sh",
51-
"test:package": "bash scripts/test-package.sh"
51+
"test:package": "bash scripts/test-package.sh",
52+
"test:e2e": "node scripts/e2e-live.mjs . $(date +%s | tail -c 6)"
5253
},
5354
"homepage": "https://github.com/hookdeck/hookdeck-openclaw#readme",
5455
"bugs": {

scripts/e2e-live.mjs

Lines changed: 273 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,273 @@
1+
/**
2+
* End-to-end against a real Hookdeck project.
3+
*
4+
* Real source, real tunnel supervised by the plugin itself, real events, real
5+
* retries. The one thing not real is the signing secret: the project's own is
6+
* dashboard-only, so the destination is configured with CUSTOM_SIGNATURE and a
7+
* secret we choose. Verified beforehand to be byte-identical HMAC-SHA256/base64
8+
* in the same header, so the verification path is exercised unchanged.
9+
*
10+
* Everything is named `openclaw-e2e-<run>` and deleted at the end.
11+
*/
12+
import { spawn, execFile } from "node:child_process";
13+
import { readFileSync, writeFileSync, mkdirSync, rmSync, existsSync } from "node:fs";
14+
import { promisify } from "node:util";
15+
16+
const execFileAsync = promisify(execFile);
17+
const REPO = process.argv[2];
18+
const RUN = process.argv[3];
19+
const NAME = `openclaw-e2e-${RUN}`;
20+
const SECRET = `whsec_e2e_${RUN}`;
21+
const PORT = 18871;
22+
const ROOT = `/tmp/openclaw-e2e-${RUN}`;
23+
const KEY = /^HOOKDECK_TEST_API_KEY=(.+)$/m.exec(
24+
readFileSync(`${REPO}/.env.local`, "utf8"),
25+
)[1].trim();
26+
27+
const results = [];
28+
const record = (name, pass, detail) => {
29+
results.push({ name, pass, detail });
30+
console.log(`${pass ? "PASS" : "FAIL"} ${name}${detail ? ` — ${detail}` : ""}`);
31+
};
32+
const sleep = (ms) => new Promise((r) => setTimeout(r, ms));
33+
34+
const api = async (method, path, body) => {
35+
const r = await fetch(`https://api.hookdeck.com/2025-07-01${path}`, {
36+
method,
37+
headers: { authorization: `Bearer ${KEY}`, "content-type": "application/json" },
38+
...(body ? { body: JSON.stringify(body) } : {}),
39+
});
40+
const text = await r.text();
41+
return { status: r.status, body: text ? JSON.parse(text) : {} };
42+
};
43+
44+
// ---------------------------------------------------------------- provision
45+
const conn = await api("PUT", "/connections", {
46+
name: NAME,
47+
source: { name: NAME, type: "WEBHOOK" },
48+
destination: {
49+
name: NAME,
50+
type: "CLI",
51+
config: {
52+
path: "/hookdeck/e2e",
53+
path_forwarding_disabled: true,
54+
auth_type: "CUSTOM_SIGNATURE",
55+
auth: { key: "x-hookdeck-signature", signing_secret: SECRET },
56+
},
57+
},
58+
rules: [{ type: "retry", strategy: "linear", count: 3, interval: 10000, response_status_codes: ["500-599", "429", "408"] }],
59+
});
60+
if (!conn.body.id) {
61+
console.log("PROVISION FAILED", conn.status, JSON.stringify(conn.body).slice(0, 300));
62+
process.exit(1);
63+
}
64+
const CONNECTION_ID = conn.body.id;
65+
const SOURCE_URL = (await api("GET", `/sources?name=${NAME}`)).body.models[0].url;
66+
console.log(`provisioned ${CONNECTION_ID} ${SOURCE_URL}\n`);
67+
68+
// ------------------------------------------------------------------ gateway
69+
rmSync(ROOT, { recursive: true, force: true });
70+
mkdirSync(`${ROOT}/state`, { recursive: true });
71+
const config = {
72+
gateway: { mode: "local", bind: "loopback", port: PORT },
73+
plugins: {
74+
load: { paths: [REPO] },
75+
entries: {
76+
hookdeck: {
77+
enabled: true,
78+
config: {
79+
signingSecret: SECRET,
80+
apiKey: KEY,
81+
ingress: { basePath: "/hookdeck" },
82+
maxConcurrent: 4,
83+
transport: { mode: "cli", port: PORT, binaryPath: "/usr/local/bin/hookdeck" },
84+
provisioning: { enabled: false },
85+
catchUp: { enabled: true, minGapSeconds: 1 },
86+
routes: {
87+
e2e: {
88+
source: NAME,
89+
path: "/e2e",
90+
connectionId: CONNECTION_ID,
91+
dispatch: { mode: "wake", sessionKey: "main", text: "E2E {eventId}" },
92+
},
93+
},
94+
},
95+
},
96+
},
97+
},
98+
};
99+
writeFileSync(`${ROOT}/openclaw.json`, JSON.stringify(config, null, 2));
100+
101+
let gw;
102+
const startGateway = async (label) => {
103+
gw = spawn(`${REPO}/node_modules/.bin/openclaw`, ["gateway", "--allow-unconfigured"], {
104+
env: { ...process.env, OPENCLAW_CONFIG_PATH: `${ROOT}/openclaw.json`, OPENCLAW_STATE_DIR: `${ROOT}/state` },
105+
stdio: ["ignore", "pipe", "pipe"],
106+
});
107+
const log = [];
108+
gw.stdout.on("data", (d) => log.push(String(d)));
109+
gw.stderr.on("data", (d) => log.push(String(d)));
110+
gw.log = log;
111+
for (let i = 0; i < 40; i += 1) {
112+
await sleep(1000);
113+
if (log.join("").includes("tunnel connected")) break;
114+
}
115+
console.log(` [${label}] gateway up, tunnel ${log.join("").includes("tunnel connected") ? "connected" : "NOT connected"}`);
116+
return log;
117+
};
118+
119+
const send = async (payload) =>
120+
(await fetch(SOURCE_URL, {
121+
method: "POST",
122+
headers: { "content-type": "application/json" },
123+
body: typeof payload === "string" ? payload : JSON.stringify(payload),
124+
})).status;
125+
126+
const ledger = () => {
127+
const f = `${ROOT}/state/hookdeck/ledger.jsonl`;
128+
if (!existsSync(f)) return [];
129+
// Last-write-wins, as the store does. The append-only log keeps superseded
130+
// rows, so reading it raw counts a settled row as still running.
131+
const byId = new Map();
132+
for (const line of readFileSync(f, "utf8").trim().split("\n").filter(Boolean)) {
133+
const row = JSON.parse(line).d;
134+
byId.set(row.eventId, row);
135+
}
136+
return [...byId.values()];
137+
};
138+
const rowFor = (id) => ledger().filter((r) => r.eventId === id).at(-1);
139+
140+
const eventsForConnection = async () =>
141+
(await api("GET", `/events?webhook_id=${CONNECTION_ID}&limit=50`)).body.models ?? [];
142+
143+
// =========================================================== 1. core delivery
144+
let log = await startGateway("boot");
145+
const t1 = Date.now();
146+
await send({ scenario: "core", run: RUN });
147+
await sleep(8000);
148+
149+
let evs = await eventsForConnection();
150+
const core = evs.find((e) => e.created_at > new Date(t1 - 5000).toISOString());
151+
record(
152+
"a real signed delivery is verified and dispatched",
153+
core?.status === "SUCCESSFUL" && core?.response_status === 200,
154+
`hookdeck says ${core?.status}/${core?.response_status}`,
155+
);
156+
record(
157+
"the ledger records it as succeeded",
158+
rowFor(core?.id)?.status === "succeeded",
159+
`row=${JSON.stringify(rowFor(core?.id) ?? null)?.slice(0, 90)}`,
160+
);
161+
162+
// ====================================================== 2. manual retry (MANUAL)
163+
await api("POST", `/events/${core.id}/retry`);
164+
await sleep(8000);
165+
const afterRetry = rowFor(core.id);
166+
record(
167+
"a manual retry is admitted, not suppressed as a duplicate",
168+
afterRetry?.attempt >= 2 && afterRetry?.runCount >= 2,
169+
`attempt=${afterRetry?.attempt} runs=${afterRetry?.runCount}`,
170+
);
171+
172+
// ============================================================ 3. malformed body
173+
// Hookdeck screens this at the edge — 400 UNPARSABLE_JSON, no event created —
174+
// so the plugin's own malformed_json handling is never reached by a JSON-typed
175+
// source. Asserting what actually happens rather than what we assumed.
176+
const t3 = Date.now();
177+
const edge = await send("{not json");
178+
await sleep(6000);
179+
const reqs = (await api("GET", `/requests?limit=10`)).body.models ?? [];
180+
const rejected = reqs.find(
181+
(r) => r.ingested_at > new Date(t3 - 3000).toISOString() && r.rejection_cause,
182+
);
183+
record(
184+
"Hookdeck rejects a malformed body at the edge, before any delivery",
185+
edge === 400 && rejected?.rejection_cause === "UNPARSABLE_JSON",
186+
`edge answered ${edge}, request rejection_cause=${rejected?.rejection_cause}`,
187+
);
188+
record(
189+
"and creates no event, so nothing reaches the gateway",
190+
(rejected?.events_count ?? 0) === 0,
191+
`events_count=${rejected?.events_count}`,
192+
);
193+
194+
// ================================================= 4. catch-up after an outage
195+
// Kill the Gateway so the tunnel drops, send while nothing is listening, restart.
196+
gw.kill("SIGKILL");
197+
await sleep(3000);
198+
const t4 = Date.now();
199+
await send({ scenario: "catchup", run: RUN });
200+
await sleep(6000);
201+
const duringOutage = (await api("GET", `/requests?limit=20`)).body.models ?? [];
202+
const stranded = duringOutage.find(
203+
(r) => r.ingested_at > new Date(t4 - 3000).toISOString() && (r.events_count ?? 0) === 0,
204+
);
205+
record(
206+
"an event arriving with no tunnel is stranded rather than delivered",
207+
stranded !== undefined,
208+
stranded ? `request ${stranded.id} produced ${stranded.events_count} events` : "no stranded request found",
209+
);
210+
211+
log = await startGateway("restart");
212+
await sleep(20000);
213+
const catchUpLog = log.join("");
214+
record(
215+
"catch-up replay is issued on reconnect",
216+
/catch-up replay queued/.test(catchUpLog),
217+
(catchUpLog.match(/catch-up replay queued[^\n]*/) ?? ["not in log"])[0].slice(0, 80),
218+
);
219+
220+
// ======================================================== 5. crash recovery
221+
const t5 = Date.now();
222+
await send({ scenario: "crash", run: RUN });
223+
await sleep(2500);
224+
gw.kill("SIGKILL"); // mid-flight, before the row can settle
225+
await sleep(2000);
226+
const beforeRestart = ledger().filter((r) => r.status === "running");
227+
log = await startGateway("recovery");
228+
await sleep(8000);
229+
const recoveryLog = log.join("");
230+
record(
231+
"a crash mid-dispatch leaves a running row that recovery settles",
232+
beforeRestart.length === 0 || /reconciling \d+ interrupted/.test(recoveryLog),
233+
beforeRestart.length === 0
234+
? "no row was left running (dispatch completed first)"
235+
: (recoveryLog.match(/reconciling [^\n]*/) ?? ["not reconciled"])[0].slice(0, 70),
236+
);
237+
238+
// ============================================================== 6. the doctor
239+
const doctor = await execFileAsync(
240+
`${REPO}/node_modules/.bin/openclaw`,
241+
["agent", "--local", "--session-key", "e2e", "-m", "Call hookdeck_doctor and print its raw JSON.", "--model", "anthropic/claude-haiku-4-5"],
242+
{ env: { ...process.env, OPENCLAW_CONFIG_PATH: `${ROOT}/openclaw.json`, OPENCLAW_STATE_DIR: `${ROOT}/state`,
243+
ANTHROPIC_API_KEY: (/^AGENT_TEST_ANTHROPIC_API_KEY=(.+)$/m.exec(readFileSync(`${REPO}/.env.local`, "utf8")) ?? [,""])[1]?.trim() },
244+
maxBuffer: 10 * 1024 * 1024 },
245+
).catch((e) => ({ stdout: String(e.stdout ?? e.message) }));
246+
const doctorOut = doctor.stdout ?? "";
247+
record(
248+
"doctor reports the project match against the real project",
249+
/both tm_/.test(doctorOut) || /cli\/api-key project/.test(doctorOut),
250+
(doctorOut.match(/both tm_[A-Za-z0-9]+/) ?? ["see output"])[0],
251+
);
252+
record(
253+
"doctor reports provider verification from real inbound requests",
254+
/provider verification/i.test(doctorOut),
255+
(doctorOut.match(/UNVERIFIED[^"]{0,60}/) ?? doctorOut.match(/were verified[^"]{0,20}/) ?? ["not reported"])[0].slice(0, 70),
256+
);
257+
258+
// ================================================================== teardown
259+
gw?.kill("SIGKILL");
260+
console.log("\n--- teardown ---");
261+
for (const kind of ["connections", "sources", "destinations"]) {
262+
const list = (await api("GET", `/${kind}?limit=255`)).body.models ?? [];
263+
for (const item of list.filter((m) => String(m.name).startsWith("openclaw-e2e-"))) {
264+
const d = await api("DELETE", `/${kind}/${item.id}`);
265+
console.log(` deleted ${kind}/${item.id} (${item.name}) ${d.status}`);
266+
}
267+
}
268+
rmSync(ROOT, { recursive: true, force: true });
269+
270+
console.log("\n=============================================");
271+
console.log(`${results.filter((r) => r.pass).length}/${results.length} scenarios passed`);
272+
for (const r of results.filter((r) => !r.pass)) console.log(` FAILED: ${r.name}${r.detail}`);
273+
process.exit(0);

src/hookdeck/client.ts

Lines changed: 1 addition & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -224,10 +224,7 @@ export interface HookdeckClient {
224224
* over the API — the secret is never returned — so `verified` on the requests
225225
* that actually arrived is the only signal there is.
226226
*/
227-
listRequests(params?: {
228-
limit?: number;
229-
sourceId?: string;
230-
}): Promise<
227+
listRequests(params?: { limit?: number; sourceId?: string }): Promise<
231228
ApiResult<
232229
{
233230
id: string;

src/plugin/config-parse.ts

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -134,8 +134,9 @@ const configSchema = z.object({
134134
.object({
135135
enabled: z.boolean().default(true),
136136
minGapSeconds: z.number().int().nonnegative().max(86_400).default(30),
137+
heartbeatSeconds: z.number().int().positive().max(3600).default(30),
137138
})
138-
.default({ enabled: true, minGapSeconds: 30 }),
139+
.default({ enabled: true, minGapSeconds: 30, heartbeatSeconds: 30 }),
139140
ingress: z
140141
.object({ basePath: z.string().min(1).default("/hookdeck") })
141142
.default({ basePath: "/hookdeck" }),
@@ -413,6 +414,7 @@ export function parseHookdeckConfig(raw: unknown): ConfigParseResult {
413414
catchUp: {
414415
enabled: value.catchUp.enabled,
415416
minGapSeconds: value.catchUp.minGapSeconds,
417+
heartbeatSeconds: value.catchUp.heartbeatSeconds,
416418
},
417419
safety: { allowRetryCancel: value.safety.allowRetryCancel },
418420
routes,

src/plugin/config-types.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -189,6 +189,8 @@ export interface CatchUpConfig {
189189
enabled: boolean;
190190
/** Below this, an outage is not worth a bulk replay. */
191191
minGapSeconds: number;
192+
/** How often to record that this process is alive, so a crash is detectable. */
193+
heartbeatSeconds: number;
192194
}
193195

194196
export interface HookdeckPluginConfig {

src/store/cursor-store.ts

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,16 @@ export interface CursorRecord {
3535
* treated as `shutdown` to preserve the original behaviour.
3636
*/
3737
pauseReason?: "shutdown" | "operator";
38+
/**
39+
* Last time this process was known to be running and forwarding.
40+
*
41+
* Written periodically and cleared on a clean shutdown, so finding one at
42+
* startup means the previous process died without running its teardown —
43+
* a `kill -9`, an OOM kill, a power cut. That is the outage most in need of
44+
* catch-up, and the one where nothing else records a disconnect, because the
45+
* handler that would have done so died with the process.
46+
*/
47+
lastSeenAt?: number;
3848
provisioningFingerprint?: string;
3949
connectionId?: string;
4050
updatedAt: number;

0 commit comments

Comments
 (0)