Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
44 changes: 44 additions & 0 deletions .changeset/kernel-shutdown-isolate-and-honest-timeout.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,44 @@
---
"@objectstack/core": patch
---

fix(core): one throwing `kernel:shutdown` handler no longer skips every plugin `destroy()` and kills the process under a false "Shutdown timed out" (#5274)

**On `ObjectKernel`, a single bad shutdown subscriber used to end the entire teardown
and `process.exit(1)` the host — reporting a timeout that never happened.**

`performShutdown()` dispatched `kernel:shutdown` through `context.trigger` (a bare
awaited loop that never catches), so the first handler that threw propagated out to
`shutdown()`'s `Promise.race` catch. That catch was written for the timeout race alone
and treated every exception as one, producing three consequences at once:

1. the remaining `kernel:shutdown` handlers never ran;
2. **every** plugin's `destroy()` was skipped — the reverse-order destroy pass sits
after the trigger in `performShutdown()`, so it was never reached;
3. the process was killed by `process.exit(1)` under the log line
`Shutdown timed out — forcing exit`, while nothing had timed out — sending whoever
read it to the `shutdownTimeout` config for a handler bug.

Two changes, matching the reasoning #5257 recorded at `LiteKernel`'s shutdown dispatch
site:

- **`kernel:shutdown` now dispatches ISOLATING on `ObjectKernel` too.** A handler that
throws is logged as `Hook handler failed: kernel:shutdown` and the remaining handlers
still run, followed by the reverse-order `destroy()` pass and the `onShutdown()`
handlers — both of which already isolated per plugin and per handler. What is queued
behind a failing shutdown handler is the cleanup that flushes buffers, closes
connections and releases locks, so one bad handler must not amplify into leaks and
unflushed writes. The BOOT-path hooks are untouched: `kernel:ready`,
`kernel:bootstrapped` and `kernel:listening` still propagate and still fail the boot
(#5170, #5257).
- **The timeout catch now handles only a genuine timeout**, discriminated by identity on
the timer's own rejection — not by message, not by type, so nothing a plugin throws
can impersonate it. A genuine `shutdownTimeout` overrun is **unchanged**: it still
logs `Shutdown timed out — forcing exit` and still calls `process.exit(1)`, because
teardown really is hung and the process would otherwise hold what it failed to
release. Any other exception is logged at `error` and follows the normal path —
`state = 'stopped'`, return — with no `process.exit`, leaving an embedding host
(cloud auth-proxy, CLI, a test runner) its own chance to finish cleanly.

`shutdown()` still never rejects, so no existing caller changes. Telling the two paths
apart is the point of the fix, and both are pinned by named tests.
2 changes: 1 addition & 1 deletion content/docs/kernel/events.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ A handler on any of the three **boot-path** hooks — `kernel:ready`, `kernel:bo

`kernel:ready` is still the right place for **boot assertions** specifically — the service registry is only finished filling by then, so nothing earlier can judge whether a precondition your plugin *declared* was actually met, and a deployment that cannot honour what it announced must refuse to start rather than serve without the guarantee.

`kernel:shutdown` is the deliberate exception: on `LiteKernel` a failing shutdown handler is logged and the remaining cleanup still runs, because the handlers queued behind it — and the `destroy()` pass after them — are what flush buffers and release resources, so aborting teardown only leaks what they were about to release. `ObjectKernel`'s shutdown path does not yet match that (tracked in [#5274](https://github.com/objectstack-ai/objectstack/issues/5274)); write shutdown handlers that handle their own errors either way.
`kernel:shutdown` is the deliberate exception, on **both** kernels: a failing shutdown handler is logged (`Hook handler failed: kernel:shutdown`) and the remaining cleanup still runs, because the handlers queued behind it — and the `destroy()` pass after them — are what flush buffers and release resources, so aborting teardown only leaks what they were about to release. On `ObjectKernel` this also means a throwing shutdown handler no longer kills the host process: `shutdown()` still never rejects, the kernel still ends `stopped`, and `process.exit(1)` is reserved for a genuine `shutdownTimeout` overrun — the one case where teardown really is hung ([#5274](https://github.com/objectstack-ai/objectstack/issues/5274)). Write shutdown handlers that handle their own errors either way.

### Emitting Custom Events

Expand Down
140 changes: 140 additions & 0 deletions packages/core/src/kernel.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -728,6 +728,146 @@ describe('ObjectKernel', () => {

expect(handlerCalled).toBe(true);
});

// #5274. `process.exit` is intercepted in all three tests below — the
// behaviour under test is precisely whether the kernel kills the host
// process, and an unintercepted `exit(1)` takes the vitest worker with
// it (which is why this pin could not land in #5257).
const spyOnExit = () =>
vi.spyOn(process, 'exit').mockImplementation((() => undefined) as never);

const spyOnLog = (k: ObjectKernel, level: 'error' | 'info') =>
vi.spyOn(
(k as unknown as { logger: Record<'error' | 'info', (...a: unknown[]) => void> }).logger,
level,
);

// The issue's reproduction, inverted into a pin. Before this, the first
// throwing `kernel:shutdown` handler ended the entire teardown: the
// probe recorded `reached=["process.exit(1)"]` — neither the second
// handler nor the plugin's destroy() ever ran. What is queued behind a
// failing shutdown handler is the rest of the cleanup (flush buffers,
// close connections, release locks), so one bad handler must not
// amplify into leaks and unflushed writes.
it('runs the remaining kernel:shutdown handlers, every destroy() and every onShutdown handler when one handler throws (#5274)', async () => {
const reached: string[] = [];
const exitSpy = spyOnExit();

const plugin: Plugin = {
name: 'shutdown-thrower',
version: '1.0.0',
init: async (ctx) => {
ctx.hook('kernel:shutdown', async () => {
throw new Error('shutdown boom');
});
ctx.hook('kernel:shutdown', async () => { reached.push('later-shutdown'); });
},
destroy: async () => { reached.push('plugin-destroy'); },
};

try {
await kernel.use(plugin);
kernel.onShutdown(async () => { reached.push('shutdown-handler'); });
await kernel.bootstrap();
await kernel.shutdown();

// Every teardown step behind the failing handler still ran, in
// order: remaining subscribers → reverse-order destroy() →
// custom shutdown handlers.
expect(reached).toEqual(['later-shutdown', 'plugin-destroy', 'shutdown-handler']);
// …and the host process was left alone.
expect(exitSpy).not.toHaveBeenCalled();
expect(kernel.getState()).toBe('stopped');
} finally {
exitSpy.mockRestore();
}
});

// The second half of the same defect, pinned separately because it can
// regress on its own: the outer catch was written only for the timeout
// race, so a handler throw was reported as `Shutdown timed out —
// forcing exit` when nothing had timed out — sending whoever read that
// line straight to the `shutdownTimeout` config.
it('names the failing handler and never reports a timeout that did not happen (#5274)', async () => {
const exitSpy = spyOnExit();
const errorSpy = spyOnLog(kernel, 'error');
const infoSpy = spyOnLog(kernel, 'info');

const plugin: Plugin = {
name: 'shutdown-thrower-logs',
version: '1.0.0',
init: async (ctx) => {
ctx.hook('kernel:shutdown', async () => {
throw new Error('shutdown boom');
});
},
};

try {
await kernel.use(plugin);
await kernel.bootstrap();
await kernel.shutdown();

const errors = errorSpy.mock.calls.map((c) => String(c[0]));
// The failure is reported where it happened, naming the hook —
// same line LiteKernel's isolating dispatcher logs.
expect(errors).toContain('Hook handler failed: kernel:shutdown');
// …and NOT as a timeout.
expect(errors.some((m) => m.includes('Shutdown timed out'))).toBe(false);
expect(exitSpy).not.toHaveBeenCalled();

// Teardown really did complete, so it says so.
const infos = infoSpy.mock.calls.map((c) => String(c[0]));
expect(infos.some((m) => m.includes('Graceful shutdown complete'))).toBe(true);
} finally {
exitSpy.mockRestore();
errorSpy.mockRestore();
infoSpy.mockRestore();
}
});

// The other side of the discrimination, and the reason it is drawn by
// identity on the timer's own rejection: a GENUINE timeout keeps the
// hard exit. `performShutdown()` is still running and has stopped
// making progress, so the process would hang holding whatever it failed
// to release. This behaviour is unchanged by #5274 — pinned so the
// narrowing of the catch cannot quietly take it along.
it('still logs the timeout and still forces exit(1) when shutdown genuinely times out (#5274)', async () => {
const slowKernel = new ObjectKernel({
logger: { level: 'error' },
gracefulShutdown: false,
skipSystemValidation: true,
shutdownTimeout: 20,
});

const exitSpy = spyOnExit();
const errorSpy = spyOnLog(slowKernel, 'error');

const plugin: Plugin = {
name: 'hanging-shutdown-plugin',
version: '1.0.0',
init: async (ctx) => {
// Never settles — the actual shape of a hung teardown.
// Deliberately left pending: resolving it later would let
// the teardown resume after the test had finished.
ctx.hook('kernel:shutdown', () => new Promise<void>(() => {}));
},
};

try {
await slowKernel.use(plugin);
await slowKernel.bootstrap();
await slowKernel.shutdown();

const errors = errorSpy.mock.calls.map((c) => String(c[0]));
expect(errors).toContain('Shutdown timed out — forcing exit');
expect(exitSpy).toHaveBeenCalledWith(1);
expect(slowKernel.getState()).toBe('stopped');
} finally {
exitSpy.mockRestore();
errorSpy.mockRestore();
}
}, 5000);
});

describe('Dependency Resolution', () => {
Expand Down
92 changes: 85 additions & 7 deletions packages/core/src/kernel.ts
Original file line number Diff line number Diff line change
Expand Up @@ -425,11 +425,22 @@ export class ObjectKernel {
this.state = 'stopping';
this.logger.info('Graceful shutdown started');

// The ONE rejection that means "teardown hung". Created here so the
// catch below can discriminate by IDENTITY (#5274): only this
// `setTimeout` can produce this exact object, so no message match, no
// `instanceof`, and nothing a plugin throws can ever impersonate it —
// not even a handler throwing `new Error('Shutdown timeout exceeded')`.
// That discrimination is the whole point: the catch used to be reached
// by BOTH the timer and any exception escaping `performShutdown()`, and
// it treated them identically — `process.exit(1)` under a log line
// reading "Shutdown timed out" when nothing had timed out.
const shutdownTimeoutError = new Error('Shutdown timeout exceeded');

try {
const shutdownPromise = this.performShutdown();
const timeoutPromise = new Promise<void>((_, reject) => {
const t = setTimeout(() => {
reject(new Error('Shutdown timeout exceeded'));
reject(shutdownTimeoutError);
}, this.config.shutdownTimeout);
// Don't let this timer keep the event loop alive
if (t.unref) t.unref();
Expand All @@ -440,11 +451,32 @@ export class ObjectKernel {
this.state = 'stopped';
this.logger.info('✅ Graceful shutdown complete');
} catch (error) {
this.logger.error('Shutdown timed out — forcing exit', error as Error);
this.state = 'stopped';
// Flush logger then hard-exit; the process would otherwise hang
await this.logger.destroy();
process.exit(1);

if (error === shutdownTimeoutError) {
// GENUINE timeout: `performShutdown()` is still running and has
// stopped making progress, so the process would otherwise hang
// holding whatever it failed to release. Hard-exit stays — it
// is the only branch it was ever right for.
this.logger.error('Shutdown timed out — forcing exit', error as Error);
// Flush logger then hard-exit; the process would otherwise hang
await this.logger.destroy();
process.exit(1);
} else {
// NOT a timeout. `performShutdown()` isolates every teardown
// step it owns (hook dispatch, each destroy(), each shutdown
// handler), so reaching here means something outside those
// loops failed — the teardown is over either way, and there is
// nothing hung to escape from. Killing the host process here
// would take away the embedding host's (cloud auth-proxy, CLI,
// a test runner) chance to do its own cleanup, over a fault
// that did not require it. Log and return down the normal
// path; `shutdown()` still never rejects.
this.logger.error(
'Shutdown finished with an unexpected teardown error — the kernel is stopped and the process is NOT being exited; some cleanup may not have run',
error as Error,
);
}
} finally {
await this.logger.destroy();
}
Expand Down Expand Up @@ -673,9 +705,55 @@ export class ObjectKernel {
this.startedPlugins.clear();
}

/**
* Dispatch `kernel:shutdown`, ISOLATING failures: a handler that throws is
* logged and the remaining handlers still run (#5274).
*
* This is a per-hook judgement, deliberately NOT the bare awaited loop
* `context.trigger` runs for every other hook — the boot-path hooks
* (`kernel:ready`, `kernel:bootstrapped`, `kernel:listening`) keep
* propagating, because everything dispatched before "✅ Bootstrap complete"
* is a precondition of that claim and swallowing a throw there only hides
* the failure behind a process reporting success (#5170, #5257).
*
* On the teardown path there is no "refuse to proceed" left to buy. What is
* queued behind a failing shutdown handler is the rest of the cleanup —
* every other subscriber, then each plugin's `destroy()` in reverse order —
* which is what flushes buffers, closes connections and releases locks. So
* one bad handler must not amplify into leaked resources and unflushed
* writes. Same reasoning, same wording, same `Hook handler failed:
* kernel:shutdown` log line as `LiteKernel`'s dispatch site, which reaches
* the shared isolating dispatcher `ObjectKernelBase.triggerHook` (#5257).
*
* `ObjectKernel` cannot call that dispatcher: it does not extend
* `ObjectKernelBase` (only `LiteKernel` does) and owns its own `hooks` map,
* so the semantics are mirrored here rather than shared. One hook name
* meaning two opposite things across the two kernels is exactly the bug
* #5170/#5257 closed, so the pin for this one lives on both sides too.
*/
private async triggerShutdownHookIsolating(): Promise<void> {
const handlers = this.hooks.get('kernel:shutdown') || [];
this.logger.debug('Triggering hook: kernel:shutdown', {
hook: 'kernel:shutdown',
handlerCount: handlers.length,
});

for (const handler of handlers) {
try {
await handler();
} catch (error) {
this.logger.error('Hook handler failed: kernel:shutdown', error as Error);
// Continue with other handlers even if one fails
}
}
}

private async performShutdown(): Promise<void> {
// Trigger shutdown hook
await this.context.trigger('kernel:shutdown');
// Trigger shutdown hook — ISOLATING dispatch, see the method's own
// rationale. The two loops below already isolate per plugin and per
// handler; before #5274 this line was the one teardown step that did
// not, so a single throwing subscriber skipped BOTH of them.
await this.triggerShutdownHookIsolating();

// Destroy plugins in reverse order
const orderedPlugins = Array.from(this.plugins.values()).reverse();
Expand Down
Loading