fix(service-automation,core): 超时守卫在 race 落定时被清除 —— #4813 / #4875 的清仓 (#4952)

.changeset/node-and-shutdown-timeout-guards-cleared.md

@@ -0,0 +1,30 @@
+---
+'@objectstack/service-automation': patch
+'@objectstack/core': patch
+---
+
+fix: 节点执行与热重载 shutdown 的超时守卫在 race 落定时被清除,不再留下孤儿定时器 (#4952)
+
+#4813(PR #4874,内核 init/start)与 #4875(PR #4950,周期性健康检查)修掉的是同一种漏法:
+守卫 armed 之后就被扔掉 —— 被守护的一方赢下 race 之后,那根 `setTimeout` 既没 `clearTimeout`
+也没 `unref()`,带着 ref 一直把事件循环钉满整个超时预算。本次清仓剩下的两处生产实例:
+
+- **`AutomationEngine.executeWithTimeout()`**(`service-automation`)—— 三处里量级最大的一处:
+  **每个声明了 `timeoutMs` 的流程节点各一根**,孤儿数随流程节点数 × 触发频率线性增长;一次性进程
+  (`os` CLI 跑到 flow 的路径)干完活之后还会被最长的那根守卫按住到超时才退出。
+- **`HotReloadManager.reloadPlugin()`**(`core`)—— 插件 `destroy()` 的 shutdown 守卫,与 #4813
+  修掉的两处一字不差:一次毫秒级完成的热重载,照样把循环钉满 `shutdownTimeout`。
+
+两处修法与 #4874 / #4950 同形,不新造变体:私有 helper +
+`try { return await Promise.race([...]) } finally { clearTimeout(guard) }`。`hot-reload.ts` 的
+helper 把入参放宽到 `T | PromiseLike<T>`(Plugin 契约允许同步 `destroy()`);`engine.ts` 的不放宽
+(`NodeExecutor.execute` 声明返回 `Promise`)。
+
+**为什么是 `clearTimeout` 而不是 `unref()`。** `unref()` 让定时器不再钉住事件循环的同时,也让它
+不再是一个守卫 —— 若被守护的一方永不 settle 且没有别的东西撑着事件循环,Node 会在定时器触发之前
+退出,超时被静默吞掉。守卫必须在 race 未决期间保持 ref'd、在落定那一刻被回收,这正是
+`finally { clearTimeout(guard) }` 表达的语义。两处的回归测试各自沿用 #4950 的双向写法:
+真实定时器下不留 ref'd 定时器、fake timers 下连跑多轮不累积(计数能看见 `unref()` 过的定时器,
+因此识破 `unref()` 式的假修复)、以及被守护方真的挂住时超时照常上报。
+
+超时时长(`timeoutMs` / `shutdownTimeout`)一个都没动 —— 问题从来不在时长,而在没人回收。

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

@@ -0,0 +1,205 @@
+// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license.
+
+import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
+import { HotReloadManager } from './hot-reload.js';
+import type { ObjectLogger } from './logger.js';
+import type { Plugin } from './types.js';
+import type { HotReloadConfig } from '@objectstack/spec/kernel';
+
+/** Records `error` reports; every other level is dropped. `child()` is self. */
+function createRecordingLogger(errors: { message: string; error?: unknown }[]): ObjectLogger {
+  const logger = {
+    debug: () => {},
+    info: () => {},
+    warn: () => {},
+    trace: () => {},
+    fatal: () => {},
+    error: (message: string, meta?: Record<string, unknown>) => {
+      errors.push({ message, error: meta?.error });
+    },
+    child: () => logger,
+  };
+  return logger as unknown as ObjectLogger;
+}
+
+describe('HotReloadManager', () => {
+  let errors: { message: string; error?: unknown }[];
+  let manager: HotReloadManager;
+
+  beforeEach(() => {
+    errors = [];
+    manager = new HotReloadManager(createRecordingLogger(errors));
+  });
+
+  // #4952 — the shutdown timeout guard must not outlive the race it guards.
+  //
+  // Byte-for-byte the leak #4813 fixed in the kernel's startup guards
+  // (PR #4874) and #4875 fixed in the periodic health checks (PR #4950): the
+  // guard was armed and then abandoned, so a `destroy()` that finished in
+  // milliseconds still pinned the event loop for the whole `shutdownTimeout`
+  // — once per reload, per plugin.
+  //
+  // Everything below asserts the observable consequence, never the source:
+  // "hot-reload.ts calls clearTimeout" is a tautology any refactor could
+  // satisfy while still leaving the loop pinned.
+  describe('Shutdown timeout guard does not outlive the race (#4952)', () => {
+    /** A guard long enough that a single orphan is unmistakable. */
+    const guardedConfig = (overrides: Partial<HotReloadConfig> = {}): HotReloadConfig =>
+      ({
+        enabled: true,
+        debounceDelay: 1000,
+        preserveState: false,
+        stateStrategy: 'none',
+        shutdownTimeout: 120_000,
+        ...overrides,
+      }) as HotReloadConfig;
+
+    const noState = () => ({});
+    const noRestore = () => {};
+
+    /**
+     * Ref'd `Timeout` handles — `getActiveResourcesInfo()` reports only
+     * resources currently keeping the event loop alive, which is exactly the
+     * property that made `os migrate` idle ~120s in #4813.
+     */
+    const refdTimers = () => process.getActiveResourcesInfo().filter(r => r === 'Timeout').length;
+
+    it("leaves no ref'd timer behind when destroy() wins the race", async () => {
+      const calls = { count: 0 };
+      const plugin = {
+        name: 'guarded-plugin',
+        version: '1.0.0',
+        init: () => {},
+        destroy: async () => {
+          calls.count++;
+        },
+      } as unknown as Plugin;
+
+      manager.registerPlugin('guarded-plugin', guardedConfig());
+
+      const before = refdTimers();
+      const reloaded = await manager.reloadPlugin(
+        'guarded-plugin',
+        plugin,
+        '1.0.0',
+        noState,
+        noRestore
+      );
+
+      expect(reloaded).toBe(true);
+      expect(calls.count).toBe(1);
+      expect(refdTimers()).toBe(before);
+    });
+
+    it('still reports the timeout when destroy() never answers', async () => {
+      // The companion assertion: reclaiming the guard must not disarm it.
+      // `unref()` would satisfy "no ref'd timer" by detaching the guard from
+      // the loop — a process with nothing else to run then exits *silently*
+      // instead of reporting the timeout, and a plugin that hangs on shutdown
+      // is exactly the case this guard exists for. Clearing on settle keeps
+      // the guard armed exactly while the race is undecided.
+      let release: () => void = () => {};
+      const hangingPlugin = {
+        name: 'hanging-plugin',
+        version: '1.0.0',
+        init: () => {},
+        destroy: () =>
+          new Promise<void>(resolve => {
+            release = resolve;
+          }),
+      } as unknown as Plugin;
+
+      manager.registerPlugin('hanging-plugin', guardedConfig({ shutdownTimeout: 50 }));
+
+      const reloaded = await manager.reloadPlugin(
+        'hanging-plugin',
+        hangingPlugin,
+        '1.0.0',
+        noState,
+        noRestore
+      );
+
+      expect(reloaded).toBe(false);
+      expect(errors).toHaveLength(1);
+      expect(errors[0]?.message).toBe('Hot reload failed');
+      expect((errors[0]?.error as Error).message).toBe('Shutdown timeout');
+
+      release();
+    });
+
+    describe('under fake timers', () => {
+      beforeEach(() => {
+        vi.useFakeTimers();
+      });
+
+      afterEach(() => {
+        vi.useRealTimers();
+      });
+
+      it('accumulates no guard across repeated reloads', async () => {
+        const calls = { count: 0 };
+        const plugin = {
+          name: 'guarded-plugin',
+          version: '1.0.0',
+          init: () => {},
+          destroy: async () => {
+            calls.count++;
+          },
+        } as unknown as Plugin;
+
+        manager.registerPlugin('guarded-plugin', guardedConfig());
+
+        // Unlike `getActiveResourcesInfo()`, the fake-timer count still sees
+        // an `unref()`'d timer — so this distinguishes "the guard was
+        // reclaimed" from "the guard was merely detached from the loop", the
+        // fake fix that keeps the leak and loses the report above.
+        const before = vi.getTimerCount();
+
+        for (let round = 0; round < 4; round++) {
+          const reloaded = await manager.reloadPlugin(
+            'guarded-plugin',
+            plugin,
+            '1.0.0',
+            noState,
+            noRestore
+          );
+          expect(reloaded).toBe(true);
+          // Nothing armed survives the reload that armed it — no drift.
+          expect(vi.getTimerCount()).toBe(before);
+        }
+
+        expect(calls.count).toBe(4);
+      });
+
+      it('reclaims the guard on the same turn for a synchronous destroy()', async () => {
+        // The Plugin contract permits `destroy(): void` — the reason the helper
+        // is widened to `T | PromiseLike<T>`. A sync hook wins the race
+        // immediately, and the guard must go with it.
+        const calls = { count: 0 };
+        const syncPlugin = {
+          name: 'sync-plugin',
+          version: '1.0.0',
+          init: () => {},
+          destroy: () => {
+            calls.count++;
+          },
+        } as unknown as Plugin;
+
+        manager.registerPlugin('sync-plugin', guardedConfig());
+
+        const before = vi.getTimerCount();
+        const reloaded = await manager.reloadPlugin(
+          'sync-plugin',
+          syncPlugin,
+          '1.0.0',
+          noState,
+          noRestore
+        );
+
+        expect(reloaded).toBe(true);
+        expect(calls.count).toBe(1);
+        expect(vi.getTimerCount()).toBe(before);
+      });
+    });
+  });
+});

packages/core/src/hot-reload.ts

@@ -270,12 +270,11 @@ export class HotReloadManager {
       if (plugin.destroy) {
         this.logger.debug('Destroying plugin', { plugin: pluginName });
 
-        const shutdownPromise = plugin.destroy();
-        const timeoutPromise = new Promise((_, reject) => {
-          setTimeout(() => reject(new Error('Shutdown timeout')), config.shutdownTimeout);
-        });
-
-        await Promise.race([shutdownPromise, timeoutPromise]);
+        await this.raceShutdownTimeout(
+          plugin.destroy(),
+          config.shutdownTimeout,
+          'Shutdown timeout'
+        );
         this.logger.debug('Plugin destroyed successfully', { plugin: pluginName });
       }
 
@@ -312,6 +311,48 @@ export class HotReloadManager {
     }
   }
 
+  /**
+   * Race a plugin's `destroy()` against its shutdown-timeout guard, and
+   * reclaim the guard the moment the race settles (#4952).
+   *
+   * The guard used to be armed and then abandoned — byte-for-byte the leak
+   * #4813 fixed in the kernel's startup guards (PR #4874) and #4875 fixed in
+   * the periodic health checks (PR #4950): when `destroy()` won the race, its
+   * `setTimeout` stayed ref'd in the event loop for the full
+   * `shutdownTimeout`, so a hot reload that finished in milliseconds still
+   * pinned the loop for the whole budget — once per reload, per plugin.
+   *
+   * Clearing on settle rather than `unref()`-ing at arm time is deliberate.
+   * An unref'd guard also stops pinning the loop, but it stops being a guard
+   * as well: if `destroy()` never settles and nothing else keeps the loop
+   * alive, Node exits before the timer can fire and the timeout is never
+   * reported. The guard has to stay ref'd exactly as long as the race is
+   * undecided, which is what `clearTimeout` in a `finally` expresses.
+   *
+   * `shutdown` is widened to `T | PromiseLike<T>` because the Plugin contract
+   * permits a synchronous `destroy()` (`Promise<void> | void`); such a hook
+   * wins the race immediately and the guard is reclaimed on the same turn.
+   */
+  private async raceShutdownTimeout<T>(
+    shutdown: T | PromiseLike<T>,
+    timeout: number,
+    message: string
+  ): Promise<T> {
+    let guard: ReturnType<typeof setTimeout> | undefined;
+
+    const timeoutPromise = new Promise<never>((_, reject) => {
+      guard = setTimeout(() => {
+        reject(new Error(message));
+      }, timeout);
+    });
+
+    try {
+      return await Promise.race([shutdown, timeoutPromise]);
+    } finally {
+      clearTimeout(guard);
+    }
+  }
+
   /**
    * Schedule a reload with debouncing
    */