Skip to content

Commit 66dc6ab

Browse files
claude[bot]claude
andauthored
fix(core): plugin startup elapsed time is durationMs, the unit-bearing name its spec contract declares (#16057)
* 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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ * 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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ * 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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ * 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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ * fix(core): spell the plugin startup elapsed time `durationMs`, the unit-bearing name its spec contract declares Discharges contract review 5555409410 on PR #16057 (head 4d20aa7): the new published member was spelled `duration`, a key `packages/spec` has since retired. Measured on origin/main f377394: `packages/spec/src/kernel/startup-orchestrator.zod.ts:173` declares `durationMs`; `:176` tombstones `duration` with `retiredKey()` ("Rename the key to `durationMs`"); the gate `packages/spec/scripts/check-duration-unit-keys.ts` is in the tree (landed e9fcd6b). Two maintainer rulings make the rule govern every runtime-emitted duration, and a per-plugin startup elapsed time on a public result type is one. - `PluginStartupResult.durationMs?: number` replaces the never-released `duration?: number`; both emit sites in `kernel.ts` follow; `startTime` keeps its deprecated-alias treatment exactly as before. - The provenance sentence in the interface JSDoc (which ships in the published `dist/index.d.ts`), in `kernel.ts`'s `{@link}` and in the changeset cited the retired `PluginStartupResultSchema.duration`; all three now cite `durationMs` and say the bare spelling is retired. - The two pin tests read `.durationMs`; their ceiling assertion is unchanged. No ADR-0087 treatment on the core side: the spec tombstone entry (`packages/spec/src/migrations/entries/retired-keys/18.kernel__PluginStartupResult__duration.ts`) records that core's interface is a different type and not a reader of the schema; core simply does not adopt the retired spelling. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --------- Co-authored-by: claude[bot] <209825114+claude[bot]@users.noreply.github.com> Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
1 parent eddd612 commit 66dc6ab

6 files changed

Lines changed: 151 additions & 13 deletions

File tree

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
---
2+
"@objectstack/core": minor
3+
---
4+
5+
Plugin startup elapsed time is now reported as `durationMs` — the unit-bearing name the spec contract for the same result declares. `startTime`, which never held a start time, is deprecated and still populated.
6+
7+
`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.
8+
9+
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 `durationMs: 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 bare `duration` spelling is retired there with a `retiredKey()` tombstone whose prescription is "Rename the key to `durationMs`", because a duration-shaped number carries its unit in its key name, never only in describe prose. The contract surface was already correct and `packages/core` had drifted away from it. The same computation already has an honest name twelve lines above the defect in the same file: `PluginLoadResult.loadTime` carries the identical `Date.now() - startTime` under a name that does not lie.
10+
11+
Three sites move, and every one of them is additive — nothing is removed, so no consumer has to change anything on this release:
12+
13+
- `PluginStartupResult` gains `durationMs?: 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.
14+
- `ObjectKernel.getPluginStartupDurations()` is added; `getPluginMetrics()` becomes a `@deprecated` delegating alias returning the same map.
15+
- The private `pluginStartTimes` map is renamed `pluginStartupDurations` (private; no reader outside `kernel.ts` in this repo or in the pinned `objectui` sibling).
16+
17+
Migration, where you want it: read `result.durationMs` 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.
18+
19+
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, and that schema's own `duration` tombstone entry (`packages/spec/src/migrations/entries/retired-keys/18.kernel__PluginStartupResult__duration.ts`) records that core's interface is not a reader of it. Core simply does not adopt the retired spelling. When the deprecated spellings are removed, that removal is the change that carries the ledger disposition.

packages/core/ADVANCED_FEATURES.md

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -223,14 +223,15 @@ for (const [pluginName, health] of allHealth) {
223223

224224
### 7. Performance Metrics
225225

226-
Track plugin startup times:
226+
Track plugin startup durations -- the map values are elapsed milliseconds,
227+
not start instants:
227228

228229
```typescript
229230
await kernel.bootstrap();
230231

231-
const metrics = kernel.getPluginMetrics();
232-
for (const [pluginName, startTime] of metrics) {
233-
console.log(`${pluginName}: ${startTime}ms`);
232+
const durations = kernel.getPluginStartupDurations();
233+
for (const [pluginName, duration] of durations) {
234+
console.log(`${pluginName}: ${duration}ms`);
234235
}
235236
// plugin-1: 150ms
236237
// plugin-2: 320ms
@@ -327,7 +328,8 @@ Both kernels adhere to the same `Plugin` interface, but `ObjectKernel` supports
327328
- `async shutdown(): Promise<void>`
328329
- `async checkPluginHealth(pluginName: string): Promise<PluginHealthStatus>`
329330
- `async checkAllPluginsHealth(): Promise<Map<string, PluginHealthStatus>>`
330-
- `getPluginMetrics(): Map<string, number>`
331+
- `getPluginStartupDurations(): Map<string, number>`
332+
- `getPluginMetrics(): Map<string, number>` *(deprecated alias of the above)*
331333
- `async getServiceAsync<T>(name: string, scopeId?: string): Promise<T>`
332334
- `onShutdown(handler: () => Promise<void>): void`
333335
- `getState(): string`

packages/core/examples/kernel-features-example.ts

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -232,11 +232,11 @@ async function main() {
232232

233233
console.log('\n✅ Kernel started successfully!\n');
234234

235-
// Show plugin metrics
236-
console.log('📊 Plugin Startup Metrics:');
237-
const metrics = kernel.getPluginMetrics();
238-
for (const [name, time] of metrics) {
239-
console.log(` ${name}: ${time}ms`);
235+
// Show plugin startup durations (elapsed ms, not start instants)
236+
console.log('📊 Plugin Startup Durations:');
237+
const durations = kernel.getPluginStartupDurations();
238+
for (const [name, duration] of durations) {
239+
console.log(` ${name}: ${duration}ms`);
240240
}
241241
console.log('');
242242

packages/core/src/kernel.test.ts

Lines changed: 72 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
22
import { ObjectKernel } from './kernel';
33
import { ServiceLifecycle, PluginMetadata } from './plugin-loader';
4+
import type { PluginStartupResult } from './plugin-loader';
45
import type { Plugin, PluginContext } from './types';
56
import { recordGuards, stillPinningTheLoop } from '@objectstack/refd-timer-testkit';
67

@@ -582,6 +583,77 @@ describe('ObjectKernel', () => {
582583

583584
await kernel.shutdown();
584585
});
586+
587+
// These two pin the MEANING of the number, not merely that one is
588+
// present. The result member carrying it was spelled `startTime` while
589+
// holding `Date.now() - start`, so a reader who correctly took it for an
590+
// instant and wrote `Date.now() - result.startTime` got an age near the
591+
// epoch. `toBeGreaterThan(0)` cannot tell the two readings apart -- an
592+
// epoch-millisecond instant passes it too. A ceiling can: any instant
593+
// today is ~1.7e12, orders of magnitude above any plugin's start().
594+
const INSTANT_FLOOR_MS = 1_000_000_000; // ~11.5 days as a duration; well below any real epoch-ms instant
595+
596+
it('getPluginStartupDurations reports elapsed durations, not start instants', async () => {
597+
const plugin: Plugin = {
598+
name: 'timed-plugin',
599+
version: '1.0.0',
600+
init: async () => {},
601+
start: async () => {
602+
await new Promise(resolve => setTimeout(resolve, 20));
603+
},
604+
};
605+
606+
await kernel.use(plugin);
607+
await kernel.bootstrap();
608+
609+
const durations = kernel.getPluginStartupDurations();
610+
const value = durations.get('timed-plugin');
611+
612+
expect(value).toBeGreaterThan(0);
613+
expect(value).toBeLessThan(INSTANT_FLOOR_MS);
614+
// The deprecated alias is the same map, so it must agree.
615+
expect(kernel.getPluginMetrics().get('timed-plugin')).toBe(value);
616+
617+
await kernel.shutdown();
618+
});
619+
620+
it('PluginStartupResult.durationMs is an elapsed duration on both the success and the failure path', async () => {
621+
const callStart = (meta: PluginMetadata): Promise<PluginStartupResult> =>
622+
(kernel as unknown as {
623+
startPluginWithTimeout(p: PluginMetadata): Promise<PluginStartupResult>;
624+
}).startPluginWithTimeout(meta);
625+
626+
const okMeta: PluginMetadata = {
627+
name: 'ok-plugin',
628+
version: '1.0.0',
629+
init: async () => {},
630+
start: async () => {
631+
await new Promise(resolve => setTimeout(resolve, 20));
632+
},
633+
};
634+
const ok = await callStart(okMeta);
635+
636+
expect(ok.success).toBe(true);
637+
expect(ok.durationMs).toBeGreaterThan(0);
638+
expect(ok.durationMs).toBeLessThan(INSTANT_FLOOR_MS);
639+
// The deprecated alias carries the same elapsed value, not an instant.
640+
expect(ok.startTime).toBe(ok.durationMs);
641+
642+
const failingMeta: PluginMetadata = {
643+
name: 'failing-plugin',
644+
version: '1.0.0',
645+
init: async () => {},
646+
start: async () => {
647+
throw new Error('boom');
648+
},
649+
};
650+
const failed = await callStart(failingMeta);
651+
652+
expect(failed.success).toBe(false);
653+
expect(failed.durationMs).toBeGreaterThanOrEqual(0);
654+
expect(failed.durationMs).toBeLessThan(INSTANT_FLOOR_MS);
655+
expect(failed.startTime).toBe(failed.durationMs);
656+
});
585657
});
586658

587659
describe('Graceful Shutdown', () => {

packages/core/src/kernel.ts

Lines changed: 27 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -66,7 +66,12 @@ export class ObjectKernel {
6666
private pluginLoader: PluginLoader;
6767
private config: ObjectKernelConfig;
6868
private startedPlugins: Set<string> = new Set();
69-
private pluginStartTimes: Map<string, number> = new Map();
69+
/**
70+
* Plugin name -> elapsed milliseconds that plugin's `start()` took. These
71+
* are DURATIONS, never start instants; the old spelling `pluginStartTimes`
72+
* said the opposite of what it held.
73+
*/
74+
private pluginStartupDurations: Map<string, number> = new Map();
7075
private shutdownHandlers: Array<() => Promise<void>> = [];
7176
/**
7277
* Name of the plugin whose init() is currently executing (Phase 1 is
@@ -533,11 +538,24 @@ export class ObjectKernel {
533538
return results;
534539
}
535540

541+
/**
542+
* Per-plugin startup durations: plugin name -> elapsed milliseconds that
543+
* plugin's `start()` took. Not start instants -- see
544+
* {@link PluginStartupResult.durationMs}.
545+
*/
546+
getPluginStartupDurations(): Map<string, number> {
547+
return new Map(this.pluginStartupDurations);
548+
}
549+
536550
/**
537551
* Get plugin startup metrics
552+
*
553+
* @deprecated Renamed to {@link ObjectKernel.getPluginStartupDurations},
554+
* which states what the values are. Retained as a delegating alias so
555+
* nothing has to change on this release; slated for removal.
538556
*/
539557
getPluginMetrics(): Map<string, number> {
540-
return new Map(this.pluginStartTimes);
558+
return this.getPluginStartupDurations();
541559
}
542560

543561
/**
@@ -684,13 +702,16 @@ export class ObjectKernel {
684702

685703
const duration = Date.now() - startTime;
686704
this.startedPlugins.add(plugin.name);
687-
this.pluginStartTimes.set(plugin.name, duration);
705+
this.pluginStartupDurations.set(plugin.name, duration);
688706

689707
this.logger.debug(`Plugin started: ${plugin.name} (${duration}ms)`);
690708

691709
return {
692710
success: true,
693711
pluginName: plugin.name,
712+
durationMs: duration,
713+
// Deprecated alias carrying the same elapsed value; see
714+
// PluginStartupResult.startTime.
694715
startTime: duration,
695716
};
696717
} catch (error) {
@@ -701,6 +722,9 @@ export class ObjectKernel {
701722
success: false,
702723
pluginName: plugin.name,
703724
error: error as Error,
725+
durationMs: duration,
726+
// Deprecated alias carrying the same elapsed value; see
727+
// PluginStartupResult.startTime.
704728
startTime: duration,
705729
timedOut: isTimeout,
706730
};

packages/core/src/plugin-loader.ts

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -91,6 +91,27 @@ export interface PluginLoadResult {
9191
export interface PluginStartupResult {
9292
success: boolean;
9393
pluginName: string;
94+
/**
95+
* Elapsed milliseconds the plugin's `start()` took.
96+
*
97+
* Named for the member `packages/spec` declares for the same measure --
98+
* `PluginStartupResultSchema.durationMs` in
99+
* `packages/spec/src/kernel/startup-orchestrator.zod.ts` ("Time taken to
100+
* start the plugin in milliseconds"), where the bare `duration` spelling is
101+
* retired: a duration-shaped number carries its unit in its key name. Like
102+
* `PluginLoadResult.loadTime` above, it is the same `Date.now() - startTime`
103+
* computation under a name that does not lie.
104+
*/
105+
durationMs?: number;
106+
/**
107+
* The same elapsed milliseconds as {@link PluginStartupResult.durationMs}.
108+
*
109+
* @deprecated Misnamed: this has never held an instant, so a reader who
110+
* correctly takes `startTime` for one and writes `Date.now() - result.startTime`
111+
* gets an age near the epoch instead of a wait. Read `durationMs` instead.
112+
* Still populated so nothing has to change on this release (ADR-0087 L1 --
113+
* the old shape keeps working while the fleet moves); slated for removal.
114+
*/
94115
startTime?: number;
95116
error?: Error;
96117
timedOut?: boolean;

0 commit comments

Comments
 (0)