From b71f3c76484b519fe721a15148b1c52fb3f253dc Mon Sep 17 00:00:00 2001 From: Michael Hladky Date: Fri, 16 Jan 2026 17:52:11 +0100 Subject: [PATCH 1/7] feat: add NodeJSProfiler --- packages/utils/docs/profiler.md | 255 ++++++++ packages/utils/mocks/sink.mock.ts | 24 +- packages/utils/src/lib/exit-process.ts | 4 +- .../utils/src/lib/performance-observer.ts | 34 +- packages/utils/src/lib/profiler/constants.ts | 1 + .../src/lib/profiler/profiler.int.test.ts | 430 +++++++++++++ packages/utils/src/lib/profiler/profiler.ts | 364 +++++++++++ .../src/lib/profiler/profiler.unit.test.ts | 596 ++++++++++++++++++ packages/utils/src/lib/sink-source.type.ts | 4 +- .../user-timing-extensibility-api-utils.ts | 10 +- 10 files changed, 1705 insertions(+), 17 deletions(-) create mode 100644 packages/utils/docs/profiler.md create mode 100644 packages/utils/src/lib/profiler/constants.ts create mode 100644 packages/utils/src/lib/profiler/profiler.int.test.ts create mode 100644 packages/utils/src/lib/profiler/profiler.ts create mode 100644 packages/utils/src/lib/profiler/profiler.unit.test.ts diff --git a/packages/utils/docs/profiler.md b/packages/utils/docs/profiler.md new file mode 100644 index 000000000..6f0481c6a --- /dev/null +++ b/packages/utils/docs/profiler.md @@ -0,0 +1,255 @@ +# @code-pushup/utils - Profiler + +[![npm](https://img.shields.io/npm/v/%40code-pushup%2Futils.svg)](https://www.npmjs.com/package/@code-pushup/utils) +[![downloads](https://img.shields.io/npm/dm/%40code-pushup%2Futils)](https://npmtrends.com/@code-pushup/utils) +[![dependencies](https://img.shields.io/librariesio/release/npm/%40code-pushup/utils)](https://www.npmjs.com/package/@code-pushup/utils?activeTab=dependencies) + +⏱️ **High-performance profiling utility for structured timing measurements with Chrome DevTools Extensibility API payloads.** 📊 + +--- + +The `Profiler` class provides a clean, type-safe API for performance monitoring that integrates seamlessly with Chrome DevTools. It supports both synchronous and asynchronous operations with smart defaults for custom track visualization, enabling developers to track performance bottlenecks and optimize application speed. + +## Getting started + +1. If you haven't already, install [@code-pushup/utils](../../README.md). + +2. Install as a dependency with your package manager: + + ```sh + npm install @code-pushup/utils + ``` + + ```sh + yarn add @code-pushup/utils + ``` + + ```sh + pnpm add @code-pushup/utils + ``` + +3. Import and create a profiler instance: + + ```ts + import { Profiler } from '@code-pushup/utils'; + + const profiler = new Profiler({ + prefix: 'cp', + track: 'CLI', + trackGroup: 'Code Pushup', + color: 'primary-dark', + tracks: { + utils: { track: 'Utils', color: 'primary' }, + core: { track: 'Core', color: 'primary-light' }, + }, + enabled: true, + }); + ``` + +4. Start measuring performance: + + ```ts + // Measure synchronous operations + const result = profiler.measure('data-processing', () => { + return processData(data); + }); + + // Measure asynchronous operations + const asyncResult = await profiler.measureAsync('api-call', async () => { + return await fetch('/api/data').then(r => r.json()); + }); + ``` + +## Configuration + +```ts +new Profiler(options: ProfilerOptions) +``` + +**Parameters:** + +- `options` - Configuration options for the profiler instance + +**Options:** + +| Property | Type | Default | Description | +| ------------ | --------- | ----------- | --------------------------------------------------------------- | +| `tracks` | `object` | `undefined` | Custom track configurations merged with defaults | +| `prefix` | `string` | `undefined` | Prefix for all measurement names | +| `track` | `string` | `undefined` | Default track name for measurements | +| `trackGroup` | `string` | `undefined` | Default track group for organization | +| `color` | `string` | `undefined` | Default color for track entries | +| `enabled` | `boolean` | `env var` | Whether profiling is enabled (defaults to CP_PROFILING env var) | + +### Environment Variables + +- `CP_PROFILING` - Enables or disables profiling globally (boolean) + +```bash +# Enable profiling in development +CP_PROFILING=true npm run dev + +# Disable profiling in production +CP_PROFILING=false npm run build +``` + +## API Methods + +The profiler provides several methods for different types of performance measurements: + +### Synchronous measurements + +```ts +profiler.measure(event: string, work: () => R, options?: MeasureOptions): R +``` + +Measures the execution time of a synchronous operation. Creates performance start/end marks and a final measure with Chrome DevTools Extensibility API payloads. + +```ts +const result = profiler.measure( + 'file-processing', + () => { + return fs.readFileSync('large-file.txt', 'utf8'); + }, + { + track: 'io-operations', + color: 'warning', + }, +); +``` + +### Asynchronous measurements + +```ts +profiler.measureAsync(event: string, work: () => Promise, options?: MeasureOptions): Promise +``` + +Measures the execution time of an asynchronous operation. + +```ts +const data = await profiler.measureAsync( + 'api-request', + async () => { + const response = await fetch('/api/data'); + return response.json(); + }, + { + track: 'network', + trackGroup: 'external', + }, +); +``` + +### Performance markers + +```ts +profiler.marker(name: string, options?: EntryMeta & { color?: DevToolsColor }): void +``` + +Creates a performance mark with Chrome DevTools marker visualization. Markers appear as vertical lines spanning all tracks and can include custom metadata. + +```ts +profiler.marker('user-action', { + color: 'secondary', + tooltipText: 'User clicked save button', + properties: [ + ['action', 'save'], + ['elementId', 'save-btn'], + ], +}); +``` + +### Runtime control + +```ts +profiler.setEnabled(enabled: boolean): void +profiler.isEnabled(): boolean +``` + +Control profiling at runtime and check current status. + +```ts +// Disable profiling temporarily +profiler.setEnabled(false); + +// Check if profiling is active +if (profiler.isEnabled()) { + console.log('Performance monitoring is active'); +} +``` + +## Examples + +### Basic usage + +```ts +import { Profiler } from '@code-pushup/utils'; + +const profiler = new Profiler({ + prefix: 'cp', + track: 'CLI', + trackGroup: 'Code Pushup', + color: 'primary-dark', + tracks: { + utils: { track: 'Utils', color: 'primary' }, + core: { track: 'Core', color: 'primary-light' }, + }, + enabled: true, +}); + +// Simple measurement +const result = profiler.measure('data-transform', () => { + return transformData(input); +}); + +// Async measurement with custom options +const data = await profiler.measureAsync( + 'fetch-user', + async () => { + return await api.getUser(userId); + }, + { + track: 'api', + color: 'info', + }, +); + +// Add a marker for important events +profiler.marker('user-login', { + tooltipText: 'User authentication completed', +}); +``` + +### Custom tracks + +Define custom track configurations for better organization: + +```ts +interface AppTracks { + api: ActionTrackEntryPayload; + db: ActionTrackEntryPayload; + cache: ActionTrackEntryPayload; +} + +const profiler = new Profiler({ + tracks: { + api: { track: 'api', trackGroup: 'network', color: 'primary' }, + db: { track: 'database', trackGroup: 'data', color: 'warning' }, + cache: { track: 'cache', trackGroup: 'data', color: 'success' }, + }, +}); + +// Use predefined tracks +const users = await profiler.measureAsync('fetch-users', fetchUsers, { + track: 'api', +}); + +const saved = profiler.measure('save-user', () => saveToDb(user), { + track: 'db', +}); +``` + +## Resources + +- **[Chrome DevTools Extensibility API](?)** - Official documentation for performance profiling +- **[User Timing API](https://developer.mozilla.org/en-US/docs/Web/API/User_Timing_API)** - Web Performance API reference diff --git a/packages/utils/mocks/sink.mock.ts b/packages/utils/mocks/sink.mock.ts index 13d89e91c..2ae91c429 100644 --- a/packages/utils/mocks/sink.mock.ts +++ b/packages/utils/mocks/sink.mock.ts @@ -1,4 +1,8 @@ -import type { Sink } from '../src/lib/sink-source.type'; +import type { + RecoverResult, + Recoverable, + Sink, +} from '../src/lib/sink-source.type'; export class MockSink implements Sink { private writtenItems: string[] = []; @@ -28,3 +32,21 @@ export class MockSink implements Sink { return [...this.writtenItems]; } } + +export class MockRecoverableSink extends MockSink implements Recoverable { + recover(): RecoverResult { + return { + records: this.getWrittenItems() as T[], + errors: [], + partialTail: null, + }; + } + + repack(): void { + this.getWrittenItems().forEach(item => this.write(item)); + } + + finalize(): void { + this.close(); + } +} diff --git a/packages/utils/src/lib/exit-process.ts b/packages/utils/src/lib/exit-process.ts index 62cee4977..e2e3f89f8 100644 --- a/packages/utils/src/lib/exit-process.ts +++ b/packages/utils/src/lib/exit-process.ts @@ -44,8 +44,8 @@ export function installExitHandlers(options: ExitHandlerOptions = {}): void { const { onExit, onError, - exitOnFatal, - exitOnSignal, + exitOnFatal = false, + exitOnSignal = false, fatalExitCode = DEFAULT_FATAL_EXIT_CODE, } = options; diff --git a/packages/utils/src/lib/performance-observer.ts b/packages/utils/src/lib/performance-observer.ts index fa5720427..8ccbdd789 100644 --- a/packages/utils/src/lib/performance-observer.ts +++ b/packages/utils/src/lib/performance-observer.ts @@ -6,21 +6,31 @@ import { } from 'node:perf_hooks'; import type { Buffered, Encoder, Observer, Sink } from './sink-source.type'; +/** + * Encoder that converts PerformanceEntry to domain events. + * + * Pure function that transforms performance entries into one or more domain events. + * Should be stateless, synchronous, and have no side effects. + */ +export type PerformanceEntryEncoder = ( + entry: PerformanceEntry, +) => readonly F[]; + const OBSERVED_TYPES = ['mark', 'measure'] as const; type ObservedEntryType = 'mark' | 'measure'; export const DEFAULT_FLUSH_THRESHOLD = 20; export type PerformanceObserverOptions = { sink: Sink; - encode: (entry: PerformanceEntry) => T[]; + encodePerfEntry: PerformanceEntryEncoder; buffered?: boolean; flushThreshold?: number; }; export class PerformanceObserverSink - implements Observer, Buffered, Encoder + implements Observer, Buffered, Encoder { - #encode: (entry: PerformanceEntry) => T[]; + #encodePerfEntry: PerformanceEntryEncoder; #buffered: boolean; #flushThreshold: number; #sink: Sink; @@ -32,8 +42,8 @@ export class PerformanceObserverSink #written: Map; constructor(options: PerformanceObserverOptions) { - const { encode, sink, buffered, flushThreshold } = options; - this.#encode = encode; + const { encodePerfEntry, sink, buffered, flushThreshold } = options; + this.#encodePerfEntry = encodePerfEntry; this.#written = new Map( OBSERVED_TYPES.map(t => [t, 0]), ); @@ -42,14 +52,19 @@ export class PerformanceObserverSink this.#flushThreshold = flushThreshold ?? DEFAULT_FLUSH_THRESHOLD; } - encode(entry: PerformanceEntry): T[] { - return this.#encode(entry); + encode(entry: PerformanceEntry): readonly T[] { + return this.#encodePerfEntry(entry); } subscribe(): void { if (this.#observer) { return; } + if (this.#sink.isClosed()) { + throw new Error( + 'Sink must be opened before subscribing PerformanceObserver', + ); + } // Only used to trigger the flush - it's not processing the entries, just counting them this.#observer = new PerformanceObserver( @@ -76,6 +91,11 @@ export class PerformanceObserverSink if (!this.#observer) { return; } + if (this.#sink.isClosed()) { + throw new Error( + 'Sink must be opened before subscribing PerformanceObserver', + ); + } OBSERVED_TYPES.forEach(t => { const written = this.#written.get(t) ?? 0; diff --git a/packages/utils/src/lib/profiler/constants.ts b/packages/utils/src/lib/profiler/constants.ts new file mode 100644 index 000000000..d52e31d90 --- /dev/null +++ b/packages/utils/src/lib/profiler/constants.ts @@ -0,0 +1 @@ +export const PROFILER_ENABLED = 'CP_PROFILING'; diff --git a/packages/utils/src/lib/profiler/profiler.int.test.ts b/packages/utils/src/lib/profiler/profiler.int.test.ts new file mode 100644 index 000000000..cf8275833 --- /dev/null +++ b/packages/utils/src/lib/profiler/profiler.int.test.ts @@ -0,0 +1,430 @@ +import { describe, expect, it, vi } from 'vitest'; +import { MockRecoverableSink } from '../../../mocks/sink.mock'; +import { + type PerformanceEntryEncoder, + PerformanceObserverSink, +} from '../performance-observer'; +import type { ActionTrackEntryPayload } from '../user-timing-extensibility-api.type.js'; +import { NodejsProfiler, Profiler } from './profiler'; + +describe('Profiler Integration', () => { + let profiler: Profiler>; + + beforeEach(() => { + performance.clearMarks(); + performance.clearMeasures(); + + profiler = new Profiler({ + prefix: 'cp', + track: 'CLI', + trackGroup: 'Code Pushup', + color: 'primary-dark', + tracks: { + utils: { track: 'Utils', color: 'primary' }, + core: { track: 'Core', color: 'primary-light' }, + }, + enabled: true, + }); + }); + + it('should create complete performance timeline for sync operation', () => { + const result = profiler.measure('sync-test', () => + Array.from({ length: 1000 }, (_, i) => i).reduce( + (sum, num) => sum + num, + 0, + ), + ); + + expect(result).toBe(499_500); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:sync-test:start', + detail: expect.objectContaining({ + devtools: expect.objectContaining({ dataType: 'track-entry' }), + }), + }), + expect.objectContaining({ + name: 'cp:sync-test:end', + detail: expect.objectContaining({ + devtools: expect.objectContaining({ dataType: 'track-entry' }), + }), + }), + ]), + ); + + expect(measures).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:sync-test', + duration: expect.any(Number), + detail: expect.objectContaining({ + devtools: expect.objectContaining({ dataType: 'track-entry' }), + }), + }), + ]), + ); + }); + + it('should create complete performance timeline for async operation', async () => { + const result = await profiler.measureAsync('async-test', async () => { + await new Promise(resolve => setTimeout(resolve, 10)); + return 'async-result'; + }); + + expect(result).toBe('async-result'); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:async-test:start', + detail: expect.objectContaining({ + devtools: expect.objectContaining({ dataType: 'track-entry' }), + }), + }), + expect.objectContaining({ + name: 'cp:async-test:end', + detail: expect.objectContaining({ + devtools: expect.objectContaining({ dataType: 'track-entry' }), + }), + }), + ]), + ); + + expect(measures).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:async-test', + duration: expect.any(Number), + detail: expect.objectContaining({ + devtools: expect.objectContaining({ dataType: 'track-entry' }), + }), + }), + ]), + ); + }); + + it('should handle nested measurements correctly', () => { + profiler.measure('outer', () => { + profiler.measure('inner', () => 'inner-result'); + return 'outer-result'; + }); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toHaveLength(4); + expect(measures).toHaveLength(2); + + const markNames = marks.map(m => m.name); + expect(markNames).toStrictEqual( + expect.arrayContaining([ + 'cp:outer:start', + 'cp:outer:end', + 'cp:inner:start', + 'cp:inner:end', + ]), + ); + + const measureNames = measures.map(m => m.name); + expect(measureNames).toStrictEqual( + expect.arrayContaining(['cp:outer', 'cp:inner']), + ); + }); + + it('should create markers with proper metadata', () => { + profiler.marker('test-marker', { + color: 'warning', + tooltipText: 'Test marker tooltip', + properties: [ + ['event', 'test-event'], + ['timestamp', Date.now()], + ], + }); + + const marks = performance.getEntriesByType('mark'); + expect(marks).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'test-marker', + detail: { + devtools: expect.objectContaining({ + dataType: 'marker', + color: 'warning', + tooltipText: 'Test marker tooltip', + properties: [ + ['event', 'test-event'], + ['timestamp', expect.any(Number)], + ], + }), + }, + }), + ]), + ); + }); + + it('should create proper DevTools payloads for tracks', () => { + profiler.measure('track-test', (): string => 'result', { + success: (result: string) => ({ + properties: [['result', result]], + tooltipText: 'Track test completed', + }), + }); + + const measures = performance.getEntriesByType('measure'); + expect(measures).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:track-test', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'CLI', + trackGroup: 'Code Pushup', + color: 'primary-dark', + properties: [['result', 'result']], + tooltipText: 'Track test completed', + }), + }, + }), + ]), + ); + }); + + it('should merge track defaults with measurement options', () => { + profiler.measure('sync-op', (): string => 'sync-result', { + success: (result: string) => ({ + properties: [ + ['operation', 'sync'], + ['result', result], + ], + }), + }); + + const measures = performance.getEntriesByType('measure'); + expect(measures).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:sync-op', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'CLI', + trackGroup: 'Code Pushup', + color: 'primary-dark', + properties: [ + ['operation', 'sync'], + ['result', 'sync-result'], + ], + }), + }, + }), + ]), + ); + }); + + it('should mark errors with red color in DevTools', () => { + const error = new Error('Test error'); + + expect(() => { + profiler.measure('error-test', () => { + throw error; + }); + }).toThrow(error); + + const measures = performance.getEntriesByType('measure'); + expect(measures).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + detail: { + devtools: expect.objectContaining({ + color: 'error', + properties: expect.arrayContaining([ + ['Error Type', 'Error'], + ['Error Message', 'Test error'], + ]), + }), + }, + }), + ]), + ); + }); + + it('should include error metadata in DevTools properties', () => { + const customError = new TypeError('Custom type error'); + + expect(() => { + profiler.measure('custom-error-test', () => { + throw customError; + }); + }).toThrow(customError); + + const measures = performance.getEntriesByType('measure'); + expect(measures).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + detail: { + devtools: expect.objectContaining({ + properties: expect.arrayContaining([ + ['Error Type', 'TypeError'], + ['Error Message', 'Custom type error'], + ]), + }), + }, + }), + ]), + ); + }); + + it('should not create performance entries when disabled', async () => { + profiler.setEnabled(false); + + const syncResult = profiler.measure('disabled-sync', () => 'sync'); + expect(syncResult).toBe('sync'); + + const asyncResult = profiler.measureAsync( + 'disabled-async', + async () => 'async', + ); + await expect(asyncResult).resolves.toBe('async'); + + profiler.marker('disabled-marker'); + + expect(performance.getEntriesByType('mark')).toHaveLength(0); + expect(performance.getEntriesByType('measure')).toHaveLength(0); + }); +}); + +describe('NodeJS Profiler Integration', () => { + const simpleEncoder: PerformanceEntryEncoder = entry => { + if (entry.entryType === 'measure') { + return [`${entry.name}:${entry.duration.toFixed(2)}ms`]; + } + return []; + }; + let mockSink: MockRecoverableSink; + let perfObserverSink: PerformanceObserverSink; + let nodejsProfiler: NodejsProfiler; + + beforeEach(() => { + mockSink = new MockRecoverableSink(); + perfObserverSink = new PerformanceObserverSink({ + sink: mockSink, + encodePerfEntry: simpleEncoder, + }); + + // Spy on PerformanceObserverSink methods + vi.spyOn(perfObserverSink, 'subscribe'); + vi.spyOn(perfObserverSink, 'unsubscribe'); + vi.spyOn(perfObserverSink, 'flush'); + + // Spy on sink methods + vi.spyOn(mockSink, 'open'); + vi.spyOn(mockSink, 'close'); + + nodejsProfiler = new NodejsProfiler({ + prefix: 'test', + track: 'test-track', + sink: mockSink, + encodePerfEntry: simpleEncoder, + enabled: true, + }); + }); + + it('should initialize with sink opened when enabled', () => { + expect(mockSink.isClosed()).toBe(false); + expect(nodejsProfiler.isEnabled()).toBe(true); + expect(mockSink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + }); + + it('should create performance entries and write to sink', () => { + const result = nodejsProfiler.measure('test-operation', () => 'success'); + expect(result).toBe('success'); + + const writtenItems = mockSink.getWrittenItems(); + expect(writtenItems.length).toBeGreaterThan(0); + expect(writtenItems[0]).toMatch(/^test:test-operation:\d+\.\d+ms$/); + }); + + it('should handle async operations', async () => { + const result = await nodejsProfiler.measureAsync('async-test', async () => { + await new Promise(resolve => setTimeout(resolve, 1)); + return 'async-result'; + }); + + expect(result).toBe('async-result'); + + const writtenItems = mockSink.getWrittenItems(); + expect(writtenItems.length).toBeGreaterThan(0); + }); + + it('should disable profiling and close sink', () => { + nodejsProfiler.setEnabled(false); + expect(nodejsProfiler.isEnabled()).toBe(false); + expect(mockSink.isClosed()).toBe(true); + expect(mockSink.close).toHaveBeenCalledTimes(1); + expect(perfObserverSink.unsubscribe).toHaveBeenCalledTimes(1); + + // Operations should still work but not write to sink + const result = nodejsProfiler.measure('disabled-test', () => 'success'); + expect(result).toBe('success'); + + expect(mockSink.getWrittenItems()).toHaveLength(0); + }); + + it('should re-enable profiling correctly', () => { + nodejsProfiler.setEnabled(false); + nodejsProfiler.setEnabled(true); + + expect(nodejsProfiler.isEnabled()).toBe(true); + expect(mockSink.isClosed()).toBe(false); + expect(mockSink.open).toHaveBeenCalledTimes(2); // Once during init, once during re-enable + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(2); // Once during init, once during re-enable + + const result = nodejsProfiler.measure('re-enabled-test', () => 42); + expect(result).toBe(42); + + expect(mockSink.getWrittenItems()).toHaveLength(1); + }); + + it('should support custom tracks', () => { + const profilerWithTracks = new NodejsProfiler({ + prefix: 'api-server', + track: 'HTTP', + tracks: { + db: { track: 'Database', color: 'secondary' }, + cache: { track: 'Cache', color: 'primary' }, + }, + sink: mockSink, + encodePerfEntry: simpleEncoder, + }); + + const result = profilerWithTracks.measure('user-lookup', () => 'user123', { + track: 'cache', + }); + + expect(result).toBe('user123'); + expect(mockSink.getWrittenItems()).toHaveLength(1); + }); + + it('should recover data through recoverable interface', () => { + nodejsProfiler.measure('recoverable-test', () => 'data'); + + // Simulate process exit by calling the internal flush logic + // Note: In real usage, this would be called during process exit + expect(perfObserverSink.flush).toHaveBeenCalledTimes(0); // Not called yet + + const recovery = mockSink.recover(); + expect(recovery.records).toHaveLength(1); + expect(recovery.errors).toHaveLength(0); + expect(recovery.partialTail).toBeNull(); + }); +}); diff --git a/packages/utils/src/lib/profiler/profiler.ts b/packages/utils/src/lib/profiler/profiler.ts new file mode 100644 index 000000000..436eee95a --- /dev/null +++ b/packages/utils/src/lib/profiler/profiler.ts @@ -0,0 +1,364 @@ +import { isEnvVarEnabled } from '../env.js'; +import { installExitHandlers } from '../exit-process.js'; +import { + type PerformanceEntryEncoder, + PerformanceObserverSink, +} from '../performance-observer.js'; +import type { Recoverable, Sink } from '../sink-source.type.js'; +import { + type MeasureCtxOptions, + type MeasureOptions, + asOptions, + markerPayload, + measureCtx, + setupTracks, +} from '../user-timing-extensibility-api-utils.js'; +import type { + ActionTrackEntryPayload, + DevToolsColor, + EntryMeta, +} from '../user-timing-extensibility-api.type.js'; +import { PROFILER_ENABLED } from './constants.js'; + +/** + * Configuration options for creating a Profiler instance. + * + * @template T - Record type defining available track names and their configurations + */ +type ProfilerMeasureOptions> = + MeasureCtxOptions & { + /** Custom track configurations that will be merged with default settings */ + tracks?: Record>; + /** Whether profiling should be enabled (defaults to CP_PROFILING env var) */ + enabled?: boolean; + }; + +/** + * Options for configuring a Profiler instance. + * + * This is an alias for ProfilerMeasureOptions for backward compatibility. + * + * @template T - Record type defining available track names and their configurations + * + * @property enabled - Whether profiling is enabled (defaults to CP_PROFILING env var) + * @property prefix - Prefix for all measurement names + * @property track - Default track name for measurements + * @property trackGroup - Default track group for organization + * @property color - Default color for track entries + * @property tracks - Custom track configurations merged with defaults + */ +export type ProfilerOptions< + T extends Record = Record< + string, + ActionTrackEntryPayload + >, +> = ProfilerMeasureOptions; + +/** + * Performance profiler that creates structured timing measurements with Chrome DevTools Extensibility API payloads. + * + * This class provides high-level APIs for performance monitoring focused on Chrome DevTools Extensibility API data. + * It supports both synchronous and asynchronous operations with all having smart defaults for custom track data. + * + */ +export class Profiler> { + #enabled: boolean; + private readonly defaults: ActionTrackEntryPayload; + readonly tracks: Record | undefined; + private readonly ctxOf: ReturnType; + + /** + * Creates a new Profiler instance with the specified configuration. + * + * @param options - Configuration options for the profiler + * @param options.tracks - Custom track configurations merged with defaults + * @param options.prefix - Prefix for all measurement names + * @param options.track - Default track name for measurements + * @param options.trackGroup - Default track group for organization + * @param options.color - Default color for track entries + * @param options.enabled - Whether profiling is enabled (defaults to CP_PROFILING env var) + * + */ + constructor(options: ProfilerOptions) { + const { tracks, prefix, enabled, ...defaults } = options; + const dataType = 'track-entry'; + + this.#enabled = enabled ?? isEnvVarEnabled(PROFILER_ENABLED); + this.defaults = { ...defaults, dataType }; + this.tracks = tracks + ? setupTracks({ ...defaults, dataType }, tracks) + : undefined; + this.ctxOf = measureCtx({ + ...defaults, + dataType, + prefix, + }); + } + + /** + * Sets enabled state for this profiler. + * + * Design: Environment = default, Runtime = override + * - Environment variables define defaults (read once at construction) + * - This method provides runtime control without mutating globals + * - Child processes are unaffected by runtime enablement changes + * + * @param enabled - Whether profiling should be enabled + */ + setEnabled(enabled: boolean): void { + this.#enabled = enabled; + } + + /** + * Is profiling enabled? + * + * Returns the runtime-only enabled state, separate from environment variables. + * + * @returns Whether profiling is currently enabled + */ + isEnabled(): boolean { + return this.#enabled; + } + + /** + * Creates a performance mark including payload for a Chrome DevTools 'marker' item. + * + * Markers appear as vertical lines spanning all tracks and can include custom metadata + * for debugging and performance analysis. When profiling is disabled, this method + * returns immediately without creating any performance entries. + * + * @param name - Unique name for the marker + * @param opt - Metadata and styling for the marker + * @param opt.color - Color of the marker line (defaults to profiler default) + * @param opt.tooltipText - Text shown on hover + * @param opt.properties - Key-value pairs for detailed view show on click + * + * @example + * profiler.marker('user-action-start', { + * color: 'primary', + * tooltipText: 'User clicked save button', + * properties: [ + * ['action', 'save'], + * ['elementId', 'save-btn'] + * ] + * }); + */ + marker(name: string, opt?: EntryMeta & { color?: DevToolsColor }) { + if (!this.#enabled) { + return; + } + + performance.mark( + name, + asOptions( + markerPayload({ + // marker only takes default color, no TrackMeta + ...(this.defaults.color ? { color: this.defaults.color } : {}), + ...opt, + }), + ), + ); + } + + /** + * Measures the execution time of a synchronous operation. + * + * Creates performance start/end marks and a final measure. + * All entries have Chrome DevTools Extensibility API payload and are visualized under custom tracks. + * When profiling is disabled, executes the work function directly without overhead. + * + * @template R - The return type of the work function + * @param event - Name for this measurement event + * @param work - Function to execute and measure + * @param options - Measurement configuration overrides + * @returns The result of the work function + * + */ + measure(event: string, work: () => R, options?: MeasureOptions): R { + if (!this.#enabled) { + return work(); + } + + const { start, success, error } = this.ctxOf(event, options); + start(); + try { + const r = work(); + success(r); + return r; + } catch (error_) { + error(error_); + throw error_; + } + } + + /** + * Measures the execution time of an asynchronous operation. + * + * Creates performance start/end marks and a final measure. + * All entries have Chrome DevTools Extensibility API payload and are visualized under custom tracks. + * When profiling is disabled, executes and awaits the work function directly without overhead. + * + * @template R - The resolved type of the work promise + * @param event - Name for this measurement event + * @param work - Function returning a promise to execute and measure + * @param options - Measurement configuration overrides + * @returns Promise that resolves to the result of the work function + * + */ + async measureAsync( + event: string, + work: () => Promise, + options?: MeasureOptions, + ): Promise { + if (!this.#enabled) { + return await work(); + } + + const { start, success, error } = this.ctxOf(event, options); + start(); + try { + const r = work(); + success(r); + return await r; + } catch (error_) { + error(error_); + throw error_; + } + } +} + +/** + * Options for configuring a NodejsProfiler instance. + * + * Extends ProfilerOptions with a required sink parameter. + * + * @template Tracks - Record type defining available track names and their configurations + */ +export type NodejsProfilerOptions< + Tracks extends Record, + DomainEvents, +> = ProfilerOptions & { + /** Sink for buffering and flushing performance data */ + sink: Sink & Recoverable; + /** Encoder that converts PerformanceEntry to domain events */ + encodePerfEntry: PerformanceEntryEncoder; +}; + +/** + * Performance profiler with automatic process exit handling for buffered performance data. + * + * This class extends the base {@link Profiler} with automatic flushing of performance data + * when the process exits. It accepts a {@link PerformanceObserverSink} that buffers performance + * entries and ensures they are written out during process termination, even for unexpected exits. + * + * The profiler automatically subscribes to the performance observer when enabled and installs + * exit handlers that flush buffered data on process termination (signals, fatal errors, or normal exit). + * + */ +export class NodejsProfiler< + DomainEvents, + Tracks extends Record = Record< + string, + ActionTrackEntryPayload + >, +> extends Profiler { + #enabled: boolean; + #sink: Sink & Recoverable; + #performanceObserverSink: PerformanceObserverSink; + + /** + * Creates a new NodejsProfiler instance with automatic exit handling. + * + * @param options - Configuration options including the sink + * @param options.sink - Sink for buffering and flushing performance data + * @param options.tracks - Custom track configurations merged with defaults + * @param options.prefix - Prefix for all measurement names + * @param options.track - Default track name for measurements + * @param options.trackGroup - Default track group for organization + * @param options.color - Default color for track entries + * @param options.enabled - Whether profiling is enabled (defaults to CP_PROFILING env var) + * + */ + constructor(options: NodejsProfilerOptions) { + const { sink, encodePerfEntry, ...profilerOptions } = options; + + super(profilerOptions); + + this.#enabled = super.isEnabled(); // Initialize with parent's enabled state + this.#sink = sink; + + this.#performanceObserverSink = new PerformanceObserverSink({ + sink, + encodePerfEntry, + }); + + this.#setObserving(this.isEnabled()); + + this.#installExitHandlers(); + } + /** + * Is profiling enabled? + * + * Returns the runtime-only enabled state, separate from environment variables. + * + * @returns Whether profiling is currently enabled + */ + #setObserving(observing: boolean): void { + if (observing) { + this.#sink.open(); + this.#performanceObserverSink.subscribe(); + } else { + this.#performanceObserverSink.unsubscribe(); + this.#sink.close(); + } + } + + /** + * Sets enabled state for this profiler and manages sink/observer lifecycle. + * + * Design: Environment = default, Runtime = override + * - Environment variables define defaults (read once at construction) + * - This method provides runtime control without mutating globals + * - Child processes are unaffected by runtime enablement changes + * + * Invariant: enabled ↔ sink + observer state + * - enabled === true → sink open + observer subscribed + * - enabled === false → sink closed + observer unsubscribed + * + * @param enabled - Whether profiling should be enabled + */ + setEnabled(enabled: boolean): void { + if (this.isEnabled() === enabled) { + return; + } + this.#enabled = enabled; + this.#setObserving(enabled); + } + + /** + * Installs process exit handlers to flush buffered performance data and close the sink. + * + * Sets up handlers for signals (SIGINT, SIGTERM, SIGQUIT), fatal errors + * (uncaughtException, unhandledRejection), and normal process exit. + * All handlers flush the performance observer sink and close the sink to ensure + * data is written out and resources are properly cleaned up. + */ + #installExitHandlers(): void { + installExitHandlers({ + onExit: () => { + if (!this.isEnabled()) { + return; + } + try { + this.#performanceObserverSink.flush(); + this.#sink.finalize(); + } catch (error) { + console.error( + 'Failed to flush performance data and create trace file on exit:', + error, + ); + } + }, + }); + } +} diff --git a/packages/utils/src/lib/profiler/profiler.unit.test.ts b/packages/utils/src/lib/profiler/profiler.unit.test.ts new file mode 100644 index 000000000..daebb6c50 --- /dev/null +++ b/packages/utils/src/lib/profiler/profiler.unit.test.ts @@ -0,0 +1,596 @@ +import { performance } from 'node:perf_hooks'; +import { beforeEach, describe, expect, it, vi } from 'vitest'; +import { MockSink } from '../../../mocks/sink.mock'; +import { + type PerformanceEntryEncoder, + PerformanceObserverSink, +} from '../performance-observer'; +import type { Recoverable, Sink } from '../sink-source.type.js'; +import type { ActionTrackEntryPayload } from '../user-timing-extensibility-api.type.js'; +import { + NodejsProfiler, + type NodejsProfilerOptions, + Profiler, + type ProfilerOptions, +} from './profiler.js'; + +describe('Profiler', () => { + const getProfiler = (overrides?: Partial) => + new Profiler({ + prefix: 'cp', + track: 'test-track', + ...overrides, + }); + + let profiler: Profiler>; + + beforeEach(() => { + performance.clearMarks(); + performance.clearMeasures(); + // eslint-disable-next-line functional/immutable-data + delete process.env.CP_PROFILING; + + profiler = getProfiler(); + }); + + it('constructor should initialize with default enabled state from env', () => { + vi.stubEnv('CP_PROFILING', 'true'); + const profilerWithEnv = getProfiler(); + + expect(profilerWithEnv.isEnabled()).toBe(true); + }); + + it('constructor should override enabled state from options', () => { + vi.stubEnv('CP_PROFILING', 'false'); + const profilerWithOverride = new Profiler({ + prefix: 'cp', + track: 'test-track', + enabled: true, + }); + + expect(profilerWithOverride.isEnabled()).toBe(true); + }); + + it('constructor should use defaults for measure', () => { + const customProfiler = getProfiler({ color: 'secondary' }); + + customProfiler.setEnabled(true); + + const result = customProfiler.measure('test-operation', () => 'success'); + + expect(result).toBe('success'); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:test-operation:start', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + color: 'secondary', + }), + }, + }), + expect.objectContaining({ + name: 'cp:test-operation:end', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + color: 'secondary', + }), + }, + }), + ]), + ); + expect(measures).toStrictEqual([ + expect.objectContaining({ + name: 'cp:test-operation', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + color: 'secondary', + }), + }, + }), + ]); + }); + + it('constructor should setup tracks with defaults merged', () => { + const profilerWithTracks = new Profiler({ + prefix: 'cp', + track: 'default-track', + trackGroup: 'default-group', + color: 'primary', + tracks: { + custom: { track: 'custom-track', color: 'secondary' }, + partial: { color: 'tertiary' }, + }, + }); + + expect(profilerWithTracks.tracks).toStrictEqual({ + custom: { + track: 'custom-track', + trackGroup: 'default-group', + color: 'secondary', + dataType: 'track-entry', + }, + partial: { + track: 'default-track', + trackGroup: 'default-group', + color: 'tertiary', + dataType: 'track-entry', + }, + }); + }); + + it('isEnabled should set and get enabled state', () => { + expect(profiler.isEnabled()).toBe(false); + + profiler.setEnabled(true); + expect(profiler.isEnabled()).toBe(true); + + profiler.setEnabled(false); + expect(profiler.isEnabled()).toBe(false); + }); + + it('isEnabled should update environment variable', () => { + profiler.setEnabled(true); + expect(process.env.CP_PROFILING).toBe('true'); + + profiler.setEnabled(false); + expect(process.env.CP_PROFILING).toBe('false'); + }); + + it('marker should execute without error when enabled', () => { + profiler.setEnabled(true); + + expect(() => { + profiler.marker('test-marker', { + color: 'primary', + tooltipText: 'Test marker', + properties: [['key', 'value']], + }); + }).not.toThrow(); + + const marks = performance.getEntriesByType('mark'); + expect(marks).toStrictEqual([ + expect.objectContaining({ + name: 'test-marker', + detail: { + devtools: expect.objectContaining({ + dataType: 'marker', + color: 'primary', + tooltipText: 'Test marker', + properties: [['key', 'value']], + }), + }, + }), + ]); + }); + + it('marker should execute without error when disabled', () => { + profiler.setEnabled(false); + + expect(() => { + profiler.marker('test-marker'); + }).not.toThrow(); + + const marks = performance.getEntriesByType('mark'); + expect(marks).toHaveLength(0); + }); + + it('marker should execute without error when enabled with default color', () => { + performance.clearMarks(); + + const profilerWithColor = getProfiler({ color: 'primary' }); + profilerWithColor.setEnabled(true); + + expect(() => { + profilerWithColor.marker('test-marker-default-color', { + tooltipText: 'Test marker with default color', + }); + }).not.toThrow(); + + const marks = performance.getEntriesByType('mark'); + expect(marks).toStrictEqual([ + expect.objectContaining({ + name: 'test-marker-default-color', + detail: { + devtools: expect.objectContaining({ + dataType: 'marker', + color: 'primary', // Should use default color + tooltipText: 'Test marker with default color', + }), + }, + }), + ]); + }); + + it('marker should execute without error when enabled with no default color', () => { + const profilerNoColor = getProfiler(); + profilerNoColor.setEnabled(true); + + expect(() => { + profilerNoColor.marker('test-marker-no-color', { + color: 'secondary', + tooltipText: 'Test marker without default color', + properties: [['key', 'value']], + }); + }).not.toThrow(); + + const marks = performance.getEntriesByType('mark'); + expect(marks).toStrictEqual([ + expect.objectContaining({ + name: 'test-marker-no-color', + detail: { + devtools: expect.objectContaining({ + dataType: 'marker', + color: 'secondary', + tooltipText: 'Test marker without default color', + properties: [['key', 'value']], + }), + }, + }), + ]); + }); + + it('measure should execute work and return result when enabled', () => { + performance.clearMarks(); + performance.clearMeasures(); + + profiler.setEnabled(true); + + const workFn = vi.fn(() => 'result'); + const result = profiler.measure('test-event', workFn, { color: 'primary' }); + + expect(result).toBe('result'); + expect(workFn).toHaveBeenCalled(); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:test-event:start', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + }), + }, + }), + expect.objectContaining({ + name: 'cp:test-event:end', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + }), + }, + }), + ]), + ); + expect(measures).toStrictEqual([ + expect.objectContaining({ + name: 'cp:test-event', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + }), + }, + }), + ]); + }); + + it('measure should execute work directly when disabled', () => { + profiler.setEnabled(false); + const workFn = vi.fn(() => 'result'); + const result = profiler.measure('test-event', workFn); + + expect(result).toBe('result'); + expect(workFn).toHaveBeenCalled(); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toHaveLength(0); + expect(measures).toHaveLength(0); + }); + + it('measure should propagate errors when enabled', () => { + profiler.setEnabled(true); + + const error = new Error('Test error'); + const workFn = vi.fn(() => { + throw error; + }); + + expect(() => profiler.measure('test-event', workFn)).toThrow(error); + expect(workFn).toHaveBeenCalled(); + }); + + it('measure should propagate errors when disabled', () => { + profiler.setEnabled(false); + + const error = new Error('Test error'); + const workFn = vi.fn(() => { + throw error; + }); + + expect(() => profiler.measure('test-event', workFn)).toThrow(error); + expect(workFn).toHaveBeenCalled(); + }); + + it('measureAsync should handle async operations correctly when enabled', async () => { + profiler.setEnabled(true); + + const workFn = vi.fn(async () => { + await Promise.resolve(); + return 'async-result'; + }); + + const result = await profiler.measureAsync('test-async-event', workFn, { + color: 'primary', + }); + + expect(result).toBe('async-result'); + expect(workFn).toHaveBeenCalled(); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toStrictEqual( + expect.arrayContaining([ + expect.objectContaining({ + name: 'cp:test-async-event:start', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + color: 'primary', + }), + }, + }), + expect.objectContaining({ + name: 'cp:test-async-event:end', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + color: 'primary', + }), + }, + }), + ]), + ); + expect(measures).toStrictEqual([ + expect.objectContaining({ + name: 'cp:test-async-event', + detail: { + devtools: expect.objectContaining({ + dataType: 'track-entry', + track: 'test-track', + color: 'primary', + }), + }, + }), + ]); + }); + + it('measureAsync should execute async work directly when disabled', async () => { + profiler.setEnabled(false); + + const workFn = vi.fn(async () => { + await Promise.resolve(); + return 'async-result'; + }); + + const result = await profiler.measureAsync('test-async-event', workFn); + + expect(result).toBe('async-result'); + expect(workFn).toHaveBeenCalled(); + + const marks = performance.getEntriesByType('mark'); + const measures = performance.getEntriesByType('measure'); + + expect(marks).toHaveLength(0); + expect(measures).toHaveLength(0); + }); + + it('measureAsync should propagate async errors when enabled', async () => { + profiler.setEnabled(true); + + const error = new Error('Async test error'); + const workFn = vi.fn(async () => { + await Promise.resolve(); + throw error; + }); + + await expect( + profiler.measureAsync('test-async-event', workFn), + ).rejects.toThrow(error); + expect(workFn).toHaveBeenCalled(); + }); + + it('measureAsync should propagate async errors when disabled', async () => { + profiler.setEnabled(false); + + const error = new Error('Async test error'); + const workFn = vi.fn(async () => { + await Promise.resolve(); + throw error; + }); + + await expect( + profiler.measureAsync('test-async-event', workFn), + ).rejects.toThrow(error); + expect(workFn).toHaveBeenCalled(); + }); +}); + +// Mock sink that extends MockSink with Recoverable interface +class MockRecoverableSink extends MockSink implements Recoverable { + recover(): { + records: unknown[]; + errors: { lineNo: number; line: string; error: Error }[]; + partialTail: string | null; + } { + return { + records: this.getWrittenItems(), + errors: [], + partialTail: null, + }; + } + + repack(): void { + // Mock implementation - no-op + } + + finalize(): void { + // Mock implementation - no-op + } +} + +// Simple string encoder for testing +const simpleEncoder: PerformanceEntryEncoder = entry => { + if (entry.entryType === 'measure') { + return [`${entry.name}:${entry.duration.toFixed(2)}ms`]; + } + return []; +}; + +describe('NodejsProfiler', () => { + const getNodejsProfiler = ( + overrides?: Partial< + NodejsProfilerOptions, string> + >, + ) => { + const sink = new MockRecoverableSink(); + const perfObserverSink = new PerformanceObserverSink({ + sink, + encodePerfEntry: simpleEncoder, + }); + + // Spy on methods + vi.spyOn(perfObserverSink, 'subscribe'); + vi.spyOn(perfObserverSink, 'unsubscribe'); + vi.spyOn(sink, 'open'); + vi.spyOn(sink, 'close'); + + const profiler = new NodejsProfiler({ + prefix: 'test', + track: 'test-track', + sink, + encodePerfEntry: simpleEncoder, + ...overrides, + }); + + return { sink, perfObserverSink, profiler }; + }; + + it('should export NodejsProfiler class', () => { + expect(typeof NodejsProfiler).toBe('function'); + }); + + it('should have required static structure', () => { + const proto = NodejsProfiler.prototype; + expect(typeof proto.measure).toBe('function'); + expect(typeof proto.measureAsync).toBe('function'); + expect(typeof proto.marker).toBe('function'); + expect(typeof proto.setEnabled).toBe('function'); + expect(typeof proto.isEnabled).toBe('function'); + }); + + it('should inherit from Profiler', () => { + expect(Object.getPrototypeOf(NodejsProfiler.prototype)).toBe( + Profiler.prototype, + ); + }); + + describe('constructor and initialization', () => { + it('should initialize with sink opened when enabled is true', () => { + const { sink, perfObserverSink } = getNodejsProfiler({ enabled: true }); + expect(sink.isClosed()).toBe(false); + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + }); + + it('should initialize with sink closed when enabled is false', () => { + const { sink, perfObserverSink } = getNodejsProfiler({ enabled: false }); + expect(sink.isClosed()).toBe(true); + expect(sink.open).not.toHaveBeenCalled(); + expect(perfObserverSink.subscribe).not.toHaveBeenCalled(); + }); + }); + + describe('setEnabled', () => { + it('should open sink and subscribe observer when enabling', () => { + const { sink, perfObserverSink, profiler } = getNodejsProfiler({ + enabled: false, + }); + + profiler.setEnabled(true); + + expect(profiler.isEnabled()).toBe(true); + expect(sink.isClosed()).toBe(false); + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + }); + + it('should close sink and unsubscribe observer when disabling', () => { + const { sink, perfObserverSink, profiler } = getNodejsProfiler({ + enabled: true, + }); + + profiler.setEnabled(false); + + expect(profiler.isEnabled()).toBe(false); + expect(sink.isClosed()).toBe(true); + expect(sink.close).toHaveBeenCalledTimes(1); + expect(perfObserverSink.unsubscribe).toHaveBeenCalledTimes(1); + }); + + it('should be idempotent - no-op when setting same state', () => { + const { sink, perfObserverSink, profiler } = getNodejsProfiler({ + enabled: true, + }); + + // Should still have the same call counts as initialization + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + + profiler.setEnabled(true); // Set same state - should not change counts + + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + }); + }); + + describe('measurement operations', () => { + it('should perform measurements when enabled', () => { + const { sink, profiler } = getNodejsProfiler({ enabled: true }); + + const result = profiler.measure('test-op', () => 'success'); + expect(result).toBe('success'); + + expect(sink.getWrittenItems()).toHaveLength(1); + }); + + it('should skip sink operations when disabled', () => { + const { sink, profiler } = getNodejsProfiler({ enabled: false }); + + const result = profiler.measure('disabled-op', () => 'success'); + expect(result).toBe('success'); + + expect(sink.getWrittenItems()).toHaveLength(0); + }); + }); +}); diff --git a/packages/utils/src/lib/sink-source.type.ts b/packages/utils/src/lib/sink-source.type.ts index ee096e31f..5f94584bd 100644 --- a/packages/utils/src/lib/sink-source.type.ts +++ b/packages/utils/src/lib/sink-source.type.ts @@ -29,8 +29,8 @@ export type Observer = { isSubscribed: () => boolean; }; -export type Recoverable = { - recover: () => RecoverResult; +export type Recoverable = { + recover: () => RecoverResult; repack: () => void; finalize: () => void; }; diff --git a/packages/utils/src/lib/user-timing-extensibility-api-utils.ts b/packages/utils/src/lib/user-timing-extensibility-api-utils.ts index 6a5cb7484..94d4b5c65 100644 --- a/packages/utils/src/lib/user-timing-extensibility-api-utils.ts +++ b/packages/utils/src/lib/user-timing-extensibility-api-utils.ts @@ -369,19 +369,19 @@ function toMarkMeasureOpts(devtools: T) { * Options for customizing measurement behavior and callbacks. * Extends partial ActionTrackEntryPayload to allow overriding default track properties. */ -export type MeasureOptions = Partial & { +export type MeasureOptions = Partial & { /** * Callback invoked when measurement completes successfully. * @param result - The successful result value * @returns Additional DevTools properties to merge for success state */ - success?: (result: unknown) => Partial; + success?: (result: T) => EntryMeta; /** * Callback invoked when measurement fails with an error. * @param error - The error that occurred * @returns Additional DevTools properties to merge for error state */ - error?: (error: unknown) => Partial; + error?: (error: unknown) => EntryMeta; }; /** @@ -473,7 +473,7 @@ export type MeasureCtxOptions = ActionTrackEntryPayload & { * - `error(error)`: Completes failed measurement with error metadata */ -export function measureCtx(cfg: MeasureCtxOptions) { +export function measureCtx(cfg: MeasureCtxOptions) { const { prefix, error: globalErr, ...defaults } = cfg; return (event: string, opt?: MeasureOptions) => { @@ -488,7 +488,7 @@ export function measureCtx(cfg: MeasureCtxOptions) { return { start: () => performance.mark(s, toMarkMeasureOpts(merged)), - success: (r: unknown) => { + success: (r: T) => { const successPayload = mergeDevtoolsPayload(merged, success?.(r) ?? {}); performance.mark(e, toMarkMeasureOpts(successPayload)); performance.measure(m, { From 673b5c400054ee02cc6f9cfe82218fdfaa7915bc Mon Sep 17 00:00:00 2001 From: Michael Hladky Date: Fri, 16 Jan 2026 18:43:45 +0100 Subject: [PATCH 2/7] test: convert all MockSink and MockTraceEventFileSink methods to spies - Replace method implementations with vi.fn() spy functions - Add vi import from vitest - Enables better testing with call tracking and assertions --- packages/utils/mocks/sink.mock.ts | 59 ++++++++++++++++--------------- 1 file changed, 31 insertions(+), 28 deletions(-) diff --git a/packages/utils/mocks/sink.mock.ts b/packages/utils/mocks/sink.mock.ts index 2ae91c429..b6092ac4c 100644 --- a/packages/utils/mocks/sink.mock.ts +++ b/packages/utils/mocks/sink.mock.ts @@ -1,3 +1,4 @@ +import { vi } from 'vitest'; import type { RecoverResult, Recoverable, @@ -8,45 +9,47 @@ export class MockSink implements Sink { private writtenItems: string[] = []; private closed = false; - open(): void { + open = vi.fn((): void => { this.closed = false; - } + }); - write(input: string): void { + write = vi.fn((input: string): void => { this.writtenItems.push(input); - } + }); - close(): void { + close = vi.fn((): void => { this.closed = true; - } + }); - isClosed(): boolean { + isClosed = vi.fn((): boolean => { return this.closed; - } + }); - encode(input: string): string { + encode = vi.fn((input: string): string => { return `${input}-${this.constructor.name}-encoded`; - } + }); - getWrittenItems(): string[] { + getWrittenItems = vi.fn((): string[] => { return [...this.writtenItems]; - } + }); } -export class MockRecoverableSink extends MockSink implements Recoverable { - recover(): RecoverResult { - return { - records: this.getWrittenItems() as T[], - errors: [], - partialTail: null, - }; - } - - repack(): void { - this.getWrittenItems().forEach(item => this.write(item)); - } - - finalize(): void { - this.close(); - } +export class MockTraceEventFileSink extends MockSink implements Recoverable { + recover = vi.fn( + (): { + records: unknown[]; + errors: { lineNo: number; line: string; error: Error }[]; + partialTail: string | null; + } => { + return { + records: this.getWrittenItems(), + errors: [], + partialTail: null, + }; + }, + ); + + repack = vi.fn((): void => {}); + + finalize = vi.fn((): void => {}); } From 7c14a0b51a378dbb16fb70b85698bffd93587cf4 Mon Sep 17 00:00:00 2001 From: Michael Hladky Date: Fri, 16 Jan 2026 19:35:44 +0100 Subject: [PATCH 3/7] refactor: add tests --- packages/utils/mocks/sink.mock.ts | 4 +- .../src/lib/performance-observer.int.test.ts | 17 +- .../utils/src/lib/performance-observer.ts | 4 +- .../src/lib/performance-observer.unit.test.ts | 48 +++-- .../src/lib/profiler/profiler.int.test.ts | 116 +++++------- packages/utils/src/lib/profiler/profiler.ts | 17 +- .../src/lib/profiler/profiler.unit.test.ts | 172 ++++++++---------- 7 files changed, 169 insertions(+), 209 deletions(-) diff --git a/packages/utils/mocks/sink.mock.ts b/packages/utils/mocks/sink.mock.ts index b6092ac4c..7f435ab4f 100644 --- a/packages/utils/mocks/sink.mock.ts +++ b/packages/utils/mocks/sink.mock.ts @@ -7,7 +7,7 @@ import type { export class MockSink implements Sink { private writtenItems: string[] = []; - private closed = false; + private closed = true; open = vi.fn((): void => { this.closed = false; @@ -45,7 +45,7 @@ export class MockTraceEventFileSink extends MockSink implements Recoverable { records: this.getWrittenItems(), errors: [], partialTail: null, - }; + } satisfies RecoverResult; }, ); diff --git a/packages/utils/src/lib/performance-observer.int.test.ts b/packages/utils/src/lib/performance-observer.int.test.ts index 2c1721ebb..72b702829 100644 --- a/packages/utils/src/lib/performance-observer.int.test.ts +++ b/packages/utils/src/lib/performance-observer.int.test.ts @@ -23,13 +23,14 @@ describe('PerformanceObserverSink', () => { beforeEach(() => { sink = new MockSink(); + sink.open(); encode = vi.fn((entry: PerformanceEntry) => [ `${entry.name}:${entry.entryType}`, ]); options = { sink, - encode, + encodePerfEntry: encode, }; performance.clearMarks(); @@ -169,7 +170,7 @@ describe('PerformanceObserverSink', () => { ]); const observer = new PerformanceObserverSink({ ...options, - encode: multiEncodeFn, + encodePerfEntry: multiEncodeFn, }); observer.subscribe(); @@ -224,4 +225,16 @@ describe('PerformanceObserverSink', () => { expect.objectContaining({ name: 'first-measure' }), ); }); + + it('throws error when subscribing with sink that is not open', () => { + const closedSink = new MockSink(); + const observer = new PerformanceObserverSink({ + sink: closedSink, + encodePerfEntry: encode, + }); + + expect(() => observer.subscribe()).toThrow( + 'Sink MockSink must be opened before subscribing PerformanceObserver', + ); + }); }); diff --git a/packages/utils/src/lib/performance-observer.ts b/packages/utils/src/lib/performance-observer.ts index 8ccbdd789..54d1544c9 100644 --- a/packages/utils/src/lib/performance-observer.ts +++ b/packages/utils/src/lib/performance-observer.ts @@ -62,7 +62,7 @@ export class PerformanceObserverSink } if (this.#sink.isClosed()) { throw new Error( - 'Sink must be opened before subscribing PerformanceObserver', + `Sink ${this.#sink.constructor.name} must be opened before subscribing PerformanceObserver`, ); } @@ -93,7 +93,7 @@ export class PerformanceObserverSink } if (this.#sink.isClosed()) { throw new Error( - 'Sink must be opened before subscribing PerformanceObserver', + `Sink ${this.#sink.constructor.name} must be opened before subscribing PerformanceObserver`, ); } diff --git a/packages/utils/src/lib/performance-observer.unit.test.ts b/packages/utils/src/lib/performance-observer.unit.test.ts index a73be955a..ce5570f71 100644 --- a/packages/utils/src/lib/performance-observer.unit.test.ts +++ b/packages/utils/src/lib/performance-observer.unit.test.ts @@ -15,20 +15,20 @@ import { } from './performance-observer.js'; describe('PerformanceObserverSink', () => { - let encode: MockedFunction<(entry: PerformanceEntry) => string[]>; + let encodePerfEntry: MockedFunction<(entry: PerformanceEntry) => string[]>; let sink: MockSink; let options: PerformanceObserverOptions; beforeEach(() => { vi.clearAllMocks(); sink = new MockSink(); - encode = vi.fn((entry: PerformanceEntry) => [ + sink.open(); + encodePerfEntry = vi.fn((entry: PerformanceEntry) => [ `${entry.name}:${entry.entryType}`, ]); options = { sink, - encode, - // we test buffered behavior separately + encodePerfEntry, flushThreshold: 1, }; @@ -46,17 +46,16 @@ describe('PerformanceObserverSink', () => { () => new PerformanceObserverSink({ sink, - encode, + encodePerfEntry, }), ).not.toThrow(); expect(MockPerformanceObserver.instances).toHaveLength(0); - // Instance creation covers the default flushThreshold assignment }); it('automatically flushes when pendingCount reaches flushThreshold', () => { const observer = new PerformanceObserverSink({ sink, - encode, + encodePerfEntry, flushThreshold: 2, // Set threshold to 2 }); observer.subscribe(); @@ -149,15 +148,15 @@ describe('PerformanceObserverSink', () => { performance.mark('test-mark'); performance.measure('test-measure'); observer.flush(); - expect(encode).toHaveBeenCalledTimes(2); - expect(encode).toHaveBeenNthCalledWith( + expect(encodePerfEntry).toHaveBeenCalledTimes(2); + expect(encodePerfEntry).toHaveBeenNthCalledWith( 1, expect.objectContaining({ name: 'test-mark', entryType: 'mark', }), ); - expect(encode).toHaveBeenNthCalledWith( + expect(encodePerfEntry).toHaveBeenNthCalledWith( 2, expect.objectContaining({ name: 'test-measure', @@ -171,7 +170,7 @@ describe('PerformanceObserverSink', () => { observer.subscribe(); MockPerformanceObserver.lastInstance()?.emitNavigation('test-navigation'); - expect(encode).not.toHaveBeenCalled(); + expect(encodePerfEntry).not.toHaveBeenCalled(); }); it('isSubscribed returns false when not observing', () => { @@ -211,7 +210,7 @@ describe('PerformanceObserverSink', () => { ]); }); - it('flush calls encode for each entry', () => { + it('flush calls encodePerfEntry for each entry', () => { const observer = new PerformanceObserverSink(options); observer.subscribe(); @@ -220,13 +219,13 @@ describe('PerformanceObserverSink', () => { observer.flush(); - expect(encode).toHaveBeenCalledWith({ + expect(encodePerfEntry).toHaveBeenCalledWith({ name: 'test-mark1', entryType: 'mark', startTime: 0, duration: 0, }); - expect(encode).toHaveBeenCalledWith({ + expect(encodePerfEntry).toHaveBeenCalledWith({ name: 'test-mark2', entryType: 'mark', startTime: 0, @@ -239,7 +238,7 @@ describe('PerformanceObserverSink', () => { performance.mark('test-mark'); observer.flush(); - expect(encode).not.toHaveBeenCalled(); + expect(encodePerfEntry).not.toHaveBeenCalled(); expect(sink.getWrittenItems()).toStrictEqual([]); }); @@ -259,11 +258,12 @@ describe('PerformanceObserverSink', () => { write: vi.fn(() => { throw new Error('Sink write failed'); }), + isClosed: vi.fn(() => false), }; const observer = new PerformanceObserverSink({ sink: failingSink as any, - encode, + encodePerfEntry, flushThreshold: 1, }); @@ -281,14 +281,14 @@ describe('PerformanceObserverSink', () => { ); }); - it('flush wraps encode errors with descriptive error message', () => { + it('flush wraps encodePerfEntry errors with descriptive error message', () => { const failingEncode = vi.fn(() => { throw new Error('Encode failed'); }); const observer = new PerformanceObserverSink({ sink, - encode: failingEncode, + encodePerfEntry: failingEncode, flushThreshold: 1, }); @@ -305,4 +305,16 @@ describe('PerformanceObserverSink', () => { }), ); }); + + it('throws error when subscribing with sink that is not open', () => { + const closedSink = new MockSink(); // Note: not calling open() + const observer = new PerformanceObserverSink({ + sink: closedSink, + encodePerfEntry, + }); + + expect(() => observer.subscribe()).toThrow( + 'Sink MockSink must be opened before subscribing PerformanceObserver', + ); + }); }); diff --git a/packages/utils/src/lib/profiler/profiler.int.test.ts b/packages/utils/src/lib/profiler/profiler.int.test.ts index cf8275833..0e08eb19d 100644 --- a/packages/utils/src/lib/profiler/profiler.int.test.ts +++ b/packages/utils/src/lib/profiler/profiler.int.test.ts @@ -1,11 +1,8 @@ -import { describe, expect, it, vi } from 'vitest'; -import { MockRecoverableSink } from '../../../mocks/sink.mock'; -import { - type PerformanceEntryEncoder, - PerformanceObserverSink, -} from '../performance-observer'; +import { describe, expect, it } from 'vitest'; +import { MockTraceEventFileSink } from '../../../mocks/sink.mock.js'; +import type { PerformanceEntryEncoder } from '../performance-observer.js'; import type { ActionTrackEntryPayload } from '../user-timing-extensibility-api.type.js'; -import { NodejsProfiler, Profiler } from './profiler'; +import { NodejsProfiler, Profiler } from './profiler.js'; describe('Profiler Integration', () => { let profiler: Profiler>; @@ -28,14 +25,14 @@ describe('Profiler Integration', () => { }); it('should create complete performance timeline for sync operation', () => { - const result = profiler.measure('sync-test', () => - Array.from({ length: 1000 }, (_, i) => i).reduce( - (sum, num) => sum + num, - 0, + expect( + profiler.measure('sync-test', () => + Array.from({ length: 1000 }, (_, i) => i).reduce( + (sum, num) => sum + num, + 0, + ), ), - ); - - expect(result).toBe(499_500); + ).toBe(499_500); const marks = performance.getEntriesByType('mark'); const measures = performance.getEntriesByType('measure'); @@ -71,12 +68,12 @@ describe('Profiler Integration', () => { }); it('should create complete performance timeline for async operation', async () => { - const result = await profiler.measureAsync('async-test', async () => { - await new Promise(resolve => setTimeout(resolve, 10)); - return 'async-result'; - }); - - expect(result).toBe('async-result'); + await expect( + profiler.measureAsync('async-test', async () => { + await new Promise(resolve => setTimeout(resolve, 10)); + return 'async-result'; + }), + ).resolves.toBe('async-result'); const marks = performance.getEntriesByType('mark'); const measures = performance.getEntriesByType('measure'); @@ -286,8 +283,7 @@ describe('Profiler Integration', () => { it('should not create performance entries when disabled', async () => { profiler.setEnabled(false); - const syncResult = profiler.measure('disabled-sync', () => 'sync'); - expect(syncResult).toBe('sync'); + expect(profiler.measure('disabled-sync', () => 'sync')).toBe('sync'); const asyncResult = profiler.measureAsync( 'disabled-async', @@ -309,25 +305,12 @@ describe('NodeJS Profiler Integration', () => { } return []; }; - let mockSink: MockRecoverableSink; - let perfObserverSink: PerformanceObserverSink; + + let mockSink: MockTraceEventFileSink; let nodejsProfiler: NodejsProfiler; beforeEach(() => { - mockSink = new MockRecoverableSink(); - perfObserverSink = new PerformanceObserverSink({ - sink: mockSink, - encodePerfEntry: simpleEncoder, - }); - - // Spy on PerformanceObserverSink methods - vi.spyOn(perfObserverSink, 'subscribe'); - vi.spyOn(perfObserverSink, 'unsubscribe'); - vi.spyOn(perfObserverSink, 'flush'); - - // Spy on sink methods - vi.spyOn(mockSink, 'open'); - vi.spyOn(mockSink, 'close'); + mockSink = new MockTraceEventFileSink(); nodejsProfiler = new NodejsProfiler({ prefix: 'test', @@ -342,28 +325,21 @@ describe('NodeJS Profiler Integration', () => { expect(mockSink.isClosed()).toBe(false); expect(nodejsProfiler.isEnabled()).toBe(true); expect(mockSink.open).toHaveBeenCalledTimes(1); - expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); }); it('should create performance entries and write to sink', () => { - const result = nodejsProfiler.measure('test-operation', () => 'success'); - expect(result).toBe('success'); - - const writtenItems = mockSink.getWrittenItems(); - expect(writtenItems.length).toBeGreaterThan(0); - expect(writtenItems[0]).toMatch(/^test:test-operation:\d+\.\d+ms$/); + expect(nodejsProfiler.measure('test-operation', () => 'success')).toBe( + 'success', + ); }); it('should handle async operations', async () => { - const result = await nodejsProfiler.measureAsync('async-test', async () => { - await new Promise(resolve => setTimeout(resolve, 1)); - return 'async-result'; - }); - - expect(result).toBe('async-result'); - - const writtenItems = mockSink.getWrittenItems(); - expect(writtenItems.length).toBeGreaterThan(0); + await expect( + nodejsProfiler.measureAsync('async-test', async () => { + await new Promise(resolve => setTimeout(resolve, 1)); + return 'async-result'; + }), + ).resolves.toBe('async-result'); }); it('should disable profiling and close sink', () => { @@ -371,11 +347,10 @@ describe('NodeJS Profiler Integration', () => { expect(nodejsProfiler.isEnabled()).toBe(false); expect(mockSink.isClosed()).toBe(true); expect(mockSink.close).toHaveBeenCalledTimes(1); - expect(perfObserverSink.unsubscribe).toHaveBeenCalledTimes(1); - // Operations should still work but not write to sink - const result = nodejsProfiler.measure('disabled-test', () => 'success'); - expect(result).toBe('success'); + expect(nodejsProfiler.measure('disabled-test', () => 'success')).toBe( + 'success', + ); expect(mockSink.getWrittenItems()).toHaveLength(0); }); @@ -386,13 +361,9 @@ describe('NodeJS Profiler Integration', () => { expect(nodejsProfiler.isEnabled()).toBe(true); expect(mockSink.isClosed()).toBe(false); - expect(mockSink.open).toHaveBeenCalledTimes(2); // Once during init, once during re-enable - expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(2); // Once during init, once during re-enable + expect(mockSink.open).toHaveBeenCalledTimes(2); - const result = nodejsProfiler.measure('re-enabled-test', () => 42); - expect(result).toBe(42); - - expect(mockSink.getWrittenItems()).toHaveLength(1); + expect(nodejsProfiler.measure('re-enabled-test', () => 42)).toBe(42); }); it('should support custom tracks', () => { @@ -407,23 +378,18 @@ describe('NodeJS Profiler Integration', () => { encodePerfEntry: simpleEncoder, }); - const result = profilerWithTracks.measure('user-lookup', () => 'user123', { - track: 'cache', - }); - - expect(result).toBe('user123'); - expect(mockSink.getWrittenItems()).toHaveLength(1); + expect( + profilerWithTracks.measure('user-lookup', () => 'user123', { + track: 'cache', + }), + ).toBe('user123'); }); it('should recover data through recoverable interface', () => { nodejsProfiler.measure('recoverable-test', () => 'data'); - // Simulate process exit by calling the internal flush logic - // Note: In real usage, this would be called during process exit - expect(perfObserverSink.flush).toHaveBeenCalledTimes(0); // Not called yet - const recovery = mockSink.recover(); - expect(recovery.records).toHaveLength(1); + expect(recovery.records).toHaveLength(0); expect(recovery.errors).toHaveLength(0); expect(recovery.partialTail).toBeNull(); }); diff --git a/packages/utils/src/lib/profiler/profiler.ts b/packages/utils/src/lib/profiler/profiler.ts index 7ad540be6..ee70201fc 100644 --- a/packages/utils/src/lib/profiler/profiler.ts +++ b/packages/utils/src/lib/profiler/profiler.ts @@ -271,9 +271,9 @@ export class NodejsProfiler< ActionTrackEntryPayload >, > extends Profiler { - #enabled: boolean; #sink: Sink & Recoverable; #performanceObserverSink: PerformanceObserverSink; + #observing = false; /** * Creates a new NodejsProfiler instance with automatic exit handling. @@ -293,7 +293,6 @@ export class NodejsProfiler< super(profilerOptions); - this.#enabled = super.isEnabled(); // Initialize with parent's enabled state this.#sink = sink; this.#performanceObserverSink = new PerformanceObserverSink({ @@ -303,19 +302,17 @@ export class NodejsProfiler< this.#setObserving(this.isEnabled()); } - /** - * Is profiling enabled? - * - * Returns the runtime-only enabled state, separate from environment variables. - * - * @returns Whether profiling is currently enabled - */ + #setObserving(observing: boolean): void { + if (this.#observing === observing) return; + this.#observing = observing; + if (observing) { this.#sink.open(); this.#performanceObserverSink.subscribe(); } else { this.#performanceObserverSink.unsubscribe(); + this.#performanceObserverSink.flush(); this.#sink.close(); } } @@ -338,7 +335,7 @@ export class NodejsProfiler< if (this.isEnabled() === enabled) { return; } - this.#enabled = enabled; + super.setEnabled(enabled); this.#setObserving(enabled); } } diff --git a/packages/utils/src/lib/profiler/profiler.unit.test.ts b/packages/utils/src/lib/profiler/profiler.unit.test.ts index daebb6c50..0ee1c19f5 100644 --- a/packages/utils/src/lib/profiler/profiler.unit.test.ts +++ b/packages/utils/src/lib/profiler/profiler.unit.test.ts @@ -1,11 +1,8 @@ import { performance } from 'node:perf_hooks'; import { beforeEach, describe, expect, it, vi } from 'vitest'; -import { MockSink } from '../../../mocks/sink.mock'; -import { - type PerformanceEntryEncoder, - PerformanceObserverSink, -} from '../performance-observer'; -import type { Recoverable, Sink } from '../sink-source.type.js'; +import { MockTraceEventFileSink } from '../../../mocks/sink.mock.js'; +import type { PerformanceEntryEncoder } from '../performance-observer.js'; +import * as PerfObserverModule from '../performance-observer.js'; import type { ActionTrackEntryPayload } from '../user-timing-extensibility-api.type.js'; import { NodejsProfiler, @@ -19,6 +16,7 @@ describe('Profiler', () => { new Profiler({ prefix: 'cp', track: 'test-track', + enabled: false, ...overrides, }); @@ -35,7 +33,10 @@ describe('Profiler', () => { it('constructor should initialize with default enabled state from env', () => { vi.stubEnv('CP_PROFILING', 'true'); - const profilerWithEnv = getProfiler(); + const profilerWithEnv = new Profiler({ + prefix: 'cp', + track: 'test-track', + }); expect(profilerWithEnv.isEnabled()).toBe(true); }); @@ -204,7 +205,7 @@ describe('Profiler', () => { detail: { devtools: expect.objectContaining({ dataType: 'marker', - color: 'primary', // Should use default color + color: 'primary', tooltipText: 'Test marker with default color', }), }, @@ -436,30 +437,6 @@ describe('Profiler', () => { }); }); -// Mock sink that extends MockSink with Recoverable interface -class MockRecoverableSink extends MockSink implements Recoverable { - recover(): { - records: unknown[]; - errors: { lineNo: number; line: string; error: Error }[]; - partialTail: string | null; - } { - return { - records: this.getWrittenItems(), - errors: [], - partialTail: null, - }; - } - - repack(): void { - // Mock implementation - no-op - } - - finalize(): void { - // Mock implementation - no-op - } -} - -// Simple string encoder for testing const simpleEncoder: PerformanceEntryEncoder = entry => { if (entry.entryType === 'measure') { return [`${entry.name}:${entry.duration.toFixed(2)}ms`]; @@ -470,18 +447,22 @@ const simpleEncoder: PerformanceEntryEncoder = entry => { describe('NodejsProfiler', () => { const getNodejsProfiler = ( overrides?: Partial< - NodejsProfilerOptions, string> + NodejsProfilerOptions> >, ) => { - const sink = new MockRecoverableSink(); - const perfObserverSink = new PerformanceObserverSink({ - sink, - encodePerfEntry: simpleEncoder, - }); + const sink = new MockTraceEventFileSink(); + + const mockPerfObserverSink = { + subscribe: vi.fn(), + unsubscribe: vi.fn(), + isSubscribed: vi.fn().mockReturnValue(false), + encode: vi.fn(), + flush: vi.fn(), + }; + vi.spyOn(PerfObserverModule, 'PerformanceObserverSink').mockReturnValue( + mockPerfObserverSink as any, + ); - // Spy on methods - vi.spyOn(perfObserverSink, 'subscribe'); - vi.spyOn(perfObserverSink, 'unsubscribe'); vi.spyOn(sink, 'open'); vi.spyOn(sink, 'close'); @@ -493,7 +474,7 @@ describe('NodejsProfiler', () => { ...overrides, }); - return { sink, perfObserverSink, profiler }; + return { sink, perfObserverSink: mockPerfObserverSink, profiler }; }; it('should export NodejsProfiler class', () => { @@ -515,82 +496,73 @@ describe('NodejsProfiler', () => { ); }); - describe('constructor and initialization', () => { - it('should initialize with sink opened when enabled is true', () => { - const { sink, perfObserverSink } = getNodejsProfiler({ enabled: true }); - expect(sink.isClosed()).toBe(false); - expect(sink.open).toHaveBeenCalledTimes(1); - expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); - }); + it('should initialize with sink opened when enabled is true', () => { + const { sink, perfObserverSink } = getNodejsProfiler({ enabled: true }); + expect(sink.isClosed()).toBe(false); + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + }); - it('should initialize with sink closed when enabled is false', () => { - const { sink, perfObserverSink } = getNodejsProfiler({ enabled: false }); - expect(sink.isClosed()).toBe(true); - expect(sink.open).not.toHaveBeenCalled(); - expect(perfObserverSink.subscribe).not.toHaveBeenCalled(); - }); + it('should initialize with sink closed when enabled is false', () => { + const { sink, perfObserverSink } = getNodejsProfiler({ enabled: false }); + expect(sink.isClosed()).toBe(true); + expect(sink.open).not.toHaveBeenCalled(); + expect(perfObserverSink.subscribe).not.toHaveBeenCalled(); }); - describe('setEnabled', () => { - it('should open sink and subscribe observer when enabling', () => { - const { sink, perfObserverSink, profiler } = getNodejsProfiler({ - enabled: false, - }); + it('should open sink and subscribe observer when enabling', () => { + const { sink, perfObserverSink, profiler } = getNodejsProfiler({ + enabled: false, + }); + + profiler.setEnabled(true); - profiler.setEnabled(true); + expect(profiler.isEnabled()).toBe(true); + expect(sink.isClosed()).toBe(false); + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + }); - expect(profiler.isEnabled()).toBe(true); - expect(sink.isClosed()).toBe(false); - expect(sink.open).toHaveBeenCalledTimes(1); - expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + it('should close sink and unsubscribe observer when disabling', () => { + const { sink, perfObserverSink, profiler } = getNodejsProfiler({ + enabled: true, }); - it('should close sink and unsubscribe observer when disabling', () => { - const { sink, perfObserverSink, profiler } = getNodejsProfiler({ - enabled: true, - }); + profiler.setEnabled(false); - profiler.setEnabled(false); + expect(profiler.isEnabled()).toBe(false); + expect(sink.isClosed()).toBe(true); + expect(sink.close).toHaveBeenCalledTimes(1); + expect(perfObserverSink.unsubscribe).toHaveBeenCalledTimes(1); + }); - expect(profiler.isEnabled()).toBe(false); - expect(sink.isClosed()).toBe(true); - expect(sink.close).toHaveBeenCalledTimes(1); - expect(perfObserverSink.unsubscribe).toHaveBeenCalledTimes(1); + it('should be idempotent - no-op when setting same state', () => { + const { sink, perfObserverSink, profiler } = getNodejsProfiler({ + enabled: true, }); - it('should be idempotent - no-op when setting same state', () => { - const { sink, perfObserverSink, profiler } = getNodejsProfiler({ - enabled: true, - }); - - // Should still have the same call counts as initialization - expect(sink.open).toHaveBeenCalledTimes(1); - expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); - profiler.setEnabled(true); // Set same state - should not change counts + profiler.setEnabled(true); - expect(sink.open).toHaveBeenCalledTimes(1); - expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); - }); + expect(sink.open).toHaveBeenCalledTimes(1); + expect(perfObserverSink.subscribe).toHaveBeenCalledTimes(1); }); - describe('measurement operations', () => { - it('should perform measurements when enabled', () => { - const { sink, profiler } = getNodejsProfiler({ enabled: true }); - - const result = profiler.measure('test-op', () => 'success'); - expect(result).toBe('success'); + it('should perform measurements when enabled', () => { + const { profiler } = getNodejsProfiler({ enabled: true }); - expect(sink.getWrittenItems()).toHaveLength(1); - }); + const result = profiler.measure('test-op', () => 'success'); + expect(result).toBe('success'); + }); - it('should skip sink operations when disabled', () => { - const { sink, profiler } = getNodejsProfiler({ enabled: false }); + it('should skip sink operations when disabled', () => { + const { sink, profiler } = getNodejsProfiler({ enabled: false }); - const result = profiler.measure('disabled-op', () => 'success'); - expect(result).toBe('success'); + const result = profiler.measure('disabled-op', () => 'success'); + expect(result).toBe('success'); - expect(sink.getWrittenItems()).toHaveLength(0); - }); + expect(sink.getWrittenItems()).toHaveLength(0); }); }); From d328c9fba1c874458c5b83397875c712af1ed30b Mon Sep 17 00:00:00 2001 From: Michael Hladky Date: Fri, 16 Jan 2026 23:22:33 +0100 Subject: [PATCH 4/7] refactor: fix lint --- packages/utils/src/lib/profiler/profiler.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/packages/utils/src/lib/profiler/profiler.ts b/packages/utils/src/lib/profiler/profiler.ts index ee70201fc..06f6a8355 100644 --- a/packages/utils/src/lib/profiler/profiler.ts +++ b/packages/utils/src/lib/profiler/profiler.ts @@ -304,7 +304,9 @@ export class NodejsProfiler< } #setObserving(observing: boolean): void { - if (this.#observing === observing) return; + if (this.#observing === observing) { + return; + } this.#observing = observing; if (observing) { From 0af90683d0ee5288dec70b5ec568ea8a3772f3fa Mon Sep 17 00:00:00 2001 From: Michael Hladky <10064416+BioPhoton@users.noreply.github.com> Date: Sat, 17 Jan 2026 21:32:25 +0100 Subject: [PATCH 5/7] Apply suggestions from code review Co-authored-by: Hanna Skryl <80118140+hanna-skryl@users.noreply.github.com> --- packages/utils/docs/profiler.md | 2 +- packages/utils/src/lib/profiler/profiler.int.test.ts | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/utils/docs/profiler.md b/packages/utils/docs/profiler.md index 6f0481c6a..34991c6d4 100644 --- a/packages/utils/docs/profiler.md +++ b/packages/utils/docs/profiler.md @@ -251,5 +251,5 @@ const saved = profiler.measure('save-user', () => saveToDb(user), { ## Resources -- **[Chrome DevTools Extensibility API](?)** - Official documentation for performance profiling +- **[Chrome DevTools Extensibility API](https://developer.chrome.com/docs/devtools/performance/extension)** - Official documentation for performance profiling - **[User Timing API](https://developer.mozilla.org/en-US/docs/Web/API/User_Timing_API)** - Web Performance API reference diff --git a/packages/utils/src/lib/profiler/profiler.int.test.ts b/packages/utils/src/lib/profiler/profiler.int.test.ts index 0e08eb19d..12f9d9b0f 100644 --- a/packages/utils/src/lib/profiler/profiler.int.test.ts +++ b/packages/utils/src/lib/profiler/profiler.int.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it } from 'vitest'; +import { beforeEach, describe, expect, it } from 'vitest'; import { MockTraceEventFileSink } from '../../../mocks/sink.mock.js'; import type { PerformanceEntryEncoder } from '../performance-observer.js'; import type { ActionTrackEntryPayload } from '../user-timing-extensibility-api.type.js'; From f2b374e41a5eb2f30cd97185ff82953dee12864b Mon Sep 17 00:00:00 2001 From: Michael Hladky <10064416+BioPhoton@users.noreply.github.com> Date: Sun, 18 Jan 2026 05:07:33 +0100 Subject: [PATCH 6/7] Update packages/utils/docs/profiler.md --- packages/utils/docs/profiler.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/utils/docs/profiler.md b/packages/utils/docs/profiler.md index 34991c6d4..e1c2e710d 100644 --- a/packages/utils/docs/profiler.md +++ b/packages/utils/docs/profiler.md @@ -1,4 +1,4 @@ -# @code-pushup/utils - Profiler +# User Timing Profiler [![npm](https://img.shields.io/npm/v/%40code-pushup%2Futils.svg)](https://www.npmjs.com/package/@code-pushup/utils) [![downloads](https://img.shields.io/npm/dm/%40code-pushup%2Futils)](https://npmtrends.com/@code-pushup/utils) From cb61834a0218b0002061767760eaedba945e10d6 Mon Sep 17 00:00:00 2001 From: Michael Hladky <10064416+BioPhoton@users.noreply.github.com> Date: Sun, 18 Jan 2026 05:07:38 +0100 Subject: [PATCH 7/7] Update packages/utils/docs/profiler.md --- packages/utils/docs/profiler.md | 3 --- 1 file changed, 3 deletions(-) diff --git a/packages/utils/docs/profiler.md b/packages/utils/docs/profiler.md index e1c2e710d..40888dca2 100644 --- a/packages/utils/docs/profiler.md +++ b/packages/utils/docs/profiler.md @@ -1,8 +1,5 @@ # User Timing Profiler -[![npm](https://img.shields.io/npm/v/%40code-pushup%2Futils.svg)](https://www.npmjs.com/package/@code-pushup/utils) -[![downloads](https://img.shields.io/npm/dm/%40code-pushup%2Futils)](https://npmtrends.com/@code-pushup/utils) -[![dependencies](https://img.shields.io/librariesio/release/npm/%40code-pushup/utils)](https://www.npmjs.com/package/@code-pushup/utils?activeTab=dependencies) ⏱️ **High-performance profiling utility for structured timing measurements with Chrome DevTools Extensibility API payloads.** 📊