diff --git a/.changeset/kernel-boot-hook-failure-propagation.md b/.changeset/kernel-boot-hook-failure-propagation.md new file mode 100644 index 0000000000..1dc5386780 --- /dev/null +++ b/.changeset/kernel-boot-hook-failure-propagation.md @@ -0,0 +1,59 @@ +--- +"@objectstack/core": minor +--- + +fix(core)!: a throwing `kernel:bootstrapped` / `kernel:listening` handler fails the boot on LiteKernel too (#5257) + +**A failed `listen()` no longer yields a false "✅ Bootstrap complete".** + +#5170 (PR #5258) unified `kernel:ready`: a handler that throws fails the boot on +`ObjectKernel` and `LiteKernel` alike. It deliberately ruled that one hook only, +leaving the other lifecycle hooks split — `ObjectKernel` propagates their +failures (its `context.trigger` is a bare awaited loop that never catches) while +`LiteKernel` routed them through the isolating dispatcher, logging +`Hook handler failed: ` and carrying on. This closes the two boot-path +hooks that were left: `kernel:bootstrapped` and `kernel:listening` now use the +propagating dispatcher (`triggerHookOrThrow`) on `LiteKernel`, in the same shape +#5258 established — the remaining handlers for that hook are skipped, the later +boot hooks never fire, the original error reaches the caller **unwrapped**, +`state` is left `'stopped'` rather than `'running'`, and the success line is +never logged. + +The concrete failure this removes: `HonoServerPlugin` opens its socket inside a +`kernel:listening` handler — `await this.server.listen(port)`, with no try/catch +of its own, deliberately. When that rejected on `LiteKernel` (EACCES on a +privileged port, a failure inside the port-fallback logic itself, a serverless / +edge host where `listen` is not available at all) the throw was swallowed, +`bootstrap()` resolved normally, and the process printed +`✅ Bootstrap complete` while **nothing was listening**. The same plugin code on +`ObjectKernel` failed the boot. The health check that came next was the first +thing to notice, and it had already been told startup succeeded. Plain "port is +in use" was never affected — `server.listen` falls back to a random port +internally — which is exactly why this stayed invisible. + +`kernel:bootstrapped` carries reconcile and audit work (objectql's +`announceOpenMigrationGates`, service-automation's node-type / trigger-binding +audits, the sharing plugin's boot backfills); a swallowed failure there is a +quieter version of the same lie — the audit silently does not run. + +**`kernel:shutdown` keeps fail-soft dispatch**, now as an explicit per-hook +judgement recorded in a comment at the dispatch site rather than an inherited +default. On the teardown path there is no "refuse to proceed" left to buy, and +the handlers queued behind a failing one — plus the reverse-order `destroy()` +pass after them — are what flush buffers, close connections and release locks. +Aborting that sequence would convert one bad handler into leaked resources and +unflushed writes. + +**Who is affected.** Hosts that boot through `LiteKernel` — vitest, serverless, +edge (Workers) — and register a `kernel:bootstrapped` or `kernel:listening` +handler that can throw. Such a host previously came up "successfully" with the +work of that handler silently skipped; it now refuses to start and surfaces the +original error. If a handler of yours performs best-effort work whose failure +genuinely must not stop the boot, it needs its own `try/catch` — which is what +the in-repo `kernel:bootstrapped` subscribers already do, per handler, with the +reason written down. Nothing in this repo relied on the swallow: the core (426), +client, runtime, http-conformance, connector-{rest,mcp,slack} and +service-automation (665) suites pass unchanged. + +Boot assertions still belong in `kernel:ready`: it is the earliest hook at which +the service registry is finished filling. diff --git a/content/docs/kernel/events.mdx b/content/docs/kernel/events.mdx index a83d07a518..7c8e9fbf43 100644 --- a/content/docs/kernel/events.mdx +++ b/content/docs/kernel/events.mdx @@ -33,7 +33,11 @@ ctx.hook('kernel:ready', async () => { `ctx.hook(name, handler)` takes exactly two arguments — there is no options/priority parameter. Kernel hooks run in **registration order**, and `ctx.trigger()` awaits each handler sequentially. -A `kernel:ready` handler that **throws fails the boot**, on `ObjectKernel` and `LiteKernel` alike: the remaining `kernel:ready` handlers are skipped, `kernel:bootstrapped` and `kernel:listening` never fire, and `bootstrap()` rejects with the original error. That is what makes `kernel:ready` the place to assert that a precondition your plugin *declared* was actually met — the service registry is still filling during `init()`, so nothing earlier can judge it, and a deployment that cannot honour what it announced must refuse to start rather than serve without the guarantee. The other lifecycle hooks do **not** share that contract: `ObjectKernel` propagates their failures too, while `LiteKernel` logs each one and runs the remaining handlers. Put boot assertions in `kernel:ready`. +A handler on any of the three **boot-path** hooks — `kernel:ready`, `kernel:bootstrapped`, `kernel:listening` — that **throws fails the boot**, on `ObjectKernel` and `LiteKernel` alike: the remaining handlers for that hook are skipped, the later boot hooks never fire, `bootstrap()` rejects with the original error (unwrapped), the kernel is left `stopped` rather than `running`, and **no "✅ Bootstrap complete" is logged**. Everything dispatched before that line is a precondition of it, so swallowing a failure there would not rescue the boot — it would only hide it behind a process reporting success. That is most visible on `kernel:listening`, where HTTP server plugins open their socket: a `listen()` that rejects (EACCES on a privileged port, a host that cannot listen at all) takes the boot down instead of leaving a live process with nothing listening. + +`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. ### Emitting Custom Events diff --git a/packages/core/src/kernel-base.ts b/packages/core/src/kernel-base.ts index 69ae687127..775e24573f 100644 --- a/packages/core/src/kernel-base.ts +++ b/packages/core/src/kernel-base.ts @@ -250,11 +250,17 @@ export abstract class ObjectKernelBase { * Trigger a hook with all registered handlers, ISOLATING failures: a * handler that throws is logged and the remaining handlers still run. * - * Use this for notification-style hooks, where one subscriber's failure - * must not deny the others their notification. It is the WRONG dispatcher - * for a hook that carries boot assertions — a swallowed throw there turns - * "this deployment refuses to start misconfigured" into a log line nobody - * reads. Those hooks use {@link triggerHookOrThrow} (#5170). + * Use this for hooks where one subscriber's failure must not deny the + * others their turn — notification-style hooks, and `kernel:shutdown`, + * where the handlers still queued behind the failing one are the cleanup + * that flushes buffers and releases resources (#5257). + * + * It is the WRONG dispatcher for anything on the BOOT path. Every hook + * dispatched before "✅ Bootstrap complete" is a precondition of that + * claim, so swallowing a throw there does not rescue the boot — it only + * hides the failure behind a process that reports success. Those hooks + * (`kernel:ready`, `kernel:bootstrapped`, `kernel:listening`) use + * {@link triggerHookOrThrow} (#5170, #5257). * * @param name - Hook name * @param args - Arguments to pass to handlers @@ -285,18 +291,31 @@ export abstract class ObjectKernelBase { * lifecycle hook (its `context.trigger` is a bare awaited loop that never * catches). `LiteKernel` used the isolating {@link triggerHook} for all of * them, so one hook name meant two opposite things depending on which - * kernel booted the same plugin code (#5170). `kernel:ready` is the hook - * where that divergence bites: it is the only correct moment for a plugin - * to assert that the preconditions it declared were actually met (the - * registries are still filling during `init()`), so "declared but not - * deliverable ⇒ refuse to boot" gates live there — and on LiteKernel, - * which is what vitest/serverless/edge run, they were being downgraded to - * an error log while the process carried on serving traffic without the - * guarantee it claimed. + * kernel booted the same plugin code (#5170). + * + * `LiteKernel` now uses this dispatcher for all three BOOT-path hooks: + * + * - `kernel:ready` (#5170) — the only correct moment for a plugin to + * assert that the preconditions it declared were actually met (the + * registries are still filling during `init()`), so "declared but not + * deliverable ⇒ refuse to boot" gates live there. On LiteKernel, which + * is what vitest/serverless/edge run, they were downgraded to an error + * log while the process carried on serving traffic without the + * guarantee it claimed. + * - `kernel:bootstrapped` and `kernel:listening` (#5257) — the same + * argument one hook later. `kernel:listening` is where HTTP server + * plugins open their socket, so a swallowed failure there produced the + * worst shape available: a live process printing "✅ Bootstrap complete" + * with nothing listening. `kernel:bootstrapped` carries reconcile and + * audit passes whose silent failure is a quieter version of the same + * lie. * - * Deliberately NOT applied to the other hook names: #5170 rules - * `kernel:ready` only, and a notification hook keeping fail-soft dispatch - * is a separate judgement per hook, not a side effect of this one. + * Deliberately NOT applied to `kernel:shutdown`, which keeps + * {@link triggerHook}: on the teardown path a failing handler must not + * block the cleanup queued behind it. That is a per-hook judgement + * recorded at the dispatch site in `lite-kernel.ts`, not an inherited + * default — and it is the reason this dispatcher is chosen per hook rather + * than swapped in wholesale. * * @param name - Hook name * @param args - Arguments to pass to handlers diff --git a/packages/core/src/kernel.test.ts b/packages/core/src/kernel.test.ts index e712a50c24..fca8f42bbc 100644 --- a/packages/core/src/kernel.test.ts +++ b/packages/core/src/kernel.test.ts @@ -636,6 +636,66 @@ describe('ObjectKernel', () => { expect(kernel.getState()).toBe('stopped'); }); + // #5257 — the ObjectKernel HALVES of the two pins this issue adds. + // ObjectKernel already behaved this way (`context.trigger` never + // catches); the tests exist so the pair is symmetric with + // lite-kernel.test.ts and a regression on EITHER kernel is caught by a + // named test rather than inferred from the other one still passing. + // That symmetry is the whole point: the bug #5170 and #5257 closed was + // one hook name meaning two opposite things depending on the kernel, + // and only a matched pair of tests can hold that shut. + it('fails the boot when a kernel:bootstrapped handler throws (#5257)', async () => { + const reached: string[] = []; + const plugin: Plugin = { + name: 'bootstrapped-thrower-plugin', + version: '1.0.0', + init: async (ctx) => { + ctx.hook('kernel:bootstrapped', async () => { + throw new Error('node-type audit could not seal the vocabulary'); + }); + ctx.hook('kernel:bootstrapped', async () => { reached.push('later-bootstrapped'); }); + ctx.hook('kernel:listening', async () => { reached.push('kernel:listening'); }); + }, + }; + + await kernel.use(plugin); + + await expect(kernel.bootstrap()).rejects.toThrow('node-type audit could not seal the vocabulary'); + + expect(reached).toEqual([]); + expect(kernel.getState()).toBe('stopped'); + }); + + // The headline case of #5257, from the kernel that always got it + // right: `HonoServerPlugin` awaits `server.listen(port)` inside a + // `kernel:listening` handler with no try/catch of its own, so a listen + // that rejects must fail the boot rather than resolve into a process + // announcing "✅ Bootstrap complete" with nothing listening. + it('fails the boot — and never logs "Bootstrap complete" — when a kernel:listening handler throws (#5257)', async () => { + const reached: string[] = []; + const plugin: Plugin = { + name: 'listening-thrower-plugin', + version: '1.0.0', + init: async (ctx) => { + ctx.hook('kernel:listening', async () => { + throw new Error('listen EACCES: permission denied 0.0.0.0:80'); + }); + ctx.hook('kernel:listening', async () => { reached.push('later-listening'); }); + }, + }; + + await kernel.use(plugin); + const infoSpy = vi.spyOn((kernel as unknown as { logger: { info: (...a: unknown[]) => void } }).logger, 'info'); + + await expect(kernel.bootstrap()).rejects.toThrow('listen EACCES: permission denied 0.0.0.0:80'); + + expect(reached).toEqual([]); + expect(kernel.getState()).toBe('stopped'); + const logged = infoSpy.mock.calls.map((c) => String(c[0])); + expect(logged.some((m) => m.includes('Bootstrap complete'))).toBe(false); + infoSpy.mockRestore(); + }); + it('should trigger shutdown hook', async () => { let hookCalled = false; diff --git a/packages/core/src/lite-kernel.test.ts b/packages/core/src/lite-kernel.test.ts index c6d99097ac..c285fce0c4 100644 --- a/packages/core/src/lite-kernel.test.ts +++ b/packages/core/src/lite-kernel.test.ts @@ -1,4 +1,4 @@ -import { describe, it, expect, beforeEach } from 'vitest'; +import { describe, it, expect, beforeEach, vi } from 'vitest'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { LiteKernel } from './lite-kernel'; @@ -303,33 +303,97 @@ describe('LiteKernel with Configurable Logger', () => { expect(kernel.getState()).toBe('stopped'); }); - // The other side of the same contract: #5170 rules `kernel:ready` ONLY. - // The notification-style hooks keep LiteKernel's isolating dispatch, so - // one failing subscriber does not deny the others their notification. - // Pinned so a future "unify everything" reading of #5170 has to be a - // deliberate change with its own issue, not a silent widening. - it('keeps fail-soft dispatch for hooks other than kernel:ready (#5170)', async () => { + // #5257 — the DELIBERATE FLIP of the pin #5170 left behind. That pin + // read "keeps fail-soft dispatch for hooks other than kernel:ready", + // covering `kernel:bootstrapped`, `kernel:listening` AND + // `kernel:shutdown` in one assertion, because #5170's dispatch word + // ruled `kernel:ready` alone. #5257 rules the other two boot-path + // hooks: they propagate now, and only `kernel:shutdown` still holds + // the fail-soft half (its own test below). The split is what the + // three tests here record — per hook, on purpose. + it('fails the boot when a kernel:bootstrapped handler throws (#5257)', async () => { const reached: string[] = []; const plugin: Plugin = { - name: 'other-hook-thrower-plugin', + name: 'bootstrapped-thrower-plugin', init: async (ctx) => { - ctx.hook('kernel:bootstrapped', async () => { throw new Error('bootstrapped boom'); }); + ctx.hook('kernel:bootstrapped', async () => { + throw new Error('node-type audit could not seal the vocabulary'); + }); ctx.hook('kernel:bootstrapped', async () => { reached.push('later-bootstrapped'); }); - ctx.hook('kernel:listening', async () => { throw new Error('listening boom'); }); + ctx.hook('kernel:listening', async () => { reached.push('kernel:listening'); }); + }, + }; + + kernel.use(plugin); + + // The ORIGINAL error surfaces — not a wrapped "bootstrap failed". + await expect(kernel.bootstrap()).rejects.toThrow('node-type audit could not seal the vocabulary'); + + // Boot stopped AT the failing handler: no later bootstrapped + // handler, and no listening phase at all. + expect(reached).toEqual([]); + expect(kernel.getState()).toBe('stopped'); + }); + + // The headline case of #5257. `kernel:listening` is where HTTP server + // plugins open their socket — `HonoServerPlugin` awaits + // `server.listen(port)` there with no try/catch of its own. Swallowing + // that rejection (EACCES on a privileged port, a listen the edge / + // serverless host cannot perform at all) used to leave a live process + // that had printed "✅ Bootstrap complete" and was listening on + // nothing. Hence the explicit assertion that the success line is NOT + // logged: `bootstrap()` rejecting is only half the contract, the other + // half is that nothing announced success on the way out. + it('fails the boot — and never logs "Bootstrap complete" — when a kernel:listening handler throws (#5257)', async () => { + const reached: string[] = []; + const plugin: Plugin = { + name: 'listening-thrower-plugin', + init: async (ctx) => { + ctx.hook('kernel:listening', async () => { + throw new Error('listen EACCES: permission denied 0.0.0.0:80'); + }); ctx.hook('kernel:listening', async () => { reached.push('later-listening'); }); + }, + }; + + kernel.use(plugin); + const infoSpy = vi.spyOn((kernel as unknown as { logger: { info: (...a: unknown[]) => void } }).logger, 'info'); + + await expect(kernel.bootstrap()).rejects.toThrow('listen EACCES: permission denied 0.0.0.0:80'); + + expect(reached).toEqual([]); + expect(kernel.getState()).toBe('stopped'); + const logged = infoSpy.mock.calls.map((c) => String(c[0])); + expect(logged.some((m) => m.includes('Bootstrap complete'))).toBe(false); + infoSpy.mockRestore(); + }); + + // The half of the old pin that SURVIVES #5257, kept as its own test so + // the reason is attached to the one hook it applies to. `kernel:shutdown` + // stays fail-soft: on the teardown path there is no "refuse to proceed" + // left to buy, and the handlers queued behind a failing one are the + // cleanup that flushes buffers and releases resources. Aborting the + // sequence would turn one bad handler into leaked resources. + it('keeps fail-soft dispatch for kernel:shutdown — a failing handler must not block the remaining cleanup (#5257)', async () => { + const reached: string[] = []; + const plugin: Plugin = { + name: 'shutdown-thrower-plugin', + 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'); }, }; kernel.use(plugin); await expect(kernel.bootstrap()).resolves.toBeUndefined(); expect(kernel.getState()).toBe('running'); - expect(reached).toEqual(['later-bootstrapped', 'later-listening']); await expect(kernel.shutdown()).resolves.toBeUndefined(); - expect(reached).toContain('later-shutdown'); + // Both the later hook handler AND the plugin teardown behind it ran. + expect(reached).toEqual(['later-shutdown', 'plugin-destroy']); + expect(kernel.getState()).toBe('stopped'); }); }); }); diff --git a/packages/core/src/lite-kernel.ts b/packages/core/src/lite-kernel.ts index 68d96cfd64..e4631feaf9 100644 --- a/packages/core/src/lite-kernel.ts +++ b/packages/core/src/lite-kernel.ts @@ -80,34 +80,47 @@ export class LiteKernel extends ObjectKernelBase { await this.runPluginStart(plugin); } - // Trigger ready hook (route/middleware registration phase). + // The three boot-path lifecycle hooks all use PROPAGATING dispatch, + // identical to `ObjectKernel.bootstrap()`'s `context.trigger` (a bare + // awaited loop that never catches): a handler that throws FAILS THE + // BOOT on both kernels, the remaining handlers are skipped, the + // original error reaches the caller unwrapped, and the kernel is left + // 'stopped' rather than 'running' so a failed boot never reads as a + // live kernel. `kernel:ready` got this in #5170; `kernel:bootstrapped` + // and `kernel:listening` in #5257. // - // PROPAGATING dispatch, identical to ObjectKernel's (#5170): a - // `kernel:ready` handler that throws FAILS THE BOOT on both kernels. - // This hook is where plugins assert that what they declared can - // actually be delivered — the registries are still filling during - // init(), so a boot gate has nowhere earlier to run — and a swallowed - // assertion means the process keeps serving without the guarantee it - // announced. The kernel is left 'stopped' rather than 'running', - // mirroring `ObjectKernel.bootstrap()`'s catch, so a failed boot never - // reads as a live kernel. + // Why the boot path is the wrong place to be forgiving: everything + // between here and the log line below is a PRECONDITION of the + // "✅ Bootstrap complete" this method is about to print. Swallowing a + // throw does not make the boot succeed — it only makes the failure + // invisible while `bootstrap()` resolves normally. `kernel:listening` + // is the sharpest case: it is where HTTP server plugins actually open + // their socket (`HonoServerPlugin` awaits `server.listen(port)` with + // no try/catch of its own, deliberately — propagation is the correct + // behaviour there), so a swallowed EACCES / unavailable-listen on an + // edge or serverless host produced a live process, a cheerful + // "Bootstrap complete", and not one socket listening. try { + // Route/middleware registration phase, and the only correct moment + // for a plugin to assert that what it DECLARED can actually be + // delivered — the registries are still filling during init(), so a + // boot gate has nowhere earlier to run (#5170). await this.triggerHookOrThrow('kernel:ready'); + // "All synchronous bootstrap has settled" anchor, strictly after + // every kernel:ready handler has settled and before any HTTP socket + // opens. Carries reconcile/backfill/audit work. NOTE: does not + // guarantee background app seed data has settled — subscribe + // `app:seeded` for that (see plugin-lifecycle-events.ts). + await this.triggerHookOrThrow('kernel:bootstrapped'); + // HTTP servers open their listening socket here — strictly after + // every kernel:ready and kernel:bootstrapped handler has completed. + await this.triggerHookOrThrow('kernel:listening'); } catch (error) { this.state = 'stopped'; throw error; } - // Trigger bootstrapped hook — "all synchronous bootstrap has settled" - // anchor, strictly after every kernel:ready handler has settled and - // before any HTTP socket opens. NOTE: does not guarantee background app - // seed data has settled — subscribe `app:seeded` for that - // (see plugin-lifecycle-events.ts). - await this.triggerHook('kernel:bootstrapped'); - // Trigger listening hook (HTTP servers open their socket here — - // strictly after every kernel:ready handler has completed). - await this.triggerHook('kernel:listening'); - this.logger.info('✅ Bootstrap complete', { - pluginCount: this.plugins.size + this.logger.info('✅ Bootstrap complete', { + pluginCount: this.plugins.size }); } @@ -131,7 +144,17 @@ export class LiteKernel extends ObjectKernelBase { this.state = 'stopping'; this.logger.info('Shutdown started'); - // Trigger shutdown hook + // Trigger shutdown hook — FAIL-SOFT dispatch ({@link triggerHook}), + // deliberately, and NOT the propagating dispatcher the boot-path hooks + // above use (#5257). This is a per-hook judgement written down, not an + // inherited default: on the shutdown path there is no "refuse to + // proceed" left to buy. The remaining work — every other subscriber's + // cleanup, then each plugin's destroy() in reverse order — is what + // flushes buffers, closes connections and releases locks, so letting + // one subscriber's failure abort the rest converts a single bad + // handler into leaked resources and unflushed writes. A failing + // shutdown handler is logged (`Hook handler failed: kernel:shutdown`) + // and the cleanup continues. await this.triggerHook('kernel:shutdown'); // Destroy plugins in reverse order