Skip to content

Commit f3d9d79

Browse files
1stvampTrigger.dev RepoOps
authored andcommitted
fix(supervisor): notice an informer watch that stalls without closing
Supervisor: detect a Kubernetes informer watch that stalls without closing, or whose response never starts, and reconnect it. This covers the failed pod handler and the restore informer. Mono-RevId: c8ba684e2ffb6b4e361f8f99223d71418c6171ba
1 parent 10b9960 commit f3d9d79

11 files changed

Lines changed: 428 additions & 25 deletions

File tree

Lines changed: 175 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,175 @@
1+
import { createServer, type IncomingMessage, type ServerResponse } from "node:http";
2+
import type { AddressInfo } from "node:net";
3+
import { afterEach, describe, expect, it, vi } from "vitest";
4+
import { type KubeConfig, type KubernetesObject, ListWatch, Watch } from "@kubernetes/client-node";
5+
import { SimpleStructuredLogger } from "@trigger.dev/core/v3/utils/structuredLogger";
6+
import { ReconnectingInformer } from "./reconnectingInformer.js";
7+
8+
describe("ReconnectingInformer watch stalls", () => {
9+
afterEach(() => {
10+
vi.useRealTimers();
11+
});
12+
13+
type WatchCall = { path: string; done: (err: unknown) => void; aborted: boolean };
14+
15+
function makeInformer(
16+
watch: Pick<Watch, "watch">,
17+
opts: { watchTimeoutSeconds?: number; onStall?: (quietMs: number) => void } = {}
18+
) {
19+
return new ReconnectingInformer<KubernetesObject>({
20+
name: "test-informer",
21+
logger: new SimpleStructuredLogger("test-informer"),
22+
reconnectIntervalMs: 1,
23+
path: "/api/v1/namespaces/v4-runs/pods",
24+
list: async () => ({ items: [], metadata: { resourceVersion: "1" } }),
25+
makeInformer: (path, list) => new ListWatch(path, watch as Watch, list, false),
26+
...opts,
27+
});
28+
}
29+
30+
/** A fake Watch that stays silent until told otherwise. */
31+
function setup(opts: Parameters<typeof makeInformer>[1] = { watchTimeoutSeconds: 300 }) {
32+
const calls: WatchCall[] = [];
33+
const watch = {
34+
watch: vi.fn(
35+
async (path: string, _query: unknown, _callback: unknown, done: WatchCall["done"]) => {
36+
const call: WatchCall = { path, done, aborted: false };
37+
calls.push(call);
38+
return { abort: () => (call.aborted = true) } as unknown as AbortController;
39+
}
40+
),
41+
};
42+
return { calls, informer: makeInformer(watch, opts) };
43+
}
44+
45+
it("asks the server to close each watch at the timeout", async () => {
46+
const { calls, informer } = setup();
47+
await informer.start();
48+
49+
expect(calls[0]!.path).toBe("/api/v1/namespaces/v4-runs/pods?timeoutSeconds=300");
50+
await informer.stop();
51+
});
52+
53+
// A connection that died without closing raises nothing on its own.
54+
it("reconnects a watch that neither delivers nor closes past the timeout", async () => {
55+
vi.useFakeTimers({ toFake: ["setInterval", "clearInterval", "Date"] });
56+
const onStall = vi.fn();
57+
const { calls, informer } = setup({ watchTimeoutSeconds: 300, onStall });
58+
await informer.start();
59+
60+
await vi.advanceTimersByTimeAsync(300_000);
61+
expect(calls).toHaveLength(1);
62+
63+
// The check runs every 30 s, so the first past 330 s quiet is at 360 s.
64+
await vi.advanceTimersByTimeAsync(60_000);
65+
await vi.waitFor(() => expect(calls).toHaveLength(2));
66+
expect(calls[0]!.aborted).toBe(true);
67+
expect(onStall).toHaveBeenCalledOnce();
68+
await informer.stop();
69+
});
70+
71+
it("leaves alone a watch the server closes and the client renews", async () => {
72+
vi.useFakeTimers({ toFake: ["setInterval", "clearInterval", "Date"] });
73+
const onStall = vi.fn();
74+
const { calls, informer } = setup({ watchTimeoutSeconds: 300, onStall });
75+
await informer.start();
76+
77+
for (let i = 1; i <= 3; i++) {
78+
await vi.advanceTimersByTimeAsync(300_000);
79+
calls.at(-1)!.done(null);
80+
await vi.waitFor(() => expect(calls).toHaveLength(i + 1));
81+
}
82+
await vi.advanceTimersByTimeAsync(60_000);
83+
84+
expect(calls).toHaveLength(4);
85+
expect(onStall).not.toHaveBeenCalled();
86+
await informer.stop();
87+
});
88+
89+
it("sets no timeout and checks nothing without a watch timeout", async () => {
90+
vi.useFakeTimers({ toFake: ["setInterval", "clearInterval", "Date"] });
91+
const { calls, informer } = setup({});
92+
await informer.start();
93+
94+
await vi.advanceTimersByTimeAsync(3_600_000);
95+
96+
expect(calls).toHaveLength(1);
97+
expect(calls[0]!.path).toBe("/api/v1/namespaces/v4-runs/pods");
98+
await informer.stop();
99+
});
100+
101+
/** Polls on real timers, which the fake ones in these tests leave alone. */
102+
async function realTimeUntil(condition: () => boolean) {
103+
for (let i = 0; i < 400 && !condition(); i++) {
104+
await new Promise((resolve) => setTimeout(resolve, 5));
105+
}
106+
expect(condition()).toBe(true);
107+
}
108+
109+
/** A real client Watch against a local API server that answers each watch as told. */
110+
async function realWatch(answer: (n: number, res: ServerResponse) => void) {
111+
const watches: IncomingMessage[] = [];
112+
const server = createServer((req, res) => {
113+
watches.push(req);
114+
answer(watches.length, res);
115+
});
116+
await new Promise<void>((resolve) => server.listen(0, "127.0.0.1", resolve));
117+
// A KubeConfig always fetches through an https agent; this is plain http.
118+
const url = `http://127.0.0.1:${(server.address() as AddressInfo).port}`;
119+
const kc = {
120+
getCurrentCluster: () => ({ server: url }),
121+
applyToFetchOptions: async () => ({}),
122+
} as unknown as KubeConfig;
123+
const close = () =>
124+
new Promise<void>((resolve) => {
125+
server.closeAllConnections();
126+
server.close(() => resolve());
127+
});
128+
return { watch: new Watch(kc), watches, close };
129+
}
130+
131+
// The client only returns the request's controller once the headers arrive.
132+
it("aborts a watch whose headers never arrive", async () => {
133+
const before = Watch.HEADERS_TIMEOUT_MS;
134+
Watch.HEADERS_TIMEOUT_MS = 50;
135+
const { watch, close } = await realWatch(() => {});
136+
try {
137+
const done = vi.fn();
138+
await watch.watch("/api/v1/pods", {}, () => {}, done);
139+
expect(done).toHaveBeenCalledWith(expect.objectContaining({ name: "AbortError" }));
140+
} finally {
141+
Watch.HEADERS_TIMEOUT_MS = before;
142+
await close();
143+
}
144+
});
145+
146+
// The stall's reconnect meets a blackholed connection too: it must give up on
147+
// it rather than hold the reconnect guard, and watch again.
148+
it("recovers when the reconnect after a stall never gets its headers", async () => {
149+
const before = Watch.HEADERS_TIMEOUT_MS;
150+
Watch.HEADERS_TIMEOUT_MS = 50;
151+
vi.useFakeTimers({ toFake: ["setInterval", "clearInterval", "Date"] });
152+
// The first watch connects and goes silent, the second never answers, the third connects.
153+
const { watch, watches, close } = await realWatch((n, res) => {
154+
if (n !== 2) {
155+
res.writeHead(200, { "content-type": "application/json" });
156+
res.flushHeaders();
157+
}
158+
});
159+
const informer = makeInformer(watch, { watchTimeoutSeconds: 300 });
160+
const reconnecting = () => (informer as unknown as { reconnecting: boolean }).reconnecting;
161+
try {
162+
await informer.start();
163+
await vi.waitFor(() => expect(watches).toHaveLength(1));
164+
165+
await vi.advanceTimersByTimeAsync(360_000);
166+
// The second watch's header timeout runs on real time; only once it fires
167+
// does the reconnect watch a third time and settle.
168+
await realTimeUntil(() => watches.length === 3 && !reconnecting());
169+
} finally {
170+
await informer.stop();
171+
Watch.HEADERS_TIMEOUT_MS = before;
172+
await close();
173+
}
174+
});
175+
});

‎apps/supervisor/src/clients/reconnectingInformer.ts‎

Lines changed: 87 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -4,21 +4,40 @@ import type { SimpleStructuredLogger } from "@trigger.dev/core/v3/utils/structur
44

55
const MAX_RECONNECT_BACKOFF_MS = 30_000;
66

7+
// Past the server closing the watch at its timeout, how long to wait for the
8+
// client to watch again before taking the watch for stalled.
9+
const WATCH_STALL_GRACE_MS = 30_000;
10+
711
type ReconnectingInformerOptions<T extends KubernetesObject> = {
812
/** Used in log fields, to tell informers apart. */
913
name: string;
1014
logger: SimpleStructuredLogger;
1115
reconnectIntervalMs: number;
16+
/** The watch path, which gets the timeout as a query parameter. */
17+
path: string;
1218
list: ListPromise<T>;
13-
/** Builds the informer around the list it is given, which wraps `list`. */
14-
makeInformer: (list: ListPromise<T>) => ListWatch<T>;
19+
/** Builds the informer around the path and list it is given, which wraps `list`. */
20+
makeInformer: (path: string, list: ListPromise<T>) => ListWatch<T>;
1521
/** Called for every error the informer raises, before any reconnect. */
1622
onError?: (err: unknown) => void;
23+
/**
24+
* How long the server keeps each watch open before closing it. A watch that has
25+
* neither connected nor delivered an event for this plus 30 s is taken as
26+
* stalled. Without it, a watch has no timeout and is never checked.
27+
*/
28+
watchTimeoutSeconds?: number;
29+
/** Called when the stall check takes the watch for stalled, before it reconnects. */
30+
onStall?: (quietMs: number) => void;
1731
};
1832

1933
/**
2034
* An informer that reconnects with a capped backoff until a start succeeds, for
2135
* as long as it runs. The client's own error handling gives up after one failure.
36+
*
37+
* A connection that died without closing (a dropped NAT entry, a blackholed load
38+
* balancer) raises nothing. With a watch timeout, the server closes each watch
39+
* and the client watches again, so a healthy watch connects at least that often,
40+
* and a stall check reconnects one that goes quiet for longer.
2241
*/
2342
export class ReconnectingInformer<T extends KubernetesObject> {
2443
readonly informer: ListWatch<T>;
@@ -27,6 +46,10 @@ export class ReconnectingInformer<T extends KubernetesObject> {
2746
private readonly reconnectIntervalMs: number;
2847
private readonly listFn: ListPromise<T>;
2948
private readonly onErrorHook?: (err: unknown) => void;
49+
private readonly onStallHook?: (quietMs: number) => void;
50+
private readonly watchTimeoutMs?: number;
51+
private lastWatchActivityAt = 0;
52+
private stallCheck?: NodeJS.Timeout;
3053
private running = false;
3154
private reconnecting = false;
3255
private erroredDuringReconnect = false;
@@ -39,8 +62,19 @@ export class ReconnectingInformer<T extends KubernetesObject> {
3962
this.reconnectIntervalMs = opts.reconnectIntervalMs;
4063
this.listFn = opts.list;
4164
this.onErrorHook = opts.onError;
42-
this.informer = opts.makeInformer(() => this.list());
65+
this.onStallHook = opts.onStall;
66+
this.watchTimeoutMs =
67+
opts.watchTimeoutSeconds === undefined ? undefined : opts.watchTimeoutSeconds * 1000;
68+
const path =
69+
opts.watchTimeoutSeconds === undefined
70+
? opts.path
71+
: `${opts.path}?timeoutSeconds=${opts.watchTimeoutSeconds}`;
72+
this.informer = opts.makeInformer(path, () => this.list());
4373
this.informer.on("error", (err?: unknown) => void this.onError(err));
74+
this.informer.on("connect", () => this.markWatchActivity());
75+
this.informer.on("add", () => this.markWatchActivity());
76+
this.informer.on("update", () => this.markWatchActivity());
77+
this.informer.on("delete", () => this.markWatchActivity());
4478
}
4579

4680
get isRunning(): boolean {
@@ -53,17 +87,57 @@ export class ReconnectingInformer<T extends KubernetesObject> {
5387
return;
5488
}
5589
this.running = true;
56-
await this.startInformer();
90+
if (this.watchTimeoutMs !== undefined) {
91+
this.markWatchActivity();
92+
// Installed first, so a first watch that never comes up is covered too.
93+
this.stallCheck = setInterval(
94+
() => void this.checkWatchStalled(),
95+
Math.min(WATCH_STALL_GRACE_MS, this.watchTimeoutMs)
96+
);
97+
this.stallCheck.unref();
98+
}
99+
try {
100+
await this.startInformer();
101+
} catch (err: unknown) {
102+
clearInterval(this.stallCheck);
103+
throw err;
104+
}
57105
}
58106

59107
async stop() {
60108
if (!this.running) {
61109
return;
62110
}
63111
this.running = false;
112+
clearInterval(this.stallCheck);
64113
await this.informer.stop();
65114
}
66115

116+
private markWatchActivity() {
117+
this.lastWatchActivityAt = Date.now();
118+
}
119+
120+
/**
121+
* Skips while a reconnect runs: a reconnect into a blackholed connection ends
122+
* once the client's header timeout aborts it, and the next check retries.
123+
*/
124+
private async checkWatchStalled() {
125+
const quietMs = Date.now() - this.lastWatchActivityAt;
126+
if (
127+
!this.running ||
128+
this.reconnecting ||
129+
this.watchTimeoutMs === undefined ||
130+
quietMs <= this.watchTimeoutMs + WATCH_STALL_GRACE_MS
131+
) {
132+
return;
133+
}
134+
this.onStallHook?.(quietMs);
135+
this.markWatchActivity();
136+
await this.informer.stop();
137+
// The stopped request's own error arrives while this reconnect waits, and is skipped.
138+
await this.reconnect(new Error("watch stalled"));
139+
}
140+
67141
/**
68142
* The client relists on its own after a 410 and leaves that list's rejection
69143
* unhandled, so a failure there becomes a reconnect and the abandoned relist
@@ -100,15 +174,22 @@ export class ReconnectingInformer<T extends KubernetesObject> {
100174
}
101175
}
102176

177+
private async onError(err: unknown) {
178+
if (!this.running) {
179+
return;
180+
}
181+
this.onErrorHook?.(err);
182+
await this.reconnect(err);
183+
}
184+
103185
/**
104186
* Retries until a start ends with no error raised during it. A watch that
105187
* fails to connect raises its error inside the start, which still resolves.
106188
*/
107-
private async onError(err: unknown) {
189+
private async reconnect(err: unknown) {
108190
if (!this.running) {
109191
return;
110192
}
111-
this.onErrorHook?.(err);
112193
if (this.reconnecting) {
113194
this.erroredDuringReconnect = true;
114195
return;

‎apps/supervisor/src/env.ts‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -352,6 +352,7 @@ export const Env = z
352352
// Failed pod handler
353353
FAILED_POD_HANDLER_ENABLED: BoolEnv.default(true),
354354
FAILED_POD_HANDLER_RECONNECT_INTERVAL_MS: z.coerce.number().int().default(1000),
355+
FAILED_POD_HANDLER_WATCH_TIMEOUT_SECONDS: z.coerce.number().int().positive().default(300),
355356

356357
// Debug
357358
DEBUG: BoolEnv.default(false),

‎apps/supervisor/src/index.ts‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -292,6 +292,7 @@ class ManagedSupervisor {
292292
register,
293293
namespace: env.KUBERNETES_NAMESPACE,
294294
reconnectIntervalMs: env.FAILED_POD_HANDLER_RECONNECT_INTERVAL_MS,
295+
watchTimeoutSeconds: env.FAILED_POD_HANDLER_WATCH_TIMEOUT_SECONDS,
295296
});
296297
} else {
297298
this.logger.warn("Failed pod handler disabled");

0 commit comments

Comments
 (0)