Skip to content
Draft
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
19 changes: 19 additions & 0 deletions .changeset/core-plugin-startup-duration-name.md
Original file line number Diff line number Diff line change
@@ -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 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:

- `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.
12 changes: 7 additions & 5 deletions packages/core/ADVANCED_FEATURES.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -327,7 +328,8 @@ Both kernels adhere to the same `Plugin` interface, but `ObjectKernel` supports
- `async shutdown(): Promise<void>`
- `async checkPluginHealth(pluginName: string): Promise<PluginHealthStatus>`
- `async checkAllPluginsHealth(): Promise<Map<string, PluginHealthStatus>>`
- `getPluginMetrics(): Map<string, number>`
- `getPluginStartupDurations(): Map<string, number>`
- `getPluginMetrics(): Map<string, number>` *(deprecated alias of the above)*
- `async getServiceAsync<T>(name: string, scopeId?: string): Promise<T>`
- `onShutdown(handler: () => Promise<void>): void`
- `getState(): string`
Expand Down
10 changes: 5 additions & 5 deletions packages/core/examples/kernel-features-example.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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('');

Expand Down
72 changes: 72 additions & 0 deletions packages/core/src/kernel.test.ts
Original file line number Diff line number Diff line change
@@ -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';

Expand Down Expand Up @@ -582,6 +583,77 @@ 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<PluginStartupResult> =>
(kernel as unknown as {
startPluginWithTimeout(p: PluginMetadata): Promise<PluginStartupResult>;
}).startPluginWithTimeout(meta);

const okMeta: PluginMetadata = {
name: 'ok-plugin',
version: '1.0.0',
init: async () => {},
start: async () => {
await new Promise(resolve => setTimeout(resolve, 20));
},
};
const ok = await callStart(okMeta);

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 failingMeta: PluginMetadata = {
name: 'failing-plugin',
version: '1.0.0',
init: async () => {},
start: async () => {
throw new Error('boom');
},
};
const failed = await callStart(failingMeta);

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', () => {
Expand Down
30 changes: 27 additions & 3 deletions packages/core/src/kernel.ts
Original file line number Diff line number Diff line change
Expand Up @@ -66,7 +66,12 @@ export class ObjectKernel {
private pluginLoader: PluginLoader;
private config: ObjectKernelConfig;
private startedPlugins: Set<string> = new Set();
private pluginStartTimes: Map<string, number> = 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<string, number> = new Map();
private shutdownHandlers: Array<() => Promise<void>> = [];
/**
* Name of the plugin whose init() is currently executing (Phase 1 is
Expand Down Expand Up @@ -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<string, number> {
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<string, number> {
return new Map(this.pluginStartTimes);
return this.getPluginStartupDurations();
}

/**
Expand Down Expand Up @@ -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) {
Expand All @@ -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,
};
Expand Down
20 changes: 20 additions & 0 deletions packages/core/src/plugin-loader.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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 `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
* 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;
Expand Down
Loading