Skip to content

Commit c5adfe1

Browse files
fix(service-automation,core): clear the node-execution and shutdown timeout guards when the race settles (#4952) (#4982)
Two remaining production instances of the leak #4813 (PR #4874, kernel init/start) and #4875 (PR #4950, periodic health checks) already fixed: a timeout guard armed and then abandoned. When the guarded side won the race, its `setTimeout` was neither cleared nor unref'd, so it stayed ref'd and pinned the event loop for the whole timeout budget. - `AutomationEngine.executeWithTimeout()` — the widest of the three: one guard per flow node that declares `timeoutMs`, per run, so the orphan count scales with flow size x trigger frequency. A one-shot process (`os` CLI running a flow) idles for the longest armed budget after its work is done. - `HotReloadManager.reloadPlugin()` — the plugin `destroy()` shutdown guard, byte-for-byte the shape #4813 fixed. Both follow #4874 / #4950 exactly — a private helper plus `try { return await Promise.race([...]) } finally { clearTimeout(guard) }`. No new variant, no `unref()`. hot-reload's helper widens its input to `T | PromiseLike<T>` (the Plugin contract permits a synchronous `destroy()`); engine's does not (`NodeExecutor.execute` is declared Promise-returning). `unref()` would stop the pinning but also stop the guard being a guard: if the guarded side never settles and nothing else keeps the loop alive, Node exits before the timer fires and the timeout is never reported. Regression tests therefore assert both directions per site, following #4950: no ref'd timer left under real timers, no accumulation across rounds under fake timers (that count still sees an unref'd timer, so it catches an unref()-style fake fix), and the timeout still reported when the guarded side genuinely hangs. Timeout durations are untouched — the defect was never the duration. B1 (kernel.ts `shutdown()`) and B2 (objectql `checkDriversHealth()`) are deliberately out of scope per the PM ruling on #4952: both are documented deliberate `unref()` semantics. Claude-Session: https://claude.ai/code/session_01NrmBxj8rK2uGCnh9aipjwX Co-authored-by: Claude <noreply@anthropic.com>
1 parent ddd6650 commit c5adfe1

5 files changed

Lines changed: 461 additions & 15 deletions

File tree

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,30 @@
1+
---
2+
'@objectstack/service-automation': patch
3+
'@objectstack/core': patch
4+
---
5+
6+
fix: 节点执行与热重载 shutdown 的超时守卫在 race 落定时被清除,不再留下孤儿定时器 (#4952)
7+
8+
#4813(PR #4874,内核 init/start)与 #4875(PR #4950,周期性健康检查)修掉的是同一种漏法:
9+
守卫 armed 之后就被扔掉 —— 被守护的一方赢下 race 之后,那根 `setTimeout` 既没 `clearTimeout`
10+
也没 `unref()`,带着 ref 一直把事件循环钉满整个超时预算。本次清仓剩下的两处生产实例:
11+
12+
- **`AutomationEngine.executeWithTimeout()`**(`service-automation`)—— 三处里量级最大的一处:
13+
**每个声明了 `timeoutMs` 的流程节点各一根**,孤儿数随流程节点数 × 触发频率线性增长;一次性进程
14+
(`os` CLI 跑到 flow 的路径)干完活之后还会被最长的那根守卫按住到超时才退出。
15+
- **`HotReloadManager.reloadPlugin()`**(`core`)—— 插件 `destroy()` 的 shutdown 守卫,与 #4813
16+
修掉的两处一字不差:一次毫秒级完成的热重载,照样把循环钉满 `shutdownTimeout`。
17+
18+
两处修法与 #4874 / #4950 同形,不新造变体:私有 helper +
19+
`try { return await Promise.race([...]) } finally { clearTimeout(guard) }`。`hot-reload.ts` 的
20+
helper 把入参放宽到 `T | PromiseLike<T>`(Plugin 契约允许同步 `destroy()`);`engine.ts` 的不放宽
21+
(`NodeExecutor.execute` 声明返回 `Promise`)。
22+
23+
**为什么是 `clearTimeout` 而不是 `unref()`。** `unref()` 让定时器不再钉住事件循环的同时,也让它
24+
不再是一个守卫 —— 若被守护的一方永不 settle 且没有别的东西撑着事件循环,Node 会在定时器触发之前
25+
退出,超时被静默吞掉。守卫必须在 race 未决期间保持 ref'd、在落定那一刻被回收,这正是
26+
`finally { clearTimeout(guard) }` 表达的语义。两处的回归测试各自沿用 #4950 的双向写法:
27+
真实定时器下不留 ref'd 定时器、fake timers 下连跑多轮不累积(计数能看见 `unref()` 过的定时器,
28+
因此识破 `unref()` 式的假修复)、以及被守护方真的挂住时超时照常上报。
29+
30+
超时时长(`timeoutMs` / `shutdownTimeout`)一个都没动 —— 问题从来不在时长,而在没人回收。
Lines changed: 205 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,205 @@
1+
// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license.
2+
3+
import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
4+
import { HotReloadManager } from './hot-reload.js';
5+
import type { ObjectLogger } from './logger.js';
6+
import type { Plugin } from './types.js';
7+
import type { HotReloadConfig } from '@objectstack/spec/kernel';
8+
9+
/** Records `error` reports; every other level is dropped. `child()` is self. */
10+
function createRecordingLogger(errors: { message: string; error?: unknown }[]): ObjectLogger {
11+
const logger = {
12+
debug: () => {},
13+
info: () => {},
14+
warn: () => {},
15+
trace: () => {},
16+
fatal: () => {},
17+
error: (message: string, meta?: Record<string, unknown>) => {
18+
errors.push({ message, error: meta?.error });
19+
},
20+
child: () => logger,
21+
};
22+
return logger as unknown as ObjectLogger;
23+
}
24+
25+
describe('HotReloadManager', () => {
26+
let errors: { message: string; error?: unknown }[];
27+
let manager: HotReloadManager;
28+
29+
beforeEach(() => {
30+
errors = [];
31+
manager = new HotReloadManager(createRecordingLogger(errors));
32+
});
33+
34+
// #4952 — the shutdown timeout guard must not outlive the race it guards.
35+
//
36+
// Byte-for-byte the leak #4813 fixed in the kernel's startup guards
37+
// (PR #4874) and #4875 fixed in the periodic health checks (PR #4950): the
38+
// guard was armed and then abandoned, so a `destroy()` that finished in
39+
// milliseconds still pinned the event loop for the whole `shutdownTimeout`
40+
// — once per reload, per plugin.
41+
//
42+
// Everything below asserts the observable consequence, never the source:
43+
// "hot-reload.ts calls clearTimeout" is a tautology any refactor could
44+
// satisfy while still leaving the loop pinned.
45+
describe('Shutdown timeout guard does not outlive the race (#4952)', () => {
46+
/** A guard long enough that a single orphan is unmistakable. */
47+
const guardedConfig = (overrides: Partial<HotReloadConfig> = {}): HotReloadConfig =>
48+
({
49+
enabled: true,
50+
debounceDelay: 1000,
51+
preserveState: false,
52+
stateStrategy: 'none',
53+
shutdownTimeout: 120_000,
54+
...overrides,
55+
}) as HotReloadConfig;
56+
57+
const noState = () => ({});
58+
const noRestore = () => {};
59+
60+
/**
61+
* Ref'd `Timeout` handles — `getActiveResourcesInfo()` reports only
62+
* resources currently keeping the event loop alive, which is exactly the
63+
* property that made `os migrate` idle ~120s in #4813.
64+
*/
65+
const refdTimers = () => process.getActiveResourcesInfo().filter(r => r === 'Timeout').length;
66+
67+
it("leaves no ref'd timer behind when destroy() wins the race", async () => {
68+
const calls = { count: 0 };
69+
const plugin = {
70+
name: 'guarded-plugin',
71+
version: '1.0.0',
72+
init: () => {},
73+
destroy: async () => {
74+
calls.count++;
75+
},
76+
} as unknown as Plugin;
77+
78+
manager.registerPlugin('guarded-plugin', guardedConfig());
79+
80+
const before = refdTimers();
81+
const reloaded = await manager.reloadPlugin(
82+
'guarded-plugin',
83+
plugin,
84+
'1.0.0',
85+
noState,
86+
noRestore
87+
);
88+
89+
expect(reloaded).toBe(true);
90+
expect(calls.count).toBe(1);
91+
expect(refdTimers()).toBe(before);
92+
});
93+
94+
it('still reports the timeout when destroy() never answers', async () => {
95+
// The companion assertion: reclaiming the guard must not disarm it.
96+
// `unref()` would satisfy "no ref'd timer" by detaching the guard from
97+
// the loop — a process with nothing else to run then exits *silently*
98+
// instead of reporting the timeout, and a plugin that hangs on shutdown
99+
// is exactly the case this guard exists for. Clearing on settle keeps
100+
// the guard armed exactly while the race is undecided.
101+
let release: () => void = () => {};
102+
const hangingPlugin = {
103+
name: 'hanging-plugin',
104+
version: '1.0.0',
105+
init: () => {},
106+
destroy: () =>
107+
new Promise<void>(resolve => {
108+
release = resolve;
109+
}),
110+
} as unknown as Plugin;
111+
112+
manager.registerPlugin('hanging-plugin', guardedConfig({ shutdownTimeout: 50 }));
113+
114+
const reloaded = await manager.reloadPlugin(
115+
'hanging-plugin',
116+
hangingPlugin,
117+
'1.0.0',
118+
noState,
119+
noRestore
120+
);
121+
122+
expect(reloaded).toBe(false);
123+
expect(errors).toHaveLength(1);
124+
expect(errors[0]?.message).toBe('Hot reload failed');
125+
expect((errors[0]?.error as Error).message).toBe('Shutdown timeout');
126+
127+
release();
128+
});
129+
130+
describe('under fake timers', () => {
131+
beforeEach(() => {
132+
vi.useFakeTimers();
133+
});
134+
135+
afterEach(() => {
136+
vi.useRealTimers();
137+
});
138+
139+
it('accumulates no guard across repeated reloads', async () => {
140+
const calls = { count: 0 };
141+
const plugin = {
142+
name: 'guarded-plugin',
143+
version: '1.0.0',
144+
init: () => {},
145+
destroy: async () => {
146+
calls.count++;
147+
},
148+
} as unknown as Plugin;
149+
150+
manager.registerPlugin('guarded-plugin', guardedConfig());
151+
152+
// Unlike `getActiveResourcesInfo()`, the fake-timer count still sees
153+
// an `unref()`'d timer — so this distinguishes "the guard was
154+
// reclaimed" from "the guard was merely detached from the loop", the
155+
// fake fix that keeps the leak and loses the report above.
156+
const before = vi.getTimerCount();
157+
158+
for (let round = 0; round < 4; round++) {
159+
const reloaded = await manager.reloadPlugin(
160+
'guarded-plugin',
161+
plugin,
162+
'1.0.0',
163+
noState,
164+
noRestore
165+
);
166+
expect(reloaded).toBe(true);
167+
// Nothing armed survives the reload that armed it — no drift.
168+
expect(vi.getTimerCount()).toBe(before);
169+
}
170+
171+
expect(calls.count).toBe(4);
172+
});
173+
174+
it('reclaims the guard on the same turn for a synchronous destroy()', async () => {
175+
// The Plugin contract permits `destroy(): void` — the reason the helper
176+
// is widened to `T | PromiseLike<T>`. A sync hook wins the race
177+
// immediately, and the guard must go with it.
178+
const calls = { count: 0 };
179+
const syncPlugin = {
180+
name: 'sync-plugin',
181+
version: '1.0.0',
182+
init: () => {},
183+
destroy: () => {
184+
calls.count++;
185+
},
186+
} as unknown as Plugin;
187+
188+
manager.registerPlugin('sync-plugin', guardedConfig());
189+
190+
const before = vi.getTimerCount();
191+
const reloaded = await manager.reloadPlugin(
192+
'sync-plugin',
193+
syncPlugin,
194+
'1.0.0',
195+
noState,
196+
noRestore
197+
);
198+
199+
expect(reloaded).toBe(true);
200+
expect(calls.count).toBe(1);
201+
expect(vi.getTimerCount()).toBe(before);
202+
});
203+
});
204+
});
205+
});

‎packages/core/src/hot-reload.ts‎

Lines changed: 47 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -270,12 +270,11 @@ export class HotReloadManager {
270270
if (plugin.destroy) {
271271
this.logger.debug('Destroying plugin', { plugin: pluginName });
272272

273-
const shutdownPromise = plugin.destroy();
274-
const timeoutPromise = new Promise((_, reject) => {
275-
setTimeout(() => reject(new Error('Shutdown timeout')), config.shutdownTimeout);
276-
});
277-
278-
await Promise.race([shutdownPromise, timeoutPromise]);
273+
await this.raceShutdownTimeout(
274+
plugin.destroy(),
275+
config.shutdownTimeout,
276+
'Shutdown timeout'
277+
);
279278
this.logger.debug('Plugin destroyed successfully', { plugin: pluginName });
280279
}
281280

@@ -312,6 +311,48 @@ export class HotReloadManager {
312311
}
313312
}
314313

314+
/**
315+
* Race a plugin's `destroy()` against its shutdown-timeout guard, and
316+
* reclaim the guard the moment the race settles (#4952).
317+
*
318+
* The guard used to be armed and then abandoned — byte-for-byte the leak
319+
* #4813 fixed in the kernel's startup guards (PR #4874) and #4875 fixed in
320+
* the periodic health checks (PR #4950): when `destroy()` won the race, its
321+
* `setTimeout` stayed ref'd in the event loop for the full
322+
* `shutdownTimeout`, so a hot reload that finished in milliseconds still
323+
* pinned the loop for the whole budget — once per reload, per plugin.
324+
*
325+
* Clearing on settle rather than `unref()`-ing at arm time is deliberate.
326+
* An unref'd guard also stops pinning the loop, but it stops being a guard
327+
* as well: if `destroy()` never settles and nothing else keeps the loop
328+
* alive, Node exits before the timer can fire and the timeout is never
329+
* reported. The guard has to stay ref'd exactly as long as the race is
330+
* undecided, which is what `clearTimeout` in a `finally` expresses.
331+
*
332+
* `shutdown` is widened to `T | PromiseLike<T>` because the Plugin contract
333+
* permits a synchronous `destroy()` (`Promise<void> | void`); such a hook
334+
* wins the race immediately and the guard is reclaimed on the same turn.
335+
*/
336+
private async raceShutdownTimeout<T>(
337+
shutdown: T | PromiseLike<T>,
338+
timeout: number,
339+
message: string
340+
): Promise<T> {
341+
let guard: ReturnType<typeof setTimeout> | undefined;
342+
343+
const timeoutPromise = new Promise<never>((_, reject) => {
344+
guard = setTimeout(() => {
345+
reject(new Error(message));
346+
}, timeout);
347+
});
348+
349+
try {
350+
return await Promise.race([shutdown, timeoutPromise]);
351+
} finally {
352+
clearTimeout(guard);
353+
}
354+
}
355+
315356
/**
316357
* Schedule a reload with debouncing
317358
*/

0 commit comments

Comments
 (0)