Skip to content

Commit eb3e650

Browse files
fix(core): clear the health-check timeout guard when the race settles (#4875) (#4950)
`PluginHealthMonitor.performHealthCheck()` armed its timeout guard via the private `timeout()` helper and then abandoned it: when the plugin's `checkMethod` won the race, the `setTimeout` stayed ref'd in the event loop for the full `config.timeout`. Same leak as the kernel's init/start guards (#4813, PR #4874), with one aggravating difference — health checks are periodic, so the orphans accumulate one per plugin per round instead of being a fixed cost paid once at boot. Replaces `timeout()` with `raceCheckTimeout()`, the same shape and the same reasoning as `ObjectKernel.raceStartupTimeout()`: `try { await Promise.race(...) } finally { clearTimeout(guard) }`. Not `unref()` — an unref'd guard stops pinning the loop but also stops being a guard, so a check that never settles is silently dropped instead of reported. Regression tests: no ref'd timer survives a check that wins the race, no guard accumulates across periodic rounds (counted under fake timers, which also sees an `unref()`'d timer and so rejects a fake fix), and the timeout is still reported when the check genuinely hangs. Claude-Session: https://claude.ai/code/session_01NrmBxj8rK2uGCnh9aipjwX Co-authored-by: Claude <noreply@anthropic.com>
1 parent f61c8cf commit eb3e650

3 files changed

Lines changed: 209 additions & 9 deletions

File tree

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,28 @@
1+
---
2+
'@objectstack/core': patch
3+
---
4+
5+
fix(core): 健康检查的超时守卫在 race 落定时被清除,周期性检查不再堆积孤儿定时器 (#4875)
6+
7+
`PluginHealthMonitor.performHealthCheck()` 里那条 race 的守卫由 `timeout()` armed 之后就被
8+
扔掉:插件的 `checkMethod` 赢下 race 之后,那根 `setTimeout` 既没 `clearTimeout` 也没
9+
`unref()`,带着 ref 一直挂满整个 `config.timeout`。这与 #4813 修掉的两处(内核 init/start
10+
守卫,PR #4874)是同一种漏法。
11+
12+
差别在于**健康检查是周期性的**:内核那两处是启动时一次性的固定份额(4 个插件 = 8 根),这里
13+
则是**每个插件每一轮各留一根**,`interval` 越密、`timeout` 越长,堆得越高 —— 一个
14+
`interval: 30s` / `timeout: 5s` 的插件在任意时刻都挂着若干根本该在毫秒级就回收的定时器。
15+
今天这条还没发作,只是因为 `startMonitoring()` 目前没有被内核启动流程调用;一旦健康监控被接进
16+
宿主,它就是 #4813 的放大版。
17+
18+
修法与 #4874 同形:`timeout()` 换成私有 helper `raceCheckTimeout()`,`try { await
19+
Promise.race(...) } finally { clearTimeout(guard) }`。
20+
21+
**为什么是 `clearTimeout` 而不是 `unref()`** `unref()` 让定时器不再钉住事件循环的同时,
22+
也让它不再是一个守卫 —— 若检查永不 settle 且没有别的东西撑着事件循环,Node 会在定时器触发
23+
之前退出,超时被静默吞掉。守卫必须在 race 未决期间保持 ref'd、在落定那一刻被回收,这正是
24+
`finally { clearTimeout(guard) }` 表达的语义。回归测试因此是三条:守卫赢不了时不留 ref'd
25+
定时器、连跑多轮不累积(fake timers 下计数,能识破 `unref()` 式的假修复)、以及检查真的挂住时
26+
超时照常上报。
27+
28+
超时时长(`config.timeout`)一个都没动 —— 问题从来不在时长,而在没人回收。

packages/core/src/health-monitor.test.ts

Lines changed: 140 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
1-
import { describe, it, expect, beforeEach } from 'vitest';
1+
import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
22
import { PluginHealthMonitor } from './health-monitor.js';
33
import { createLogger } from './logger.js';
4+
import type { Plugin } from './types.js';
45
import type { PluginHealthCheck } from '@objectstack/spec/kernel';
56

67
describe('PluginHealthMonitor', () => {
@@ -75,7 +76,144 @@ describe('PluginHealthMonitor', () => {
7576

7677
monitor.registerPlugin('test-plugin', config);
7778
monitor.shutdown();
78-
79+
7980
expect(monitor.getAllHealthStatuses().size).toBe(0);
8081
});
82+
83+
// #4875 — the health-check timeout guard must not outlive the race it guards.
84+
//
85+
// Same shape as the kernel's startup guards (#4813, PR #4874), with one
86+
// aggravating difference: health checks are *periodic*, so an abandoned
87+
// guard is not a fixed cost paid once at boot — it is one orphaned timer per
88+
// plugin per round, each pinning the event loop for a whole `config.timeout`.
89+
//
90+
// What follows asserts the observable consequence, never the source:
91+
// "health-monitor.ts calls clearTimeout" is a tautology any refactor could
92+
// satisfy while still leaving the loop pinned.
93+
describe('Health-check timeout guard does not outlive the race (#4875)', () => {
94+
/** A guard long enough that a single orphan is unmistakable. */
95+
const guardedConfig = (overrides: Partial<PluginHealthCheck> = {}): PluginHealthCheck => ({
96+
interval: 30_000,
97+
timeout: 120_000,
98+
failureThreshold: 3,
99+
successThreshold: 1,
100+
autoRestart: false,
101+
maxRestartAttempts: 3,
102+
restartBackoff: 'fixed',
103+
checkMethod: 'healthCheck',
104+
...overrides,
105+
});
106+
107+
/** A plugin whose custom health check answers immediately (wins the race). */
108+
const healthyPlugin = (calls: { count: number }): Plugin =>
109+
({
110+
name: 'guarded-plugin',
111+
version: '1.0.0',
112+
init: () => {},
113+
healthCheck: async () => {
114+
calls.count++;
115+
return true;
116+
},
117+
}) as unknown as Plugin;
118+
119+
/**
120+
* Ref'd `Timeout` handles — `getActiveResourcesInfo()` reports only
121+
* resources currently keeping the event loop alive, which is exactly the
122+
* property that made `os migrate` idle ~120s in #4813.
123+
*/
124+
const refdTimers = () =>
125+
process.getActiveResourcesInfo().filter((r) => r === 'Timeout').length;
126+
127+
it("leaves no ref'd timer behind when the health check wins the race", async () => {
128+
const calls = { count: 0 };
129+
monitor.registerPlugin('guarded-plugin', guardedConfig());
130+
131+
const before = refdTimers();
132+
monitor.startMonitoring('guarded-plugin', healthyPlugin(calls));
133+
134+
// The initial check runs immediately; wait for its report to land.
135+
await vi.waitFor(() => {
136+
expect(monitor.getHealthReport('guarded-plugin')).toBeDefined();
137+
});
138+
139+
// Drop the monitoring interval — whatever is left is the guard's doing.
140+
monitor.stopMonitoring('guarded-plugin');
141+
142+
expect(calls.count).toBe(1);
143+
expect(monitor.getHealthStatus('guarded-plugin')).toBe('healthy');
144+
expect(refdTimers()).toBe(before);
145+
});
146+
147+
it('still reports the timeout when the check never answers', async () => {
148+
// The companion assertion: reclaiming the guard must not disarm it.
149+
// `unref()` would satisfy "no ref'd timer" by detaching the guard from
150+
// the loop — a process with nothing else to run then exits *silently*
151+
// instead of reporting the timeout. Clearing on settle keeps the guard
152+
// armed exactly while the race is undecided.
153+
let release: () => void = () => {};
154+
const hangingPlugin = {
155+
name: 'hanging-plugin',
156+
version: '1.0.0',
157+
init: () => {},
158+
healthCheck: () =>
159+
new Promise((resolve) => {
160+
release = () => resolve(true);
161+
}),
162+
} as unknown as Plugin;
163+
164+
monitor.registerPlugin('hanging-plugin', guardedConfig({ timeout: 100 }));
165+
monitor.startMonitoring('hanging-plugin', hangingPlugin);
166+
167+
await vi.waitFor(() => {
168+
expect(monitor.getHealthStatus('hanging-plugin')).toBe('failed');
169+
});
170+
171+
expect(monitor.getHealthReport('hanging-plugin')?.message).toBe(
172+
'Health check timeout after 100ms'
173+
);
174+
175+
monitor.stopMonitoring('hanging-plugin');
176+
release();
177+
});
178+
179+
describe('under fake timers', () => {
180+
beforeEach(() => {
181+
vi.useFakeTimers();
182+
});
183+
184+
afterEach(() => {
185+
vi.useRealTimers();
186+
});
187+
188+
it('accumulates no guard across periodic rounds', async () => {
189+
const calls = { count: 0 };
190+
const config = guardedConfig({ interval: 1_000 });
191+
monitor.registerPlugin('guarded-plugin', config);
192+
193+
const before = vi.getTimerCount();
194+
monitor.startMonitoring('guarded-plugin', healthyPlugin(calls));
195+
196+
// Flush the initial check without letting the interval or the guard fire.
197+
await vi.advanceTimersByTimeAsync(0);
198+
expect(calls.count).toBe(1);
199+
200+
// Unlike `getActiveResourcesInfo()`, the fake-timer count still sees
201+
// an `unref()`'d timer — so this distinguishes "the guard was
202+
// reclaimed" from "the guard was merely detached from the loop".
203+
const settled = vi.getTimerCount();
204+
expect(settled).toBe(before + 1); // the monitoring interval, and nothing else
205+
206+
// Periodic checks are where this leak compounds: one orphan per round.
207+
for (let round = 0; round < 5; round++) {
208+
await vi.advanceTimersByTimeAsync(config.interval);
209+
}
210+
211+
expect(calls.count).toBe(6);
212+
expect(vi.getTimerCount()).toBe(settled);
213+
214+
monitor.stopMonitoring('guarded-plugin');
215+
expect(vi.getTimerCount()).toBe(before);
216+
});
217+
});
218+
});
81219
});

packages/core/src/health-monitor.ts

Lines changed: 41 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -107,10 +107,11 @@ export class PluginHealthMonitor {
107107
try {
108108
// Check if plugin has a custom health check method
109109
if (config.checkMethod && typeof (plugin as any)[config.checkMethod] === 'function') {
110-
const checkResult = await Promise.race([
110+
const checkResult = await this.raceCheckTimeout(
111111
(plugin as any)[config.checkMethod](),
112-
this.timeout(config.timeout, `Health check timeout after ${config.timeout}ms`)
113-
]);
112+
config.timeout,
113+
`Health check timeout after ${config.timeout}ms`
114+
);
114115

115116
if (checkResult === false || (checkResult && checkResult.status === 'unhealthy')) {
116117
status = 'unhealthy';
@@ -308,11 +309,44 @@ export class PluginHealthMonitor {
308309
}
309310

310311
/**
311-
* Timeout helper
312+
* Race a plugin's custom health check against its timeout guard, and
313+
* reclaim the guard the moment the race settles (#4875).
314+
*
315+
* Same shape, same reasoning as `ObjectKernel.raceStartupTimeout()` (#4813,
316+
* PR #4874): the guard used to be armed and then abandoned — when the check
317+
* won the race, its `setTimeout` stayed ref'd in the event loop for the full
318+
* `config.timeout`. Health checks are *periodic*, so unlike the kernel's
319+
* one-shot startup guards the orphans here accumulate: one per plugin per
320+
* round, each pinning the loop for `config.timeout`.
321+
*
322+
* Clearing on settle rather than `unref()`-ing at arm time is deliberate.
323+
* An unref'd guard also stops pinning the loop, but it stops being a guard
324+
* as well: if the check never settles and nothing else keeps the loop alive,
325+
* Node exits before the timer can fire and the timeout is never reported.
326+
* The guard has to stay ref'd exactly as long as the race is undecided,
327+
* which is what `clearTimeout` in a `finally` expresses.
328+
*
329+
* `check` is widened to `T | PromiseLike<T>` because `checkMethod` is called
330+
* dynamically off the plugin and may be synchronous; such a check wins the
331+
* race immediately and the guard is reclaimed on the same turn.
312332
*/
313-
private timeout<T>(ms: number, message: string): Promise<T> {
314-
return new Promise((_, reject) => {
315-
setTimeout(() => reject(new Error(message)), ms);
333+
private async raceCheckTimeout<T>(
334+
check: T | PromiseLike<T>,
335+
ms: number,
336+
message: string
337+
): Promise<T> {
338+
let guard: ReturnType<typeof setTimeout> | undefined;
339+
340+
const timeoutPromise = new Promise<never>((_, reject) => {
341+
guard = setTimeout(() => {
342+
reject(new Error(message));
343+
}, ms);
316344
});
345+
346+
try {
347+
return await Promise.race([check, timeoutPromise]);
348+
} finally {
349+
clearTimeout(guard);
350+
}
317351
}
318352
}

0 commit comments

Comments
 (0)