From b52b5cd528d5eecb0e315cfe1a3f1fbebef25ce7 Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Sat, 5 Sep 2026 22:08:22 +0000 Subject: [PATCH 1/4] fix(core): plugin startup elapsed time is `duration`, the name its spec contract already uses `PluginStartupResult.startTime` has always carried `Date.now() - startTime`, an elapsed duration, so the name asserts the opposite of the value: a reader who correctly takes it for an instant and writes `Date.now() - result.startTime` gets an age near the epoch. `packages/spec/src/kernel/startup-orchestrator.zod.ts` already declares the correct name for the same measure (`duration`, "Time taken to start the plugin in milliseconds"), and `PluginLoadResult.loadTime` twelve lines above the defect already spells the identical computation truthfully -- so this is a declared-vs-enforced divergence between `packages/core` and the spec contract it implements, not a naming preference. Three sites, all additive (nothing is removed, so no consumer changes): - `PluginStartupResult` gains `duration?: number`; `startTime` stays, populated with the same value, marked `@deprecated` with a doc comment that states plainly what it holds (ADR-0087 L1 -- the old shape keeps working). - the private `pluginStartTimes` map is renamed `pluginStartupDurations` (private; measured zero readers outside `kernel.ts`). - `getPluginStartupDurations()` is added and `getPluginMetrics()` becomes a deprecated delegating alias. Pin tests assert the value is a bounded elapsed duration rather than an epoch-millisecond instant, on the success and the failure path -- the assertion `toBeGreaterThan(0)` could never make. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --- packages/core/ADVANCED_FEATURES.md | 12 ++-- .../core/examples/kernel-features-example.ts | 10 +-- packages/core/src/kernel.test.ts | 68 +++++++++++++++++++ packages/core/src/kernel.ts | 30 +++++++- packages/core/src/plugin-loader.ts | 20 ++++++ 5 files changed, 127 insertions(+), 13 deletions(-) diff --git a/packages/core/ADVANCED_FEATURES.md b/packages/core/ADVANCED_FEATURES.md index a949cfb106..54bfc036c2 100644 --- a/packages/core/ADVANCED_FEATURES.md +++ b/packages/core/ADVANCED_FEATURES.md @@ -223,14 +223,15 @@ for (const [pluginName, health] of allHealth) { ### 7. Performance Metrics -Track plugin startup times: +Track plugin startup durations -- the map values are elapsed milliseconds, +not start instants: ```typescript await kernel.bootstrap(); -const metrics = kernel.getPluginMetrics(); -for (const [pluginName, startTime] of metrics) { - console.log(`${pluginName}: ${startTime}ms`); +const durations = kernel.getPluginStartupDurations(); +for (const [pluginName, duration] of durations) { + console.log(`${pluginName}: ${duration}ms`); } // plugin-1: 150ms // plugin-2: 320ms @@ -327,7 +328,8 @@ Both kernels adhere to the same `Plugin` interface, but `ObjectKernel` supports - `async shutdown(): Promise` - `async checkPluginHealth(pluginName: string): Promise` - `async checkAllPluginsHealth(): Promise>` -- `getPluginMetrics(): Map` +- `getPluginStartupDurations(): Map` +- `getPluginMetrics(): Map` *(deprecated alias of the above)* - `async getServiceAsync(name: string, scopeId?: string): Promise` - `onShutdown(handler: () => Promise): void` - `getState(): string` diff --git a/packages/core/examples/kernel-features-example.ts b/packages/core/examples/kernel-features-example.ts index a6466bf58d..f0da416669 100644 --- a/packages/core/examples/kernel-features-example.ts +++ b/packages/core/examples/kernel-features-example.ts @@ -232,11 +232,11 @@ async function main() { console.log('\nāœ… Kernel started successfully!\n'); - // Show plugin metrics - console.log('šŸ“Š Plugin Startup Metrics:'); - const metrics = kernel.getPluginMetrics(); - for (const [name, time] of metrics) { - console.log(` ${name}: ${time}ms`); + // Show plugin startup durations (elapsed ms, not start instants) + console.log('šŸ“Š Plugin Startup Durations:'); + const durations = kernel.getPluginStartupDurations(); + for (const [name, duration] of durations) { + console.log(` ${name}: ${duration}ms`); } console.log(''); diff --git a/packages/core/src/kernel.test.ts b/packages/core/src/kernel.test.ts index 2d5e38f477..4c7b9d5906 100644 --- a/packages/core/src/kernel.test.ts +++ b/packages/core/src/kernel.test.ts @@ -1,6 +1,7 @@ import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; import { ObjectKernel } from './kernel'; import { ServiceLifecycle, PluginMetadata } from './plugin-loader'; +import type { PluginStartupResult } from './plugin-loader'; import type { Plugin, PluginContext } from './types'; import { recordGuards, stillPinningTheLoop } from '@objectstack/refd-timer-testkit'; @@ -582,6 +583,73 @@ describe('ObjectKernel', () => { await kernel.shutdown(); }); + + // These two pin the MEANING of the number, not merely that one is + // present. The result member carrying it was spelled `startTime` while + // holding `Date.now() - start`, so a reader who correctly took it for an + // instant and wrote `Date.now() - result.startTime` got an age near the + // epoch. `toBeGreaterThan(0)` cannot tell the two readings apart -- an + // epoch-millisecond instant passes it too. A ceiling can: any instant + // today is ~1.7e12, orders of magnitude above any plugin's start(). + const INSTANT_FLOOR_MS = 1_000_000_000; // ~11.5 days as a duration; well below any real epoch-ms instant + + it('getPluginStartupDurations reports elapsed durations, not start instants', async () => { + const plugin: Plugin = { + name: 'timed-plugin', + version: '1.0.0', + init: async () => {}, + start: async () => { + await new Promise(resolve => setTimeout(resolve, 20)); + }, + }; + + await kernel.use(plugin); + await kernel.bootstrap(); + + const durations = kernel.getPluginStartupDurations(); + const value = durations.get('timed-plugin'); + + expect(value).toBeGreaterThan(0); + expect(value).toBeLessThan(INSTANT_FLOOR_MS); + // The deprecated alias is the same map, so it must agree. + expect(kernel.getPluginMetrics().get('timed-plugin')).toBe(value); + + await kernel.shutdown(); + }); + + it('PluginStartupResult.duration is an elapsed duration on both the success and the failure path', async () => { + const callStart = (meta: PluginMetadata): Promise => + (kernel as unknown as { + startPluginWithTimeout(p: PluginMetadata): Promise; + }).startPluginWithTimeout(meta); + + const ok = await callStart({ + name: 'ok-plugin', + version: '1.0.0', + start: async () => { + await new Promise(resolve => setTimeout(resolve, 20)); + }, + } as PluginMetadata); + + expect(ok.success).toBe(true); + expect(ok.duration).toBeGreaterThan(0); + expect(ok.duration).toBeLessThan(INSTANT_FLOOR_MS); + // The deprecated alias carries the same elapsed value, not an instant. + expect(ok.startTime).toBe(ok.duration); + + const failed = await callStart({ + name: 'failing-plugin', + version: '1.0.0', + start: async () => { + throw new Error('boom'); + }, + } as PluginMetadata); + + expect(failed.success).toBe(false); + expect(failed.duration).toBeGreaterThanOrEqual(0); + expect(failed.duration).toBeLessThan(INSTANT_FLOOR_MS); + expect(failed.startTime).toBe(failed.duration); + }); }); describe('Graceful Shutdown', () => { diff --git a/packages/core/src/kernel.ts b/packages/core/src/kernel.ts index 81a869b5f1..7285dfcb54 100644 --- a/packages/core/src/kernel.ts +++ b/packages/core/src/kernel.ts @@ -66,7 +66,12 @@ export class ObjectKernel { private pluginLoader: PluginLoader; private config: ObjectKernelConfig; private startedPlugins: Set = new Set(); - private pluginStartTimes: Map = new Map(); + /** + * Plugin name -> elapsed milliseconds that plugin's `start()` took. These + * are DURATIONS, never start instants; the old spelling `pluginStartTimes` + * said the opposite of what it held. + */ + private pluginStartupDurations: Map = new Map(); private shutdownHandlers: Array<() => Promise> = []; /** * Name of the plugin whose init() is currently executing (Phase 1 is @@ -533,11 +538,24 @@ export class ObjectKernel { return results; } + /** + * Per-plugin startup durations: plugin name -> elapsed milliseconds that + * plugin's `start()` took. Not start instants -- see + * {@link PluginStartupResult.duration}. + */ + getPluginStartupDurations(): Map { + return new Map(this.pluginStartupDurations); + } + /** * Get plugin startup metrics + * + * @deprecated Renamed to {@link ObjectKernel.getPluginStartupDurations}, + * which states what the values are. Retained as a delegating alias so + * nothing has to change on this release; slated for removal. */ getPluginMetrics(): Map { - return new Map(this.pluginStartTimes); + return this.getPluginStartupDurations(); } /** @@ -684,13 +702,16 @@ export class ObjectKernel { const duration = Date.now() - startTime; this.startedPlugins.add(plugin.name); - this.pluginStartTimes.set(plugin.name, duration); + this.pluginStartupDurations.set(plugin.name, duration); this.logger.debug(`Plugin started: ${plugin.name} (${duration}ms)`); return { success: true, pluginName: plugin.name, + duration, + // Deprecated alias carrying the same elapsed value; see + // PluginStartupResult.startTime. startTime: duration, }; } catch (error) { @@ -701,6 +722,9 @@ export class ObjectKernel { success: false, pluginName: plugin.name, error: error as Error, + duration, + // Deprecated alias carrying the same elapsed value; see + // PluginStartupResult.startTime. startTime: duration, timedOut: isTimeout, }; diff --git a/packages/core/src/plugin-loader.ts b/packages/core/src/plugin-loader.ts index 24c3c31c51..bb9abd5e0c 100644 --- a/packages/core/src/plugin-loader.ts +++ b/packages/core/src/plugin-loader.ts @@ -91,6 +91,26 @@ export interface PluginLoadResult { export interface PluginStartupResult { success: boolean; pluginName: string; + /** + * Elapsed milliseconds the plugin's `start()` took. + * + * Named for the member the spec contract this result implements already + * declares -- `PluginStartupResultSchema.duration` in + * `packages/spec/src/kernel/startup-orchestrator.zod.ts` ("Time taken to + * start the plugin in milliseconds") -- and matching `PluginLoadResult.loadTime` + * above: the same `Date.now() - startTime` computation under a name that + * does not lie. + */ + duration?: number; + /** + * The same elapsed milliseconds as {@link PluginStartupResult.duration}. + * + * @deprecated Misnamed: this has never held an instant, so a reader who + * correctly takes `startTime` for one and writes `Date.now() - result.startTime` + * gets an age near the epoch instead of a wait. Read `duration` instead. + * Still populated so nothing has to change on this release (ADR-0087 L1 -- + * the old shape keeps working while the fleet moves); slated for removal. + */ startTime?: number; error?: Error; timedOut?: boolean; From 5ad759ec91be35d1b2f97b7dff5aa10354170491 Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Sat, 5 Sep 2026 22:15:30 +0000 Subject: [PATCH 2/4] test(core): type the pin-test plugin metadata instead of casting it `PluginMetadata` requires `init`, so the object-literal `as` casts tripped TS2352 under `tsconfig.test.json`. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --- packages/core/src/kernel.test.ts | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/packages/core/src/kernel.test.ts b/packages/core/src/kernel.test.ts index 4c7b9d5906..67f98858a0 100644 --- a/packages/core/src/kernel.test.ts +++ b/packages/core/src/kernel.test.ts @@ -623,13 +623,15 @@ describe('ObjectKernel', () => { startPluginWithTimeout(p: PluginMetadata): Promise; }).startPluginWithTimeout(meta); - const ok = await callStart({ + const okMeta: PluginMetadata = { name: 'ok-plugin', version: '1.0.0', + init: async () => {}, start: async () => { await new Promise(resolve => setTimeout(resolve, 20)); }, - } as PluginMetadata); + }; + const ok = await callStart(okMeta); expect(ok.success).toBe(true); expect(ok.duration).toBeGreaterThan(0); @@ -637,13 +639,15 @@ describe('ObjectKernel', () => { // The deprecated alias carries the same elapsed value, not an instant. expect(ok.startTime).toBe(ok.duration); - const failed = await callStart({ + const failingMeta: PluginMetadata = { name: 'failing-plugin', version: '1.0.0', + init: async () => {}, start: async () => { throw new Error('boom'); }, - } as PluginMetadata); + }; + const failed = await callStart(failingMeta); expect(failed.success).toBe(false); expect(failed.duration).toBeGreaterThanOrEqual(0); From 96e3ddd3e702820071415dd1e4e46a3b5b3bcddf Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Sat, 5 Sep 2026 22:23:37 +0000 Subject: [PATCH 3/4] chore(changeset): minor for the additive `duration` widening on @objectstack/core Additive widening of a published package's public surface (a new exported member on `PluginStartupResult`, a new method on `ObjectKernel`) takes at least `minor` per the `Check Changeset` step's WHICH LEVEL prose; the act wins over the `fix(` commit type. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --- .../core-plugin-startup-duration-name.md | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+) create mode 100644 .changeset/core-plugin-startup-duration-name.md diff --git a/.changeset/core-plugin-startup-duration-name.md b/.changeset/core-plugin-startup-duration-name.md new file mode 100644 index 0000000000..39deabd4dc --- /dev/null +++ b/.changeset/core-plugin-startup-duration-name.md @@ -0,0 +1,19 @@ +--- +"@objectstack/core": minor +--- + +Plugin startup elapsed time is now reported as `duration` ā€” the name the spec contract for the same result already declares. `startTime`, which never held a start time, is deprecated and still populated. + +`PluginStartupResult.startTime` (`packages/core/src/plugin-loader.ts`) has always been assigned `Date.now() - startTime`, an elapsed duration, on both the success and the failure path. The name therefore asserts the opposite of the value: a reader who correctly takes `startTime` for an instant and writes `Date.now() - result.startTime` gets an age near the epoch rather than a wait. That is the one failure mode a unit convention cannot rescue ā€” an ambiguous name makes someone stop and check, this one lets them proceed confidently wrong. + +This is not a naming preference but a divergence between what is declared and what is enforced. `packages/spec/src/kernel/startup-orchestrator.zod.ts` declares `duration: z.number().min(0)` ā€” "Time taken to start the plugin in milliseconds" ā€” for the very result this interface implements, so the contract was already correct and `packages/core` had drifted away from it. The right spelling is also twelve lines above the defect in the same file: `PluginLoadResult.loadTime` carries the identical `Date.now() - startTime` computation under a name that does not lie. + +Three sites move, and every one of them is additive ā€” nothing is removed, so no consumer has to change anything on this release: + +- `PluginStartupResult` gains `duration?: number`. `startTime?: number` stays, still carrying the same value, marked `@deprecated` with a doc comment that states plainly it is elapsed milliseconds and not an instant. +- `ObjectKernel.getPluginStartupDurations()` is added; `getPluginMetrics()` becomes a `@deprecated` delegating alias returning the same map. +- The private `pluginStartTimes` map is renamed `pluginStartupDurations` (private; no reader outside `kernel.ts` in this repo or in the pinned `objectui` sibling). + +Migration, where you want it: read `result.duration` where you read `result.startTime`, and `kernel.getPluginStartupDurations()` where you called `kernel.getPluginMetrics()`. The values are identical, so the change can be made at leisure; both old spellings keep working until they are removed. + +ADR-0087 disposition: no migration-ledger entry, and none is required. Nothing is retired by this release ā€” the old member and the old method both remain, populated and callable, which is ADR-0087's L1 outcome (the old shape keeps loading while the fleet moves) rather than a retirement. There is also nothing for `objectstack migrate meta` to rewrite: `packages/core/src/plugin-loader.ts#PluginStartupResult` is a runtime TypeScript interface with no Zod schema, no `packages/spec` declaration and no stored representation ā€” the `PluginStartupResult` in `packages/spec/src/kernel/startup-orchestrator.zod.ts` is a separate, differently-shaped declaration that this change does not touch. When the deprecated spellings are removed, that removal is the change that carries the ledger disposition. From 4d20aa70eebb7b18abae050d8a81528c1da0e2df Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Sat, 5 Sep 2026 22:33:03 +0000 Subject: [PATCH 4/4] docs(core): say 'declares the same measure', not 'the contract this result implements' Measured: `packages/core` neither imports nor references `packages/spec/src/kernel/startup-orchestrator.zod.ts`, and nothing in the repo implements `IStartupOrchestrator`. The two `PluginStartupResult` declarations describe the same domain result and share no shape, so 'implements' overstated a relationship that does not exist in code. The reason to take the contract's name is unchanged: it is the name the spec surface declares for this measure. Filed separately as the wider question this made visible. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --- .changeset/core-plugin-startup-duration-name.md | 2 +- packages/core/src/plugin-loader.ts | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/.changeset/core-plugin-startup-duration-name.md b/.changeset/core-plugin-startup-duration-name.md index 39deabd4dc..417dbe0651 100644 --- a/.changeset/core-plugin-startup-duration-name.md +++ b/.changeset/core-plugin-startup-duration-name.md @@ -6,7 +6,7 @@ Plugin startup elapsed time is now reported as `duration` ā€” the name the spec `PluginStartupResult.startTime` (`packages/core/src/plugin-loader.ts`) has always been assigned `Date.now() - startTime`, an elapsed duration, on both the success and the failure path. The name therefore asserts the opposite of the value: a reader who correctly takes `startTime` for an instant and writes `Date.now() - result.startTime` gets an age near the epoch rather than a wait. That is the one failure mode a unit convention cannot rescue ā€” an ambiguous name makes someone stop and check, this one lets them proceed confidently wrong. -This is not a naming preference but a divergence between what is declared and what is enforced. `packages/spec/src/kernel/startup-orchestrator.zod.ts` declares `duration: z.number().min(0)` ā€” "Time taken to start the plugin in milliseconds" ā€” for the very result this interface implements, so the contract was already correct and `packages/core` had drifted away from it. The right spelling is also twelve lines above the defect in the same file: `PluginLoadResult.loadTime` carries the identical `Date.now() - startTime` computation under a name that does not lie. +This is not a naming preference but a divergence between what is declared and what is enforced. `packages/spec/src/kernel/startup-orchestrator.zod.ts` declares `duration: z.number().min(0)` ā€” "Time taken to start the plugin in milliseconds" ā€” for the same measure on the same result, the outcome of starting one plugin. The contract surface was already correct and `packages/core` had drifted away from it. The right spelling is also twelve lines above the defect in the same file: `PluginLoadResult.loadTime` carries the identical `Date.now() - startTime` computation under a name that does not lie. Three sites move, and every one of them is additive ā€” nothing is removed, so no consumer has to change anything on this release: diff --git a/packages/core/src/plugin-loader.ts b/packages/core/src/plugin-loader.ts index bb9abd5e0c..13c93e4fca 100644 --- a/packages/core/src/plugin-loader.ts +++ b/packages/core/src/plugin-loader.ts @@ -94,8 +94,8 @@ export interface PluginStartupResult { /** * Elapsed milliseconds the plugin's `start()` took. * - * Named for the member the spec contract this result implements already - * declares -- `PluginStartupResultSchema.duration` in + * Named for the member `packages/spec` already declares for the same + * measure -- `PluginStartupResultSchema.duration` in * `packages/spec/src/kernel/startup-orchestrator.zod.ts` ("Time taken to * start the plugin in milliseconds") -- and matching `PluginLoadResult.loadTime` * above: the same `Date.now() - startTime` computation under a name that