diff --git a/packages/utils/src/lib/create-runner-files.ts b/packages/utils/src/lib/create-runner-files.ts index 5cb402580..8a8495555 100644 --- a/packages/utils/src/lib/create-runner-files.ts +++ b/packages/utils/src/lib/create-runner-files.ts @@ -1,8 +1,8 @@ import { writeFile } from 'node:fs/promises'; import path from 'node:path'; -import { threadId } from 'node:worker_threads'; import type { RunnerFilesPaths } from '@code-pushup/models'; import { ensureDirectoryExists, pluginWorkDir } from './file-system.js'; +import { getUniqueProcessThreadId } from './process-id.js'; /** * Function to create timestamp nested plugin runner files for config and output. @@ -14,9 +14,7 @@ export async function createRunnerFiles( pluginSlug: string, configJSON: string, ): Promise { - // Use timestamp + process ID + threadId - // This prevents race conditions when running the same plugin for multiple projects in parallel - const uniqueId = `${(performance.timeOrigin + performance.now()) * 10}-${process.pid}-${threadId}`; + const uniqueId = getUniqueProcessThreadId(); const runnerWorkDir = path.join(pluginWorkDir(pluginSlug), uniqueId); const runnerConfigPath = path.join(runnerWorkDir, 'plugin-config.json'); const runnerOutputPath = path.join(runnerWorkDir, 'runner-output.json'); diff --git a/packages/utils/src/lib/process-id.ts b/packages/utils/src/lib/process-id.ts new file mode 100644 index 000000000..b18ec3e65 --- /dev/null +++ b/packages/utils/src/lib/process-id.ts @@ -0,0 +1,113 @@ +import process from 'node:process'; +import { threadId } from 'node:worker_threads'; + +/** + * Counter interface for generating sequential instance IDs. + * Encapsulates increment logic within the counter-implementation. + */ +export type Counter = { + /** + * Returns the next counter-value and increments the internal state. + * @returns The next counter-value + */ + next: () => number; +}; + +/** + * Base regex pattern for time ID format: yyyymmdd-hhmmss-ms + */ +export const TIME_ID_BASE = /\d{8}-\d{6}-\d{3}/; + +/** + * Regex patterns for validating process and instance ID formats. + * All patterns use strict anchors (^ and $) to ensure complete matches. + */ +export const ID_PATTERNS = Object.freeze({ + /** + * Time ID / Run ID format: yyyymmdd-hhmmss-ms + * Example: "20240101-120000-000" + * Used by: getUniqueTimeId() + */ + TIME_ID: new RegExp(`^${TIME_ID_BASE.source}$`), + /** + * Group ID format: alias by convention, semantically represents a group of instances + * Example: "20240101-120000-000" + * Used by: grouping related instances by time + */ + GROUP_ID: new RegExp(`^${TIME_ID_BASE.source}$`), + /** + * Process/Thread ID format: timeId-pid-threadId + * Example: "20240101-120000-000-12345-1" + * Used by: getUniqueProcessThreadId() + */ + PROCESS_THREAD_ID: new RegExp(`^${TIME_ID_BASE.source}-\\d+-\\d+$`), + /** + * Instance ID format: timeId.pid.threadId.counter + * Example: "20240101-120000-000.12345.1.1" + * Used by: getUniqueInstanceId() + */ + INSTANCE_ID: new RegExp(`^${TIME_ID_BASE.source}\\.\\d+\\.\\d+\\.\\d+$`), +} as const); + +/** + * Generates a unique run ID. + * This ID uniquely identifies a run/execution with a globally unique, sortable, human-readable date string. + * Format: yyyymmdd-hhmmss-ms + * Example: "20240101-120000-000" + * + * @returns A unique run ID string in readable date format + */ +export function getUniqueTimeId(): string { + return sortableReadableDateString( + Math.floor(performance.timeOrigin + performance.now()), + ); +} + +/** + * Generates a unique process/thread ID. + * This ID uniquely identifies a process/thread execution and prevents race conditions when running + * the same plugin for multiple projects in parallel. + * Format: timeId-pid-threadId + * Example: "20240101-120000-000-12345-1" + * + * @returns A unique ID string combining timestamp, process ID, and thread ID + */ +export function getUniqueProcessThreadId(): string { + return `${getUniqueTimeId()}-${process.pid}-${threadId}`; +} + +/** + * Generates a unique instance ID based on performance time origin, process ID, thread ID, and instance count. + * This ID uniquely identifies an instance across processes and threads. + * Format: timestamp.pid.threadId.counter + * Example: "20240101-120000-000.12345.1.1" + * + * @param counter - Counter that provides the next instance count value + * @returns A unique ID string combining timestamp, process ID, thread ID, and counter + */ +export function getUniqueInstanceId(counter: Counter): string { + return `${getUniqueTimeId()}.${process.pid}.${threadId}.${counter.next()}`; +} + +/** + * Converts a timestamp in milliseconds to a sortable, human-readable date string. + * Format: yyyymmdd-hhmmss-ms + * Example: "20240101-120000-000" + * + * @param timestampMs - Timestamp in milliseconds + * @returns A sortable date string in yyyymmdd-hhmmss-ms format + */ +export function sortableReadableDateString(timestampMs: number): string { + const date = new Date(timestampMs); + const MILLISECONDS_PER_SECOND = 1000; + const yyyy = date.getFullYear(); + const mm = String(date.getMonth() + 1).padStart(2, '0'); + const dd = String(date.getDate()).padStart(2, '0'); + const hh = String(date.getHours()).padStart(2, '0'); + const min = String(date.getMinutes()).padStart(2, '0'); + const ss = String(date.getSeconds()).padStart(2, '0'); + // eslint-disable-next-line @typescript-eslint/no-magic-numbers + const ms = String(timestampMs % MILLISECONDS_PER_SECOND).padStart(3, '0'); + + return `${yyyy}${mm}${dd}-${hh}${min}${ss}-${ms}`; +} diff --git a/packages/utils/src/lib/process-id.unit.test.ts b/packages/utils/src/lib/process-id.unit.test.ts new file mode 100644 index 000000000..7a073c8a9 --- /dev/null +++ b/packages/utils/src/lib/process-id.unit.test.ts @@ -0,0 +1,189 @@ +import { threadId } from 'node:worker_threads'; +import { + type Counter, + ID_PATTERNS, + TIME_ID_BASE, + getUniqueInstanceId, + getUniqueProcessThreadId, + getUniqueTimeId, + sortableReadableDateString, +} from './process-id.js'; + +describe('TIME_ID_BASE', () => { + it.each([ + '20231114-221320-000', + '20240101-120000-000', + '20231231-235959-999', + ])('should match valid time ID format: %s', timeId => { + expect(timeId).toMatch(TIME_ID_BASE); + }); + + it.each(['2023-11-14', '20231114', '20231114-221320', 'invalid'])( + 'should not match invalid time ID format: %s', + timeId => { + expect(timeId).not.toMatch(TIME_ID_BASE); + }, + ); +}); + +describe('ID_PATTERNS', () => { + it.each(['20231114-221320-000', '20240101-120000-000'])( + 'TIME_ID should match valid time ID: %s', + timeId => { + expect(timeId).toMatch(ID_PATTERNS.TIME_ID); + }, + ); + + it.each(['20231114-221320-000.123', '20231114-221320'])( + 'TIME_ID should not match invalid format: %s', + timeId => { + expect(timeId).not.toMatch(ID_PATTERNS.TIME_ID); + }, + ); + + it.each(['20231114-221320-000'])( + 'GROUP_ID should match valid group ID: %s', + groupId => { + expect(groupId).toMatch(ID_PATTERNS.GROUP_ID); + }, + ); + + it.each(['20231114-221320-000-12345-1', '20240101-120000-000-99999-99'])( + 'PROCESS_THREAD_ID should match valid process/thread ID: %s', + processThreadId => { + expect(processThreadId).toMatch(ID_PATTERNS.PROCESS_THREAD_ID); + }, + ); + + it.each(['20231114-221320-000', '20231114-221320-000-12345'])( + 'PROCESS_THREAD_ID should not match invalid format: %s', + processThreadId => { + expect(processThreadId).not.toMatch(ID_PATTERNS.PROCESS_THREAD_ID); + }, + ); + + it.each(['20231114-221320-000.12345.1.1', '20240101-120000-000.99999.99.42'])( + 'INSTANCE_ID should match valid instance ID: %s', + instanceId => { + expect(instanceId).toMatch(ID_PATTERNS.INSTANCE_ID); + }, + ); + + it.each(['20231114-221320-000', '20231114-221320-000-12345-1'])( + 'INSTANCE_ID should not match invalid format: %s', + instanceId => { + expect(instanceId).not.toMatch(ID_PATTERNS.INSTANCE_ID); + }, + ); + + it.each(['20231114-221320-000.12345.1.1'])( + 'INSTANCE_ID should match valid instance ID: %s', + instanceId => { + expect(instanceId).toMatch(ID_PATTERNS.INSTANCE_ID); + }, + ); + + it.each(['20231114-221320-000'])( + 'TIME_ID should match valid time ID: %s', + timeId => { + expect(timeId).toMatch(ID_PATTERNS.TIME_ID); + }, + ); +}); + +describe('sortableReadableDateString', () => { + it('should format timestamp correctly', () => { + const timestamp = 1_700_000_000_000; // 2023-11-14 22:13:20.000 + const result = sortableReadableDateString(timestamp); + expect(result).toBe('20231114-221320-000'); + expect(result).toMatch(TIME_ID_BASE); + }); +}); + +describe('getUniqueTimeId', () => { + it('should generate time ID with mocked timeOrigin', () => { + const result = getUniqueTimeId(); + + expect(result).toMatch(ID_PATTERNS.TIME_ID); + expect(result).toMatch(ID_PATTERNS.GROUP_ID); + expect(result).toBe('20231114-221320-000'); + }); + + it('should generate new ID on each call (not idempotent)', () => { + let callCount = 0; + vi.spyOn(performance, 'now').mockImplementation(() => callCount++); + + const id1 = getUniqueTimeId(); + const id2 = getUniqueTimeId(); + + expect(id1).not.toBe(id2); + expect(id1).toMatch(ID_PATTERNS.TIME_ID); + expect(id2).toMatch(ID_PATTERNS.TIME_ID); + }); +}); + +describe('getUniqueProcessThreadId', () => { + it('should generate process/thread ID with correct format', () => { + const result = getUniqueProcessThreadId(); + + expect(result).toMatch(ID_PATTERNS.PROCESS_THREAD_ID); + expect(result).toContain(`-10001-${threadId}`); + expect(result).toStartWith('20231114-221320-000'); + }); + + it('should generate new ID on each call (not idempotent)', () => { + let callCount = 0; + vi.spyOn(performance, 'now').mockImplementation(() => callCount++); + + const id1 = getUniqueProcessThreadId(); + const id2 = getUniqueProcessThreadId(); + + expect(id1).not.toBe(id2); + expect(id1).toMatch(ID_PATTERNS.PROCESS_THREAD_ID); + expect(id2).toMatch(ID_PATTERNS.PROCESS_THREAD_ID); + }); +}); + +describe('getUniqueInstanceId', () => { + it('should generate instance ID with correct format', () => { + let counter = 0; + const counterObj: Counter = { + next: () => ++counter, + }; + + const result = getUniqueInstanceId(counterObj); + + expect(result).toMatch(ID_PATTERNS.INSTANCE_ID); + expect(result).toStartWith('20231114-221320-000.'); + expect(result).toContain(`.10001.${threadId}.`); + expect(result).toEndWith('.1'); + }); + + it('should use counter to generate incrementing instance IDs', () => { + let counter = 0; + const counterObj: Counter = { + next: () => ++counter, + }; + + const results = [ + getUniqueInstanceId(counterObj), + getUniqueInstanceId(counterObj), + getUniqueInstanceId(counterObj), + ]; + + expect(results[0]).toEndWith('.1'); + expect(results[1]).toEndWith('.2'); + expect(results[2]).toEndWith('.3'); + }); + + it('should generate different IDs for different calls', () => { + let counter = 0; + const counterObj: Counter = { + next: () => ++counter, + }; + + expect(getUniqueInstanceId(counterObj)).not.toBe( + getUniqueInstanceId(counterObj), + ); + }); +}); diff --git a/packages/utils/src/lib/profiler/__snapshots__/comprehensive-stats-trace-events.jsonl b/packages/utils/src/lib/profiler/__snapshots__/comprehensive-stats-trace-events.jsonl index 5583ed827..717dfddfa 100644 --- a/packages/utils/src/lib/profiler/__snapshots__/comprehensive-stats-trace-events.jsonl +++ b/packages/utils/src/lib/profiler/__snapshots__/comprehensive-stats-trace-events.jsonl @@ -1,8 +1,8 @@ -{"cat":"blink.user_timing","ph":"i","name":"stats-profiler:operation-1:start","pid":10001,"tid":1,"ts":1700000005000000,"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} -{"cat":"blink.user_timing","ph":"b","name":"stats-profiler:operation-1","id2":{"local":"0x1"},"pid":10001,"tid":1,"ts":1700000005000001,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"e","name":"stats-profiler:operation-1","id2":{"local":"0x1"},"pid":10001,"tid":1,"ts":1700000005000002,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"i","name":"stats-profiler:operation-1:end","pid":10001,"tid":1,"ts":1700000005000003,"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} -{"cat":"blink.user_timing","ph":"i","name":"stats-profiler:operation-2:start","pid":10001,"tid":1,"ts":1700000005000004,"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} -{"cat":"blink.user_timing","ph":"b","name":"stats-profiler:operation-2","id2":{"local":"0x2"},"pid":10001,"tid":1,"ts":1700000005000005,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"e","name":"stats-profiler:operation-2","id2":{"local":"0x2"},"pid":10001,"tid":1,"ts":1700000005000006,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"i","name":"stats-profiler:operation-2:end","pid":10001,"tid":1,"ts":1700000005000007,"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000000,"name":"stats-profiler:operation-1:start","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000001,"name":"stats-profiler:operation-1","ph":"b","id2":{"local":"0x1"},"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000002,"name":"stats-profiler:operation-1","ph":"e","id2":{"local":"0x1"},"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000003,"name":"stats-profiler:operation-1:end","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000004,"name":"stats-profiler:operation-2:start","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000005,"name":"stats-profiler:operation-2","ph":"b","id2":{"local":"0x2"},"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000006,"name":"stats-profiler:operation-2","ph":"e","id2":{"local":"0x2"},"args":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000007,"name":"stats-profiler:operation-2:end","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"Stats\",\"dataType\":\"track-entry\"}}"}}} diff --git a/packages/utils/src/lib/profiler/__snapshots__/custom-tracks-trace-events.jsonl b/packages/utils/src/lib/profiler/__snapshots__/custom-tracks-trace-events.jsonl index 43f83dbdb..4773d8e48 100644 --- a/packages/utils/src/lib/profiler/__snapshots__/custom-tracks-trace-events.jsonl +++ b/packages/utils/src/lib/profiler/__snapshots__/custom-tracks-trace-events.jsonl @@ -1,4 +1,4 @@ -{"cat":"blink.user_timing","ph":"i","name":"api-server:user-lookup:start","pid":10001,"tid":1,"ts":1700000005000000,"args":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}} -{"cat":"blink.user_timing","ph":"b","name":"api-server:user-lookup","id2":{"local":"0x1"},"pid":10001,"tid":1,"ts":1700000005000001,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"e","name":"api-server:user-lookup","id2":{"local":"0x1"},"pid":10001,"tid":1,"ts":1700000005000002,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"i","name":"api-server:user-lookup:end","pid":10001,"tid":1,"ts":1700000005000003,"args":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000000,"name":"api-server:user-lookup:start","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000001,"name":"api-server:user-lookup","ph":"b","id2":{"local":"0x1"},"args":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000002,"name":"api-server:user-lookup","ph":"e","id2":{"local":"0x1"},"args":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000003,"name":"api-server:user-lookup:end","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"cache\",\"dataType\":\"track-entry\"}}"}}} diff --git a/packages/utils/src/lib/profiler/__snapshots__/sharded-path-trace-events.jsonl b/packages/utils/src/lib/profiler/__snapshots__/sharded-path-trace-events.jsonl index 2a30bcd0a..00b2e36d8 100644 --- a/packages/utils/src/lib/profiler/__snapshots__/sharded-path-trace-events.jsonl +++ b/packages/utils/src/lib/profiler/__snapshots__/sharded-path-trace-events.jsonl @@ -1,4 +1,4 @@ -{"cat":"blink.user_timing","ph":"i","name":"write-test:test-operation:start","pid":10001,"tid":1,"ts":1700000005000000,"args":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}} -{"cat":"blink.user_timing","ph":"b","name":"write-test:test-operation","id2":{"local":"0x1"},"pid":10001,"tid":1,"ts":1700000005000001,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"e","name":"write-test:test-operation","id2":{"local":"0x1"},"pid":10001,"tid":1,"ts":1700000005000002,"args":{"data":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}}} -{"cat":"blink.user_timing","ph":"i","name":"write-test:test-operation:end","pid":10001,"tid":1,"ts":1700000005000003,"args":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000000,"name":"write-test:test-operation:start","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000001,"name":"write-test:test-operation","ph":"b","id2":{"local":"0x1"},"args":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000002,"name":"write-test:test-operation","ph":"e","id2":{"local":"0x1"},"args":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}} +{"cat":"blink.user_timing","pid":10001,"tid":1,"ts":1700000005000003,"name":"write-test:test-operation:end","ph":"I","args":{"data":{"detail":"{\"devtools\":{\"track\":\"Test\",\"dataType\":\"track-entry\"}}"}}} diff --git a/packages/utils/src/lib/profiler/constants.ts b/packages/utils/src/lib/profiler/constants.ts index c0e515787..0cb78b7ae 100644 --- a/packages/utils/src/lib/profiler/constants.ts +++ b/packages/utils/src/lib/profiler/constants.ts @@ -25,3 +25,9 @@ export const PROFILER_DEBUG_ENV_VAR = 'CP_PROFILER_DEBUG'; */ export const SHARDED_WAL_COORDINATOR_ID_ENV_VAR = 'CP_SHARDED_WAL_COORDINATOR_ID'; + +/** + * Default base name for WAL files. + * Used as the base name for sharded WAL files (e.g., "trace" in "trace.json"). + */ +export const PROFILER_PERSIST_BASENAME = 'trace'; diff --git a/packages/utils/src/lib/profiler/profiler-node.int.test.ts b/packages/utils/src/lib/profiler/profiler-node.int.test.ts index 1b903ee5a..e5267118e 100644 --- a/packages/utils/src/lib/profiler/profiler-node.int.test.ts +++ b/packages/utils/src/lib/profiler/profiler-node.int.test.ts @@ -5,16 +5,16 @@ import { omitTraceJson, } from '@code-pushup/test-utils'; import type { PerformanceEntryEncoder } from '../performance-observer.js'; -import { WAL_ID_PATTERNS } from '../wal.js'; +import { ID_PATTERNS } from '../process-id.js'; import { NodejsProfiler } from './profiler-node.js'; import { entryToTraceEvents } from './trace-file-utils.js'; -import type { UserTimingTraceEvent } from './trace-file.type.js'; +import type { TraceEvent } from './trace-file.type.js'; describe('NodeJS Profiler Integration', () => { - const traceEventEncoder: PerformanceEntryEncoder = + const traceEventEncoder: PerformanceEntryEncoder = entryToTraceEvents; - let nodejsProfiler: NodejsProfiler; + let nodejsProfiler: NodejsProfiler; beforeEach(() => { performance.clearMarks(); @@ -261,7 +261,7 @@ describe('NodeJS Profiler Integration', () => { const groupIdDir = pathParts.at(-2); const fileName = pathParts.at(-1); - expect(groupIdDir).toMatch(WAL_ID_PATTERNS.GROUP_ID); + expect(groupIdDir).toMatch(ID_PATTERNS.TIME_ID); expect(fileName).toMatch(/^trace\.\d{8}-\d{6}-\d{3}(?:\.\d+){3}\.jsonl$/); const groupIdDirPath = path.dirname(filePath); @@ -283,7 +283,7 @@ describe('NodeJS Profiler Integration', () => { const dirPath = path.dirname(filePath); const groupId = path.basename(dirPath); - expect(groupId).toMatch(WAL_ID_PATTERNS.GROUP_ID); + expect(groupId).toMatch(ID_PATTERNS.TIME_ID); // eslint-disable-next-line n/no-sync expect(fs.existsSync(dirPath)).toBeTrue(); // eslint-disable-next-line n/no-sync diff --git a/packages/utils/src/lib/profiler/profiler-node.ts b/packages/utils/src/lib/profiler/profiler-node.ts index b668b2028..3ab87b642 100644 --- a/packages/utils/src/lib/profiler/profiler-node.ts +++ b/packages/utils/src/lib/profiler/profiler-node.ts @@ -5,6 +5,11 @@ import { type PerformanceObserverOptions, PerformanceObserverSink, } from '../performance-observer.js'; +import { + type Counter, + getUniqueInstanceId, + getUniqueTimeId, +} from '../process-id.js'; import { objectToEntries } from '../transform.js'; import { errorToMarkerPayload } from '../user-timing-extensibility-api-utils.js'; import type { @@ -14,8 +19,6 @@ import type { import { type AppendableSink, WriteAheadLogFile, - getShardId, - getShardedGroupId, getShardedPath, } from '../wal.js'; import { @@ -81,6 +84,13 @@ export class NodejsProfiler< #state: 'idle' | 'running' | 'closed' = 'idle'; #debug: boolean; #unsubscribeExitHandlers: (() => void) | undefined; + #shardCounter: Counter = { + next: (() => { + // eslint-disable-next-line functional/no-let + let count = 0; + return () => ++count; + })(), + }; /** * Creates a NodejsProfiler instance. @@ -110,8 +120,8 @@ export class NodejsProfiler< process.cwd(), getShardedPath({ dir: 'tmp/profiles', - groupId: getShardedGroupId(), - shardId: getShardId(), + groupId: getUniqueTimeId(), + shardId: getUniqueInstanceId(this.#shardCounter), format: walFormat, }), ), diff --git a/packages/utils/src/lib/profiler/trace-file-utils.ts b/packages/utils/src/lib/profiler/trace-file-utils.ts index 1061062d3..a568a0470 100644 --- a/packages/utils/src/lib/profiler/trace-file-utils.ts +++ b/packages/utils/src/lib/profiler/trace-file-utils.ts @@ -5,24 +5,18 @@ import type { } from 'node:perf_hooks'; import { threadId } from 'node:worker_threads'; import { defaultClock } from '../clock-epoch.js'; -import type { UserTimingDetail } from '../user-timing-extensibility-api.type.js'; import type { - BeginEvent, - CompleteEvent, - EndEvent, - InstantEvent, - InstantEventArgs, - InstantEventTracingStartedInBrowser, - SpanEvent, - SpanEventArgs, TraceEvent, TraceEventContainer, - TraceEventRaw, TraceMetadata, - UserTimingTraceEvent, + TracingStartedInBrowserOptions, } from './trace-file.type.js'; -/** Global counter for generating unique span IDs within a trace */ +/** + * Trace-local monotonic span id counter. + * Chrome only requires uniqueness within a single trace file. + * Resetting per trace is intentional - we're not aiming for global uniqueness. + */ // eslint-disable-next-line functional/no-let let id2Count = 0; @@ -33,80 +27,98 @@ let id2Count = 0; export const nextId2 = () => ({ local: `0x${++id2Count}` }); /** - * Provides default values for trace event properties. - * @param opt - Optional overrides for process ID, thread ID, and timestamp - * @param opt.pid - Process ID override, defaults to current process PID - * @param opt.tid - Thread ID override, defaults to current thread ID - * @param opt.ts - Timestamp override in microseconds, defaults to current epoch time - * @returns Object containing pid, tid, and ts with defaults applied - */ -const defaults = (opt?: { pid?: number; tid?: number; ts?: number }) => ({ - pid: opt?.pid ?? process.pid, - tid: opt?.tid ?? threadId, - ts: opt?.ts ?? defaultClock.epochNowUs(), -}); - -/** - * Generates a unique frame tree node ID from process and thread IDs. + * Generates a frame tree node ID from process and thread IDs. * @param pid - Process ID * @param tid - Thread ID - * @returns Combined numeric ID + * @returns Frame tree node ID as a number */ export const frameTreeNodeId = (pid: number, tid: number) => Number.parseInt(`${pid}0${tid}`, 10); /** - * Generates a frame name string from process and thread IDs. + * Generates a frame name from process and thread IDs. * @param pid - Process ID * @param tid - Thread ID - * @returns Formatted frame name + * @returns Frame name string in format FRAME0P{pid}T{tid} */ export const frameName = (pid: number, tid: number) => `FRAME0P${pid}T${tid}`; /** - * Creates an instant trace event for marking a point in time. - * @param opt - Event configuration options - * @returns InstantEvent object + * Core factory for creating trace events with defaults. + * @param opt - Partial trace event with required name and ph + * @returns Complete TraceEvent with defaults applied */ -export const getInstantEvent = (opt: { - name: string; - ts?: number; - pid?: number; - tid?: number; - args?: InstantEventArgs; -}): InstantEvent => ({ - cat: 'blink.user_timing', - ph: 'i', - name: opt.name, - ...defaults(opt), - args: opt.args ?? {}, +const baseEvent = ( + opt: Partial & { name: string; ph: string }, +): TraceEvent => ({ + cat: opt.cat ?? 'blink.user_timing', + pid: opt.pid ?? process.pid, + tid: opt.tid ?? threadId, + ts: opt.ts ?? defaultClock.epochNowUs(), + ...opt, }); +/** + * Creates an instant trace event for marking a point in time. + * @param name - Event name + * @param ts - Optional timestamp in microseconds + * @param opt - Optional event configuration + * @returns Instant trace event (ph: 'I') + */ +export const instant = ( + name: string, + ts?: number, + opt?: Partial, +): TraceEvent => baseEvent({ name, ph: 'I', ts, ...opt }); + +/** + * Creates a pair of begin and end span events. + * @param name - Span name + * @param tsB - Begin timestamp in microseconds + * @param tsE - End timestamp in microseconds + * @param opt - Optional event configuration + * @param opt.tsMarkerPadding - Padding to apply to timestamps (default: 1) + * @returns Array of [begin event, end event] + */ +export const span = ( + name: string, + tsB: number, + tsE: number, + opt?: Partial & { tsMarkerPadding?: number }, +): TraceEvent[] => { + const id2 = opt?.id2 ?? nextId2(); + const pad = opt?.tsMarkerPadding ?? 1; + const { tsMarkerPadding, ...eventOpt } = opt ?? {}; + const args = eventOpt.args ?? {}; + return [ + baseEvent({ name, ph: 'b', ts: tsB + pad, id2, ...eventOpt, args }), + baseEvent({ name, ph: 'e', ts: tsE - pad, id2, ...eventOpt, args }), + ]; +}; + /** * Creates a start tracing event with frame information. * This event is needed at the beginning of the traceEvents array to make tell the UI profiling has started, and it should visualize the data. * @param opt - Tracing configuration options * @returns StartTracingEvent object */ -export const getInstantEventTracingStartedInBrowser = (opt: { - url: string; - ts?: number; - pid?: number; - tid?: number; -}): InstantEventTracingStartedInBrowser => { - const { pid, tid, ts } = defaults(opt); - const id = frameTreeNodeId(pid, tid); +export const getInstantEventTracingStartedInBrowser = ( + opt: TracingStartedInBrowserOptions, +): TraceEvent => { + const pid = opt.pid ?? process.pid; + const tid = opt.tid ?? threadId; + const ts = opt.ts ?? defaultClock.epochNowUs(); return { cat: 'devtools.timeline', - ph: 'i', + ph: 'I', name: 'TracingStartedInBrowser', pid, tid, ts, args: { data: { - frameTreeNodeId: id, + frameTreeNodeId: frameTreeNodeId(pid, tid), frames: [ { frame: frameName(pid, tid), @@ -118,157 +130,78 @@ export const getInstantEventTracingStartedInBrowser = (opt: { }, ], persistentIds: true, - }, + } satisfies Record, }, }; }; /** * Creates a complete trace event with duration. - * @param opt - Event configuration with name and duration - * @returns CompleteEvent object - */ -export const getCompleteEvent = (opt: { - name: string; - dur: number; - ts?: number; - pid?: number; - tid?: number; -}): CompleteEvent => ({ - cat: 'devtools.timeline', - ph: 'X', - name: opt.name, - dur: opt.dur, - ...defaults(opt), - args: {}, -}); - -/** Options for creating span events */ -type SpanOpt = { - name: string; - id2: { local: string }; - ts?: number; - pid?: number; - tid?: number; - args?: SpanEventArgs; -}; - -/** - * Creates a begin span event. - * @param ph - Phase ('b' for begin) - * @param opt - Span event options - * @returns BeginEvent object - */ -export function getSpanEvent(ph: 'b', opt: SpanOpt): BeginEvent; -/** - * Creates an end span event. - * @param ph - Phase ('e' for end) - * @param opt - Span event options - * @returns EndEvent object + * @param name - Event name + * @param dur - Duration in microseconds + * @param opt - Optional event configuration + * @returns Complete trace event (ph: 'X') */ -export function getSpanEvent(ph: 'e', opt: SpanOpt): EndEvent; -/** - * Creates a span event (begin or end). - * @param ph - Phase ('b' or 'e') - * @param opt - Span event options - * @returns SpanEvent object - */ -export function getSpanEvent(ph: 'b' | 'e', opt: SpanOpt): SpanEvent { - return { - cat: 'blink.user_timing', - ph, - name: opt.name, - id2: opt.id2, - ...defaults(opt), - args: opt.args?.data?.detail - ? { data: { detail: opt.args.data.detail } } - : {}, - }; -} - -/** - * Creates a pair of begin and end span events. - * @param opt - Span configuration with start/end timestamps - * @returns Tuple of BeginEvent and EndEvent - */ -export const getSpan = (opt: { - name: string; - tsB: number; - tsE: number; - id2?: { local: string }; - pid?: number; - tid?: number; - args?: SpanEventArgs; - tsMarkerPadding?: number; -}): [BeginEvent, EndEvent] => { - // tsMarkerPadding is here to make the measure slightly smaller so the markers align perfectly. - // Otherwise, the marker is visible at the start of the measure below the frame - // No padding Padding - // spans: ======== |======| - // marks: | | - const pad = opt.tsMarkerPadding ?? 1; - // b|e need to share the same id2 - const id2 = opt.id2 ?? nextId2(); - - return [ - getSpanEvent('b', { - ...opt, - id2, - ts: opt.tsB + pad, - }), - getSpanEvent('e', { - ...opt, - id2, - ts: opt.tsE - pad, - }), - ]; -}; +export const complete = ( + name: string, + dur: number, + opt?: Partial, +): TraceEvent => + baseEvent({ + cat: 'devtools.timeline', + ph: 'X', + name, + dur, + args: {}, + ...opt, + }); /** * Converts a PerformanceMark to an instant trace event. * @param entry - Performance mark entry * @param opt - Optional overrides for name, pid, and tid - * @returns InstantEvent object + * @returns Instant trace event */ export const markToInstantEvent = ( entry: PerformanceMark, opt?: { name?: string; pid?: number; tid?: number }, -): InstantEvent => - getInstantEvent({ - ...opt, - name: opt?.name ?? entry.name, - ts: defaultClock.fromEntry(entry), - args: entry.detail ? { detail: entry.detail } : undefined, - }); +): TraceEvent => + instant( + opt?.name ?? entry.name, + defaultClock.fromEntry(entry), + entry.detail + ? { args: { data: { detail: entry.detail } }, ...opt } + : { args: {}, ...opt }, + ); /** * Converts a PerformanceMeasure to a pair of span events. * @param entry - Performance measure entry * @param opt - Optional overrides for name, pid, and tid - * @returns Tuple of BeginEvent and EndEvent + * @returns Array of [begin event, end event] */ export const measureToSpanEvents = ( entry: PerformanceMeasure, opt?: { name?: string; pid?: number; tid?: number }, -): [BeginEvent, EndEvent] => - getSpan({ - ...opt, - name: opt?.name ?? entry.name, - tsB: defaultClock.fromEntry(entry), - tsE: defaultClock.fromEntry(entry, true), - args: entry.detail ? { data: { detail: entry.detail } } : undefined, - }); +): TraceEvent[] => + span( + opt?.name ?? entry.name, + defaultClock.fromEntry(entry), + defaultClock.fromEntry(entry, true), + { + ...opt, + args: entry.detail ? { detail: entry.detail } : {}, + }, + ); /** - * Converts a PerformanceEntry to an array of UserTimingTraceEvents. + * Converts a PerformanceEntry to an array of trace events. * A mark is converted to an instant event, and a measure is converted to a pair of span events. * Other entry types are ignored. * @param entry - Performance entry - * @returns UserTimingTraceEvent[] + * @returns Array of trace events */ -export function entryToTraceEvents( - entry: PerformanceEntry, -): UserTimingTraceEvent[] { +export function entryToTraceEvents(entry: PerformanceEntry): TraceEvent[] { if (entry.entryType === 'mark') { return [markToInstantEvent(entry as PerformanceMark)]; } @@ -278,6 +211,70 @@ export function entryToTraceEvents( return []; } +/** + * Creates a mapper function for transforming detail properties in args. + * @param fn - Transformation function to apply to detail values + * @returns Function that maps args object + */ +const mapArgs = (fn: (v: unknown) => unknown) => (args?: TraceEvent['args']) => + args && { + ...args, + ...(args.detail != null && { detail: fn(args.detail) }), + ...(args.data?.detail != null && { + data: { ...args.data, detail: fn(args.data.detail) }, + }), + }; + +/** + * Encodes a trace event by converting object details to JSON strings. + * @param e - Trace event with potentially object details + * @returns Trace event with string-encoded details + */ +export const encodeEvent = (e: TraceEvent): TraceEvent => { + const mappedArgs = mapArgs(d => + typeof d === 'object' ? JSON.stringify(d) : d, + )(e.args); + return { + ...e, + ...(mappedArgs && { args: mappedArgs }), + }; +}; + +/** + * Decodes a trace event by parsing JSON string details back to objects. + * @param e - Trace event with potentially string-encoded details + * @returns Trace event with decoded object details + */ +export const decodeEvent = (e: TraceEvent): TraceEvent => { + const mappedArgs = mapArgs(d => (typeof d === 'string' ? JSON.parse(d) : d))( + e.args, + ); + return { + ...e, + ...(mappedArgs && { args: mappedArgs }), + }; +}; + +/** + * Serializes a trace event to a JSON string for storage. + * First encodes the event structure (converting object details to JSON strings), + * then stringifies the entire event. + * @param event - Trace event to serialize + * @returns JSON string representation of the encoded trace event + */ +export const serializeTraceEvent = (event: TraceEvent): string => + JSON.stringify(encodeEvent(event)); + +/** + * Deserializes a JSON string back to a trace event. + * First parses the JSON string, then decodes the event structure + * (parsing JSON string details back to objects). + * @param json - JSON string representation of a trace event + * @returns Decoded trace event + */ +export const deserializeTraceEvent = (json: string): TraceEvent => + decodeEvent(JSON.parse(json)); + /** * Creates trace metadata object with standard DevTools fields and custom metadata. * @param startDate - Optional start date for the trace, defaults to current date @@ -287,7 +284,7 @@ export function entryToTraceEvents( export function getTraceMetadata( startDate?: Date, metadata?: Record, -) { +): TraceMetadata { return { source: 'DevTools', startTime: startDate?.toISOString() ?? new Date().toISOString(), @@ -302,121 +299,15 @@ export function getTraceMetadata( * @param opt - Trace file configuration * @returns TraceEventContainer with events and metadata */ -export const getTraceFile = (opt: { +export const createTraceFile = (opt: { traceEvents: TraceEvent[]; startTime?: string; metadata?: Partial; }): TraceEventContainer => ({ - traceEvents: opt.traceEvents, + traceEvents: opt.traceEvents.map(encodeEvent), displayTimeUnit: 'ms', metadata: getTraceMetadata( opt.startTime ? new Date(opt.startTime) : new Date(), opt.metadata, ), }); - -/** - * Processes the detail property of an object using a custom processor function. - * @template T - Object type that may contain a detail property - * @param target - Object containing the detail property to process - * @param processor - Function to transform the detail value - * @returns New object with processed detail property, or original object if no detail - */ -function processDetail( - target: T, - processor: (detail: string | object) => string | object, -): T { - if ( - target.detail != null && - (typeof target.detail === 'string' || typeof target.detail === 'object') - ) { - return { ...target, detail: processor(target.detail) }; - } - return target; -} - -/** - * Decodes a JSON string detail property back to its original object form. - * @param target - Object containing a detail property as a JSON string - * @returns UserTimingDetail with the detail property parsed from JSON - */ -export function decodeDetail(target: { detail: string }): UserTimingDetail { - return processDetail(target, detail => - typeof detail === 'string' - ? (JSON.parse(detail) as string | object) - : detail, - ) as UserTimingDetail; -} - -/** - * Encodes object detail properties to JSON strings for storage/transmission. - * @param target - UserTimingDetail object with detail property to encode - * @returns UserTimingDetail with object details converted to JSON strings - */ -export function encodeDetail(target: UserTimingDetail): UserTimingDetail { - return processDetail( - target as UserTimingDetail & { detail?: unknown }, - (detail: string | object) => - typeof detail === 'object' - ? JSON.stringify(detail as UserTimingDetail) - : detail, - ) as UserTimingDetail; -} - -/** - * Decodes a raw trace event with JSON string details back to typed UserTimingTraceEvent. - * Parses detail properties from JSON strings to objects. - * @param event - Raw trace event with string-encoded details - * @returns UserTimingTraceEvent with parsed detail objects - */ -export function decodeTraceEvent({ - args, - ...rest -}: TraceEventRaw): UserTimingTraceEvent { - if (!args) { - return rest as UserTimingTraceEvent; - } - - const processedArgs = decodeDetail(args as { detail: string }); - if ('data' in args && args.data && typeof args.data === 'object') { - // eslint-disable-next-line @typescript-eslint/consistent-type-assertions - return { - ...rest, - args: { - ...processedArgs, - data: decodeDetail(args.data as { detail: string }), - }, - } as UserTimingTraceEvent; - } - // eslint-disable-next-line @typescript-eslint/consistent-type-assertions - return { ...rest, args: processedArgs } as UserTimingTraceEvent; -} - -/** - * Encodes a UserTimingTraceEvent to raw format with JSON string details. - * Converts object details to JSON strings for storage/transmission. - * @param event - UserTimingTraceEvent with object details - * @returns TraceEventRaw with string-encoded details - */ -export function encodeTraceEvent({ - args, - ...rest -}: UserTimingTraceEvent): TraceEventRaw { - if (!args) { - return rest as TraceEventRaw; - } - - const processedArgs = encodeDetail(args as UserTimingDetail); - if ('data' in args && args.data && typeof args.data === 'object') { - const result: TraceEventRaw = { - ...rest, - args: { - ...processedArgs, - data: encodeDetail(args.data as UserTimingDetail), - }, - }; - return result; - } - const result: TraceEventRaw = { ...rest, args: processedArgs }; - return result; -} diff --git a/packages/utils/src/lib/profiler/trace-file-utils.unit.test.ts b/packages/utils/src/lib/profiler/trace-file-utils.unit.test.ts index aa21887af..e30fdb7a0 100644 --- a/packages/utils/src/lib/profiler/trace-file-utils.unit.test.ts +++ b/packages/utils/src/lib/profiler/trace-file-utils.unit.test.ts @@ -1,27 +1,24 @@ import type { PerformanceMark, PerformanceMeasure } from 'node:perf_hooks'; import { - decodeDetail, - decodeTraceEvent, - encodeDetail, - encodeTraceEvent, + complete, + createTraceFile, + decodeEvent, + deserializeTraceEvent, + encodeEvent, entryToTraceEvents, - frameName, - frameTreeNodeId, - getCompleteEvent, - getInstantEvent, getInstantEventTracingStartedInBrowser, - getSpan, - getSpanEvent, - getTraceFile, getTraceMetadata, + instant, markToInstantEvent, measureToSpanEvents, nextId2, + serializeTraceEvent, + span, } from './trace-file-utils.js'; describe('getTraceFile', () => { it('should create trace file with empty events array', () => { - expect(getTraceFile({ traceEvents: [] })).toStrictEqual({ + expect(createTraceFile({ traceEvents: [] })).toStrictEqual({ traceEvents: [], displayTimeUnit: 'ms', metadata: { @@ -35,11 +32,9 @@ describe('getTraceFile', () => { it('should create trace file with events', () => { expect( - getTraceFile({ + createTraceFile({ traceEvents: [ - getInstantEvent({ - name: 'test-event', - ts: 1_234_567_890, + instant('test-event', 1_234_567_890, { pid: 123, tid: 456, }), @@ -65,7 +60,7 @@ describe('getTraceFile', () => { }); it('should use custom startTime when provided', () => { - const result = getTraceFile({ + const result = createTraceFile({ traceEvents: [], startTime: '2023-01-01T00:00:00.000Z', }); @@ -79,7 +74,7 @@ describe('getTraceFile', () => { }); it('should include hardware concurrency', () => { - expect(getTraceFile({ traceEvents: [] })).toHaveProperty( + expect(createTraceFile({ traceEvents: [] })).toHaveProperty( 'metadata', expect.objectContaining({ hardwareConcurrency: expect.any(Number), @@ -88,33 +83,13 @@ describe('getTraceFile', () => { }); }); -describe('frameTreeNodeId', () => { - it.each([ - [123, 456, 1_230_456], - [1, 2, 102], - [999, 999, 9_990_999], - ])('should generate correct frame tree node ID', (pid, tid, expected) => { - expect(frameTreeNodeId(pid, tid)).toBe(expected); - }); -}); - -describe('frameName', () => { - it.each([ - [123, 456], - [1, 2], - [999, 999], - ])('should generate correct frame name', (pid, tid) => { - expect(frameName(pid, tid)).toBe(`FRAME0P${pid}T${tid}`); - }); -}); - describe('getInstantEventTracingStartedInBrowser', () => { it('should create start tracing event with required url', () => { expect( getInstantEventTracingStartedInBrowser({ url: 'https://example.com' }), ).toStrictEqual({ cat: 'devtools.timeline', - ph: 'i', + ph: 'I', name: 'TracingStartedInBrowser', pid: expect.any(Number), tid: expect.any(Number), @@ -147,7 +122,7 @@ describe('getInstantEventTracingStartedInBrowser', () => { }), ).toStrictEqual({ cat: 'devtools.timeline', - ph: 'i', + ph: 'I', name: 'TracingStartedInBrowser', pid: 777, tid: 888, @@ -172,14 +147,9 @@ describe('getInstantEventTracingStartedInBrowser', () => { }); }); -describe('getCompleteEvent', () => { +describe('complete', () => { it('should create complete event with required fields', () => { - expect( - getCompleteEvent({ - name: 'test-complete', - dur: 1000, - }), - ).toStrictEqual({ + expect(complete('test-complete', 1000)).toStrictEqual({ cat: 'devtools.timeline', ph: 'X', name: 'test-complete', @@ -193,9 +163,7 @@ describe('getCompleteEvent', () => { it('should use custom pid, tid, and ts', () => { expect( - getCompleteEvent({ - name: 'custom-complete', - dur: 500, + complete('custom-complete', 500, { pid: 111, tid: 222, ts: 1_234_567_890, @@ -223,12 +191,12 @@ describe('markToInstantEvent', () => { } as PerformanceMark), ).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-mark', pid: expect.any(Number), tid: expect.any(Number), ts: expect.any(Number), - args: { detail: { customData: 'test' } }, + args: { data: { detail: { customData: 'test' } } }, }); }); @@ -241,7 +209,7 @@ describe('markToInstantEvent', () => { } as PerformanceMark), ).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-mark', pid: expect.any(Number), tid: expect.any(Number), @@ -266,12 +234,12 @@ describe('markToInstantEvent', () => { ), ).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'custom-name', pid: 999, tid: 888, ts: expect.any(Number), - args: { detail: { customData: 'test' } }, + args: { data: { detail: { customData: 'test' } } }, }); }); }); @@ -294,7 +262,7 @@ describe('measureToSpanEvents', () => { tid: expect.any(Number), ts: expect.any(Number), id2: { local: expect.stringMatching(/^0x\d+$/) }, - args: { data: { detail: { measurement: 'data' } } }, + args: { detail: { measurement: 'data' } }, }, { cat: 'blink.user_timing', @@ -304,7 +272,7 @@ describe('measureToSpanEvents', () => { tid: expect.any(Number), ts: expect.any(Number), id2: { local: expect.stringMatching(/^0x\d+$/) }, - args: { data: { detail: { measurement: 'data' } } }, + args: { detail: { measurement: 'data' } }, }, ]); }); @@ -361,63 +329,21 @@ describe('measureToSpanEvents', () => { name: 'custom-measure', pid: 777, tid: 666, - args: { data: { detail: { measurement: 'data' } } }, + args: { detail: { measurement: 'data' } }, }), expect.objectContaining({ name: 'custom-measure', pid: 777, tid: 666, - args: { data: { detail: { measurement: 'data' } } }, + args: { detail: { measurement: 'data' } }, }), ]); }); }); -describe('getSpanEvent', () => { - it('should create begin event with args detail', () => { - expect( - getSpanEvent('b', { - name: 'test-span', - id2: { local: '0x1' }, - args: { data: { detail: { customData: 'test' } as any } }, - }), - ).toStrictEqual({ - cat: 'blink.user_timing', - ph: 'b', - name: 'test-span', - pid: expect.any(Number), - tid: expect.any(Number), - ts: expect.any(Number), - id2: { local: '0x1' }, - args: { data: { detail: { customData: 'test' } } }, - }); - }); - - it('should create end event without args detail', () => { - expect( - getSpanEvent('e', { - name: 'test-span', - id2: { local: '0x2' }, - }), - ).toStrictEqual({ - cat: 'blink.user_timing', - ph: 'e', - name: 'test-span', - pid: expect.any(Number), - tid: expect.any(Number), - ts: expect.any(Number), - id2: { local: '0x2' }, - args: {}, - }); - }); -}); - -describe('getSpan', () => { +describe('span', () => { it('should create span events with custom tsMarkerPadding', () => { - const result = getSpan({ - name: 'test-span', - tsB: 1000, - tsE: 1500, + const result = span('test-span', 1000, 1500, { tsMarkerPadding: 5, args: {}, }); @@ -447,23 +373,16 @@ describe('getSpan', () => { }); it('should generate id2 when not provided', () => { - const result = getSpan({ - name: 'test-span', - tsB: 1000, - tsE: 1500, - }); + const result = span('test-span', 1000, 1500); expect(result).toHaveLength(2); - expect(result[0].id2?.local).toMatch(/^0x\d+$/); - expect(result[1].id2).toEqual(result[0].id2); + expect(result.at(0)?.id2?.local).toMatch(/^0x\d+$/); + expect(result.at(1)?.id2).toEqual(result.at(0)?.id2); }); it('should use provided id2', () => { expect( - getSpan({ - name: 'test-span', - tsB: 1000, - tsE: 1500, + span('test-span', 1000, 1500, { id2: { local: 'custom-id' }, }), ).toStrictEqual([ @@ -529,12 +448,12 @@ describe('entryToTraceEvents', () => { expect(result).toHaveLength(1); expect(result[0]).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-mark', pid: expect.any(Number), tid: expect.any(Number), ts: expect.any(Number), - args: { detail: { customData: 'test' } }, + args: { data: { detail: { customData: 'test' } } }, }); }); @@ -559,7 +478,7 @@ describe('entryToTraceEvents', () => { tid: expect.any(Number), ts: expect.any(Number), id2: { local: expect.stringMatching(/^0x\d+$/) }, - args: { data: { detail: { measurement: 'data' } } }, + args: { detail: { measurement: 'data' } }, }); expect(result[1]).toStrictEqual({ cat: 'blink.user_timing', @@ -569,7 +488,7 @@ describe('entryToTraceEvents', () => { tid: expect.any(Number), ts: expect.any(Number), id2: { local: expect.stringMatching(/^0x\d+$/) }, - args: { data: { detail: { measurement: 'data' } } }, + args: { detail: { measurement: 'data' } }, }); }); @@ -621,116 +540,134 @@ describe('getTraceMetadata', () => { }); }); -describe('decodeDetail', () => { - it('should decode string detail back to object', () => { - const input = { detail: '{"key": "value"}' }; - const result = decodeDetail(input); +describe('decodeEvent', () => { + it('should decode trace event with string details', () => { + const encodedEvent = { + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + args: { + detail: '{"custom": "data"}', + data: { detail: '{"nested": "value"}' }, + }, + }; + + const result = decodeEvent(encodedEvent); expect(result).toStrictEqual({ - detail: { key: 'value' }, + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + args: { + detail: { custom: 'data' }, + data: { detail: { nested: 'value' } }, + }, }); }); - it('should return object detail unchanged', () => { - const input = { detail: { key: 'value' } }; - const result = decodeDetail(input); - - expect(result).toStrictEqual(input); - }); - - it('should return input unchanged when detail is not string or object', () => { - const input = { detail: 123 }; - const result = decodeDetail(input as any); - - expect(result).toStrictEqual(input); - }); - - it('should return input unchanged when no detail property', () => { - const input = { other: 'value' }; - const result = decodeDetail(input as any); - - expect(result).toStrictEqual(input); - }); -}); + it('should handle trace event without args', () => { + const encodedEvent = { + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + }; -describe('encodeDetail', () => { - it('should encode object detail to JSON string', () => { - const input = { detail: { key: 'value' } }; - const result = encodeDetail(input); + const result = decodeEvent(encodedEvent); expect(result).toStrictEqual({ - detail: '{"key":"value"}', + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, }); }); - it('should return string detail unchanged', () => { - const input = { detail: 'already a string' }; - const result = encodeDetail(input); - - expect(result).toStrictEqual(input); - }); - - it('should return input unchanged when detail is not string or object', () => { - const input = { detail: 123 }; - const result = encodeDetail(input as any); - - expect(result).toStrictEqual(input); - }); + it('should handle args without data property', () => { + const encodedEvent = { + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + args: { + detail: '{"custom": "data"}', + }, + }; - it('should return input unchanged when no detail property', () => { - const input = { other: 'value' }; - const result = encodeDetail(input as any); + const result = decodeEvent(encodedEvent); - expect(result).toStrictEqual(input); + expect(result).toStrictEqual({ + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + args: { + detail: { custom: 'data' }, + }, + }); }); }); -describe('decodeTraceEvent', () => { - it('should decode trace event with string details', () => { - const rawEvent = { - cat: 'blink.user_timing' as const, - ph: 'i' as const, +describe('encodeEvent', () => { + it('should encode trace event with object details', () => { + const event = { + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { - detail: '{"custom": "data"}', - data: { detail: '{"nested": "value"}' }, + detail: { custom: 'data' }, + data: { detail: { nested: 'value' } }, }, }; - const result = decodeTraceEvent(rawEvent); + const result = encodeEvent(event); expect(result).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { - detail: { custom: 'data' }, - data: { detail: { nested: 'value' } }, + detail: '{"custom":"data"}', + data: { detail: '{"nested":"value"}' }, }, }); }); it('should handle trace event without args', () => { - const rawEvent = { - cat: 'blink.user_timing' as const, - ph: 'i' as const, + const event = { + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, }; - const result = decodeTraceEvent(rawEvent); + const result = encodeEvent(event); expect(result).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-event', pid: 123, tid: 456, @@ -739,80 +676,82 @@ describe('decodeTraceEvent', () => { }); it('should handle args without data property', () => { - const rawEvent = { - cat: 'blink.user_timing' as const, - ph: 'i' as const, + const event = { + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { - detail: '{"custom": "data"}', + detail: { custom: 'data' }, }, }; - const result = decodeTraceEvent(rawEvent); + const result = encodeEvent(event); expect(result).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { - detail: { custom: 'data' }, + detail: '{"custom":"data"}', }, }); }); }); -describe('encodeTraceEvent', () => { - it('should encode trace event with object details', () => { +describe('serializeTraceEvent', () => { + it('should serialize trace event to JSON string', () => { const event = { - cat: 'blink.user_timing' as const, - ph: 'i' as const, + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { detail: { custom: 'data' }, - data: { detail: { nested: 'value' } }, }, }; - const result = encodeTraceEvent(event); + const result = serializeTraceEvent(event); - expect(result).toStrictEqual({ + expect(result).toBeString(); + const parsed = JSON.parse(result); + expect(parsed).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { detail: '{"custom":"data"}', - data: { detail: '{"nested":"value"}' }, }, }); }); it('should handle trace event without args', () => { const event = { - cat: 'blink.user_timing' as const, - ph: 'i' as const, + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, }; - const result = encodeTraceEvent(event); + const result = serializeTraceEvent(event); - expect(result).toStrictEqual({ + expect(typeof result).toBe('string'); + const parsed = JSON.parse(result); + expect(parsed).toStrictEqual({ cat: 'blink.user_timing', - ph: 'i', + ph: 'I', name: 'test-event', pid: 123, tid: 456, @@ -820,31 +759,108 @@ describe('encodeTraceEvent', () => { }); }); - it('should handle args without data property', () => { + it('should handle nested object details in args', () => { const event = { - cat: 'blink.user_timing' as const, - ph: 'i' as const, + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { detail: { custom: 'data' }, + data: { detail: { nested: 'value' } }, }, }; - const result = encodeTraceEvent(event); + const result = serializeTraceEvent(event); - expect(result).toStrictEqual({ + expect(typeof result).toBe('string'); + const parsed = JSON.parse(result); + expect(parsed.args).toStrictEqual({ + detail: '{"custom":"data"}', + data: { detail: '{"nested":"value"}' }, + }); + }); +}); + +describe('deserializeTraceEvent', () => { + it('should deserialize JSON string back to trace event', () => { + const originalEvent = { cat: 'blink.user_timing', - ph: 'i', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + args: { + detail: { custom: 'data' }, + }, + }; + + const serialized = serializeTraceEvent(originalEvent); + const deserialized = deserializeTraceEvent(serialized); + + expect(deserialized).toStrictEqual(originalEvent); + }); + + it('should handle round-trip serialization', () => { + const originalEvent = { + cat: 'blink.user_timing', + ph: 'I', + name: 'round-trip-test', + pid: 789, + tid: 101, + ts: 987_654_321, + args: { + detail: { custom: 'data', nested: { value: 42 } }, + data: { detail: { nested: 'value' } }, + }, + }; + + const serialized = serializeTraceEvent(originalEvent); + const deserialized = deserializeTraceEvent(serialized); + const reSerialized = serializeTraceEvent(deserialized); + const reDeserialized = deserializeTraceEvent(reSerialized); + + expect(reDeserialized).toStrictEqual(originalEvent); + }); + + it('should handle trace event without args', () => { + const originalEvent = { + cat: 'blink.user_timing', + ph: 'I', + name: 'test-event', + pid: 123, + tid: 456, + ts: 1000, + }; + + const serialized = serializeTraceEvent(originalEvent); + const deserialized = deserializeTraceEvent(serialized); + + expect(deserialized).toStrictEqual(originalEvent); + }); + + it('should decode string-encoded details back to objects', () => { + const jsonString = JSON.stringify({ + cat: 'blink.user_timing', + ph: 'I', name: 'test-event', pid: 123, tid: 456, ts: 1000, args: { detail: '{"custom":"data"}', + data: { detail: '{"nested":"value"}' }, }, }); + + const deserialized = deserializeTraceEvent(jsonString); + + expect(deserialized.args).toStrictEqual({ + detail: { custom: 'data' }, + data: { detail: { nested: 'value' } }, + }); }); }); diff --git a/packages/utils/src/lib/profiler/trace-file.type.ts b/packages/utils/src/lib/profiler/trace-file.type.ts index 839c06884..669173de1 100644 --- a/packages/utils/src/lib/profiler/trace-file.type.ts +++ b/packages/utils/src/lib/profiler/trace-file.type.ts @@ -1,169 +1,31 @@ -import type { UserTimingDetail } from '../user-timing-extensibility-api.type.js'; +import type { + MarkerPayload, + TrackEntryPayload, +} from '../user-timing-extensibility-api.type.js'; -/** - * Arguments for instant trace events. - * @property {UserTimingDetail} [detail] - Optional user timing detail with DevTools payload - */ -export type InstantEventArgs = { - detail?: UserTimingDetail; -} & { [key: string]: unknown }; - -/** - * Arguments for span trace events (begin/end events). - * @property {object} [data] - Optional data object - * @property {UserTimingDetail} [data.detail] - Optional user timing detail with DevTools payload - */ -export type SpanEventArgs = { - data?: { detail?: UserTimingDetail }; -} & { [key: string]: unknown }; - -/** - * Arguments for complete trace events. - * @property {Record} [detail] - Optional detail object with arbitrary properties - */ -export type CompleteEventArgs = { detail?: Record }; - -/** - * Arguments for start tracing events. - * @property {object} data - Tracing initialization data - * @property {number} data.frameTreeNodeId - Frame tree node identifier - * @property {Array} data.frames - Array of frame information - * @property {boolean} data.persistentIds - Whether IDs are persistent - */ -export type InstantEventTracingStartedInBrowserArgs = { - data: { - frameTreeNodeId: number; - frames: { - frame: string; - isInPrimaryMainFrame: boolean; - isOutermostMainFrame: boolean; - name: string; - processId: number; - url: string; - }[]; - persistentIds: boolean; - }; -}; - -/** - * Union type of all possible trace event arguments. - */ -export type TraceArgs = - | InstantEventArgs - | SpanEventArgs - | CompleteEventArgs - | InstantEventTracingStartedInBrowserArgs; +/** DevTools payload type for trace events. */ +export type DevToolsPayload = TrackEntryPayload | MarkerPayload; /** - * Base properties shared by all trace events. - * @property {string} cat - Event category - * @property {string} name - Event name - * @property {number} pid - Process ID - * @property {number} tid - Thread ID - * @property {number} ts - Timestamp in epoch microseconds - * @property {TraceArgs} [args] - Optional event arguments + * Unified trace event type for Chrome DevTools trace format. */ -export type BaseTraceEvent = { +export type TraceEvent = { cat: string; + ph: string; name: string; pid: number; tid: number; ts: number; - args: TraceArgs; -}; - -/** - * Start tracing event for Chrome DevTools tracing. - */ -export type InstantEventTracingStartedInBrowser = BaseTraceEvent & { - cat: 'devtools.timeline'; - ph: 'i'; - name: 'TracingStartedInBrowser'; - args: InstantEventTracingStartedInBrowserArgs; -}; - -/** - * Complete trace event with duration. - * Represents a complete operation with start time and duration. - * @property {'X'} ph - Phase indicator for complete events - * @property {number} dur - Duration in microseconds - */ -export type CompleteEvent = BaseTraceEvent & { ph: 'X'; dur: number }; - -/** - * Instant trace event representing a single point in time. - * Used for user timing marks and other instantaneous events. - * @property {'blink.user_timing'} cat - Fixed category for user timing events - * @property {'i'} ph - Phase indicator for instant events - * @property {never} [dur] - Duration is not applicable for instant events - * @property {InstantEventArgs} [args] - Optional event arguments - */ -export type InstantEvent = Omit & { - cat: 'blink.user_timing'; - ph: 'i'; - dur?: never; - args: InstantEventArgs; -}; - -/** - * Core properties for span trace events (begin/end pairs). - * @property {object} id2 - Span identifier - * @property {string} id2.local - Local span ID (unique to the process, same for b and e events) - * @property {SpanEventArgs} [args] - Optional event arguments - */ -type SpanCore = Omit & { - id2: { local: string }; - args: SpanEventArgs; -}; -/** - * Begin event for a span (paired with an end event). - * @property {'b'} ph - Phase indicator for begin events - * @property {never} [dur] - Duration is not applicable for begin events - */ -export type BeginEvent = SpanCore & { - ph: 'b'; - dur?: never; + dur?: number; + id2?: { local: string }; + args?: { + detail?: unknown; + data?: { detail?: unknown; [key: string]: unknown }; + devtools?: DevToolsPayload; + [key: string]: unknown; + }; }; -/** - * End event for a span (paired with a begin event). - * @property {'e'} ph - Phase indicator for end events - * @property {never} [dur] - Duration is not applicable for end events - */ -export type EndEvent = SpanCore & { ph: 'e'; dur?: never }; - -/** - * Union type for span events (begin or end). - */ -export type SpanEvent = BeginEvent | EndEvent; - -/** - * Union type of all trace event types. - */ -export type UserTimingTraceEvent = InstantEvent | SpanEvent; - -/** - * All trace events including system events added during finalization. - */ -export type TraceEvent = - | UserTimingTraceEvent - | CompleteEvent - | InstantEventTracingStartedInBrowser; - -/** - * Raw arguments format for trace events before processing. - * Either contains a detail string directly or nested in a data object. - */ -type RawArgs = - | { detail?: string; [key: string]: unknown } - | { data?: { detail?: string }; [key: string]: unknown }; - -/** - * Raw trace event format before type conversion. - * Similar to TraceEvent but with unprocessed arguments. - */ -export type TraceEventRaw = Omit & { args: RawArgs }; - /** * Time window bounds (min, max) in trace time units (e.g. microseconds). * @property {number} min - Minimum timestamp in the window @@ -293,4 +155,12 @@ export type TraceEventContainer = { /** * Trace file format - either an array of events or a structured container. */ -export type TraceFile = TraceEvent[] | TraceEventContainer; +export type TraceFile = TraceEventContainer; + +/** Options for creating a tracing started in browser event. */ +export type TracingStartedInBrowserOptions = { + url: string; + ts?: number; + pid?: number; + tid?: number; +}; diff --git a/packages/utils/src/lib/profiler/wal-json-trace.ts b/packages/utils/src/lib/profiler/wal-json-trace.ts index fcdfec4b1..4104d5744 100644 --- a/packages/utils/src/lib/profiler/wal-json-trace.ts +++ b/packages/utils/src/lib/profiler/wal-json-trace.ts @@ -1,13 +1,15 @@ import { defaultClock } from '../clock-epoch.js'; import type { InvalidEntry, WalFormat } from '../wal.js'; +import { PROFILER_PERSIST_BASENAME } from './constants.js'; import { - decodeTraceEvent, - encodeTraceEvent, - getCompleteEvent, + complete, + createTraceFile, + deserializeTraceEvent, + encodeEvent, getInstantEventTracingStartedInBrowser, - getTraceFile, + serializeTraceEvent, } from './trace-file-utils.js'; -import type { TraceEvent, UserTimingTraceEvent } from './trace-file.type.js'; +import type { TraceEvent } from './trace-file.type.js'; /** Name for the trace start margin event */ const TRACE_START_MARGIN_NAME = '[trace padding start]'; @@ -18,18 +20,11 @@ const TRACE_MARGIN_US = 1_000_000; /** Duration in microseconds for margin events (20ms = 20,000μs) */ const TRACE_MARGIN_DURATION_US = 20_000; -/** - * Generates a complete Chrome DevTools trace file content as JSON string. - * Adds margin events around the trace events and includes metadata. - * @param events - Array of user timing trace events to include - * @param metadata - Optional custom metadata to include in the trace file - * @returns JSON string representation of the complete trace file - */ export function generateTraceContent( - events: UserTimingTraceEvent[], + events: TraceEvent[], metadata?: Record, ): string { - const traceContainer = getTraceFile({ + const traceContainer = createTraceFile({ traceEvents: events, startTime: new Date().toISOString(), metadata: { @@ -38,66 +33,58 @@ export function generateTraceContent( }, }); - const marginUs = TRACE_MARGIN_US; - const marginDurUs = TRACE_MARGIN_DURATION_US; - - const sortedEvents = [...events].sort((a, b) => a.ts - b.ts); const fallbackTs = defaultClock.epochNowUs(); - const firstTs: number = sortedEvents.at(0)?.ts ?? fallbackTs; - const lastTs: number = sortedEvents.at(-1)?.ts ?? fallbackTs; + const sortedEvents = + events.length > 0 ? [...events].sort((a, b) => a.ts - b.ts) : []; - const startTs = firstTs - marginUs; - const endTs = lastTs + marginUs; + const firstTs = sortedEvents.at(0)?.ts ?? fallbackTs; + const lastTs = sortedEvents.at(-1)?.ts ?? fallbackTs; - const traceEvents: TraceEvent[] = [ - getInstantEventTracingStartedInBrowser({ - ts: startTs, - url: events.length === 0 ? 'empty-trace' : 'generated-trace', - }), - getCompleteEvent({ - name: TRACE_START_MARGIN_NAME, - ts: startTs, - dur: marginDurUs, - }), - ...sortedEvents, - getCompleteEvent({ - name: TRACE_END_MARGIN_NAME, - ts: endTs, - dur: marginDurUs, - }), - ]; - - return JSON.stringify({ ...traceContainer, traceEvents }); + return JSON.stringify({ + ...traceContainer, + traceEvents: [ + getInstantEventTracingStartedInBrowser({ + ts: firstTs - TRACE_MARGIN_US, + url: events.length > 0 ? 'generated-trace' : 'empty-trace', + }), + complete(TRACE_START_MARGIN_NAME, TRACE_MARGIN_DURATION_US, { + ts: firstTs - TRACE_MARGIN_US, + }), + ...sortedEvents.map(encodeEvent), + complete(TRACE_END_MARGIN_NAME, TRACE_MARGIN_DURATION_US, { + ts: lastTs + TRACE_MARGIN_US, + }), + ], + }); } +/** + * Codec for encoding and decoding trace events. + * Encodes nested objects in args.detail and args.data.detail to JSON strings for storage. + */ +export const traceEventCodec = { + encode: serializeTraceEvent, + decode: deserializeTraceEvent, +}; + /** * Creates a WAL (Write-Ahead Logging) format configuration for Chrome DevTools trace files. * Automatically finalizes shards into complete trace files with proper metadata and margin events. * @returns WalFormat configuration object with baseName, codec, extensions, and finalizer */ export function traceEventWalFormat() { - const baseName = 'trace'; - const walExtension = '.jsonl'; - const finalExtension = '.json'; return { - baseName, - walExtension, - finalExtension, - codec: { - encode: (event: UserTimingTraceEvent) => - JSON.stringify(encodeTraceEvent(event)), - decode: (json: string) => - decodeTraceEvent(JSON.parse(json)) as UserTimingTraceEvent, - }, + baseName: PROFILER_PERSIST_BASENAME, + walExtension: '.jsonl', + finalExtension: '.json', + codec: traceEventCodec, finalizer: ( - records: (UserTimingTraceEvent | InvalidEntry)[], + records: (TraceEvent | InvalidEntry)[], metadata?: Record, - ) => { - const validRecords = records.filter( - (r): r is UserTimingTraceEvent => - !(typeof r === 'object' && r != null && '__invalid' in r), - ); - return generateTraceContent(validRecords, metadata); - }, - } satisfies WalFormat; + ) => + generateTraceContent( + records.filter((r): r is TraceEvent => !('__invalid' in (r as object))), + metadata, + ), + } satisfies WalFormat; } diff --git a/packages/utils/src/lib/profiler/wal-json-trace.unit.test.ts b/packages/utils/src/lib/profiler/wal-json-trace.unit.test.ts index 3f40293ec..64f6def5b 100644 --- a/packages/utils/src/lib/profiler/wal-json-trace.unit.test.ts +++ b/packages/utils/src/lib/profiler/wal-json-trace.unit.test.ts @@ -1,9 +1,226 @@ -import type { UserTimingTraceEvent } from './trace-file.type.js'; -import { generateTraceContent, traceEventWalFormat } from './wal-json-trace.js'; +import type { TraceEvent } from './trace-file.type.js'; +import { + generateTraceContent, + traceEventCodec, + traceEventWalFormat, +} from './wal-json-trace.js'; + +describe('traceEventCodec', () => { + // Memory representation: TraceEvent objects with nested objects in args.detail and args.data.detail + // This is the format we process and hold in memory + const instantEvent: TraceEvent = { + name: 'cp:test-event', + ph: 'I', + ts: 123_456_789, + pid: 123, + tid: 456, + cat: 'blink.user_timing', + args: { + detail: { + custom: 'data', + }, + data: { + detail: { + nested: 'value', + }, + }, + devtools: { + dataType: 'track-entry', + track: 'test-track', + color: 'primary', + tooltipText: 'Test event tooltip', + }, + }, + } satisfies TraceEvent; + + const spanBeginEvent: TraceEvent = { + name: 'cp:test-span', + ph: 'b', + ts: 200_000_000, + pid: 123, + tid: 456, + cat: 'blink.user_timing', + id2: { local: '0x1' }, + args: { + devtools: { + dataType: 'track-entry', + track: 'span-track', + color: 'secondary', + tooltipText: 'Test span begin', + }, + }, + } satisfies TraceEvent; + + const spanEndEvent: TraceEvent = { + name: 'cp:test-span', + ph: 'e', + ts: 250_000_000, + pid: 123, + tid: 456, + cat: 'blink.user_timing', + id2: { local: '0x1' }, + args: { + devtools: { + dataType: 'track-entry', + track: 'span-track', + color: 'secondary', + tooltipText: 'Test span end', + }, + }, + } satisfies TraceEvent; + + // Encoded JSON string representation: nested objects in args.detail and args.data.detail are JSON strings + // This is the format stored in WAL files (.jsonl) + const instantEventJsonString = JSON.stringify({ + name: 'cp:test-event', + ph: 'I', + ts: 123_456_789, + pid: 123, + tid: 456, + cat: 'blink.user_timing', + args: { + detail: JSON.stringify({ custom: 'data' }), + data: { + detail: JSON.stringify({ nested: 'value' }), + }, + devtools: { + dataType: 'track-entry', + track: 'test-track', + color: 'primary', + tooltipText: 'Test event tooltip', + }, + }, + }); + + const spanBeginEventJsonString = JSON.stringify({ + name: 'cp:test-span', + ph: 'b', + ts: 200_000_000, + pid: 123, + tid: 456, + cat: 'blink.user_timing', + id2: { local: '0x1' }, + args: { + devtools: { + dataType: 'track-entry', + track: 'span-track', + color: 'secondary', + tooltipText: 'Test span begin', + }, + }, + }); + + const spanEndEventJsonString = JSON.stringify({ + name: 'cp:test-span', + ph: 'e', + ts: 250_000_000, + pid: 123, + tid: 456, + cat: 'blink.user_timing', + id2: { local: '0x1' }, + args: { + devtools: { + dataType: 'track-entry', + track: 'span-track', + color: 'secondary', + tooltipText: 'Test span end', + }, + }, + }); + + describe('decode direction (JSON string → memory object)', () => { + it('should decode instant event from JSON string', () => { + const decoded = traceEventCodec.decode(instantEventJsonString); + expect(decoded).toStrictEqual(instantEvent); + }); + + it('should decode span begin event from JSON string', () => { + const decoded = traceEventCodec.decode(spanBeginEventJsonString); + expect(decoded).toStrictEqual(spanBeginEvent); + }); + + it('should decode span end event from JSON string', () => { + const decoded = traceEventCodec.decode(spanEndEventJsonString); + expect(decoded).toStrictEqual(spanEndEvent); + }); + + it('should decode events with nested detail objects correctly', () => { + const decoded = traceEventCodec.decode(instantEventJsonString); + expect(decoded.args?.detail).toStrictEqual({ custom: 'data' }); + expect(decoded.args?.data?.detail).toStrictEqual({ nested: 'value' }); + }); + }); + + describe('encode direction (memory object → JSON string)', () => { + it('should encode instant event to JSON string', () => { + const encoded = traceEventCodec.encode(instantEvent); + expect(typeof encoded).toBe('string'); + const parsed = JSON.parse(encoded); + expect(parsed.args.detail).toBe(JSON.stringify({ custom: 'data' })); + expect(parsed.args.data.detail).toBe(JSON.stringify({ nested: 'value' })); + }); + + it('should encode span begin event to JSON string', () => { + const encoded = traceEventCodec.encode(spanBeginEvent); + expect(typeof encoded).toBe('string'); + const decoded = traceEventCodec.decode(encoded); + expect(decoded).toStrictEqual(spanBeginEvent); + }); + + it('should encode span end event to JSON string', () => { + const encoded = traceEventCodec.encode(spanEndEvent); + expect(typeof encoded).toBe('string'); + const decoded = traceEventCodec.decode(encoded); + expect(decoded).toStrictEqual(spanEndEvent); + }); + + it('should encode nested detail objects as JSON strings', () => { + const encoded = traceEventCodec.encode(instantEvent); + const parsed = JSON.parse(encoded); + expect(typeof parsed.args.detail).toBe('string'); + expect(typeof parsed.args.data.detail).toBe('string'); + expect(JSON.parse(parsed.args.detail)).toStrictEqual({ custom: 'data' }); + expect(JSON.parse(parsed.args.data.detail)).toStrictEqual({ + nested: 'value', + }); + }); + }); + + describe('round-trip (memory → string → memory)', () => { + it('should maintain consistency for instant event', () => { + const encoded = traceEventCodec.encode(instantEvent); + const decoded = traceEventCodec.decode(encoded); + expect(decoded).toStrictEqual(instantEvent); + }); + + it('should maintain consistency for span begin event', () => { + const encoded = traceEventCodec.encode(spanBeginEvent); + const decoded = traceEventCodec.decode(encoded); + expect(decoded).toStrictEqual(spanBeginEvent); + }); + + it('should maintain consistency for span end event', () => { + const encoded = traceEventCodec.encode(spanEndEvent); + const decoded = traceEventCodec.decode(encoded); + expect(decoded).toStrictEqual(spanEndEvent); + }); + + it('should handle multiple round-trips correctly', () => { + let current = instantEvent; + // eslint-disable-next-line functional/no-loop-statements + for (let i = 0; i < 3; i++) { + const encoded = traceEventCodec.encode(current); + const decoded = traceEventCodec.decode(encoded); + expect(decoded).toStrictEqual(instantEvent); + current = decoded; + } + }); + }); +}); describe('generateTraceContent', () => { it('should generate trace content for empty events array', () => { - const events: UserTimingTraceEvent[] = []; + const events: TraceEvent[] = []; const metadata = { version: '1.0.0', generatedAt: '2024-01-01T00:00:00Z' }; const result = generateTraceContent(events, metadata); @@ -13,7 +230,7 @@ describe('generateTraceContent', () => { traceEvents: [ expect.objectContaining({ name: 'TracingStartedInBrowser', - ph: 'i', + ph: 'I', cat: 'devtools.timeline', args: { data: expect.objectContaining({ @@ -51,10 +268,10 @@ describe('generateTraceContent', () => { }); it('should generate trace content for non-empty events array', () => { - const events: UserTimingTraceEvent[] = [ + const events: TraceEvent[] = [ { name: 'cp:test-operation:start', - ph: 'i', + ph: 'I', ts: 1000, pid: 123, tid: 456, @@ -67,7 +284,7 @@ describe('generateTraceContent', () => { }, { name: 'cp:test-operation:end', - ph: 'i', + ph: 'I', ts: 2000, pid: 123, tid: 456, @@ -87,7 +304,7 @@ describe('generateTraceContent', () => { traceEvents: [ expect.objectContaining({ name: 'TracingStartedInBrowser', - ph: 'i', + ph: 'I', cat: 'devtools.timeline', args: { data: expect.objectContaining({ @@ -125,10 +342,10 @@ describe('generateTraceContent', () => { }); it('should sort events by timestamp', () => { - const events: UserTimingTraceEvent[] = [ + const events: TraceEvent[] = [ { name: 'cp:second-operation', - ph: 'i', + ph: 'I', ts: 2000, pid: 123, tid: 456, @@ -137,7 +354,7 @@ describe('generateTraceContent', () => { }, { name: 'cp:first-operation', - ph: 'i', + ph: 'I', ts: 1000, pid: 123, tid: 456, @@ -158,10 +375,10 @@ describe('generateTraceContent', () => { }); it('should handle single event with proper margin calculation', () => { - const events: UserTimingTraceEvent[] = [ + const events: TraceEvent[] = [ { name: 'cp:single-event', - ph: 'i', + ph: 'I', ts: 5000, pid: 123, tid: 456, @@ -240,9 +457,9 @@ describe('traceEventWalFormat', () => { it('should encode and decode trace events correctly', () => { const format = traceEventWalFormat(); - const testEvent: UserTimingTraceEvent = { + const testEvent: TraceEvent = { name: 'cp:test-event', - ph: 'i', + ph: 'I', ts: 123_456_789, pid: 123, tid: 456, @@ -260,12 +477,38 @@ describe('traceEventWalFormat', () => { expect(decoded).toStrictEqual(testEvent); }); + it('should maintain consistency through decode -> encode -> decode round-trip', () => { + const format = traceEventWalFormat(); + const originalEvent: TraceEvent = { + name: 'cp:round-trip-test', + ph: 'I', + ts: 987_654_321, + pid: 789, + tid: 101, + cat: 'blink.user_timing', + args: { + dataType: 'track-entry', + track: 'Round Trip Track', + trackGroup: 'Test Group', + customField: 'custom value', + }, + }; + + const initialEncoded = format.codec.encode(originalEvent); + const firstDecoded = format.codec.decode(initialEncoded); + const secondEncoded = format.codec.encode(firstDecoded); + const secondDecoded = format.codec.decode(secondEncoded); + + expect(secondDecoded).toStrictEqual(firstDecoded); + expect(secondDecoded).toStrictEqual(originalEvent); + }); + it('should finalize records into trace content', () => { const format = traceEventWalFormat(); - const records: UserTimingTraceEvent[] = [ + const records: TraceEvent[] = [ { name: 'cp:operation:start', - ph: 'i', + ph: 'I', ts: 1000, pid: 123, tid: 456, @@ -285,7 +528,7 @@ describe('traceEventWalFormat', () => { it('should include generatedAt in finalizer metadata', () => { const format = traceEventWalFormat(); - const records: UserTimingTraceEvent[] = []; + const records: TraceEvent[] = []; const result = format.finalizer(records); const parsed = JSON.parse(result); 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 fedae9fa3..2eca4f3bf 100644 --- a/packages/utils/src/lib/user-timing-extensibility-api-utils.ts +++ b/packages/utils/src/lib/user-timing-extensibility-api-utils.ts @@ -332,7 +332,7 @@ export function mergeDevtoolsPayload< } export type ActionTrackConfigs = Record< T, - ActionTrackEntryPayload + Omit >; /** * Sets up tracks with default values merged into each track. diff --git a/packages/utils/src/lib/wal.ts b/packages/utils/src/lib/wal.ts index f0dc87a83..2d3cd2e09 100644 --- a/packages/utils/src/lib/wal.ts +++ b/packages/utils/src/lib/wal.ts @@ -3,6 +3,11 @@ import * as fs from 'node:fs'; import path from 'node:path'; import process from 'node:process'; import { threadId } from 'node:worker_threads'; +import { + type Counter, + getUniqueInstanceId, + getUniqueTimeId, +} from './process-id.js'; /** * Codec for encoding/decoding values to/from strings for WAL storage. @@ -372,8 +377,14 @@ export function setCoordinatorProcess( } } -// eslint-disable-next-line functional/no-let -let shardCount = 0; +/** + * Simple counter implementation for generating sequential IDs. + */ +const shardCounter: Counter = (() => { + // eslint-disable-next-line functional/no-let + let count = 0; + return { next: () => ++count }; +})(); /** * Generates a unique sharded WAL ID based on performance time origin, process ID, thread ID, and instance count. @@ -383,60 +394,6 @@ function getShardedWalId() { return `${Math.round(performance.timeOrigin)}.${process.pid}.${threadId}.${++ShardedWal.instanceCount}`; } -/** - * Generates a human-readable shard ID. - * This ID is unique per process/thread/shard combination and used in the file name. - * Format: readable-timestamp.pid.threadId.shardCount - * Example: "20240101-120000-000.12345.1.1" - * Becomes file: trace.20240101-120000-000.12345.1.1.log - */ -export function getShardId(): string { - const timestamp = Math.round(performance.timeOrigin + performance.now()); - const readableTimestamp = sortableReadableDateString(`${timestamp}`); - return `${readableTimestamp}.${process.pid}.${threadId}.${++shardCount}`; -} - -/** - * Generates a human-readable sharded group ID. - * This ID is a globally unique, sortable, human-readable date string per run. - * Used directly as the folder name to group shards. - * Format: yyyymmdd-hhmmss-ms - * Example: "20240101-120000-000" - */ -export function getShardedGroupId(): string { - return sortableReadableDateString( - `${Math.round(performance.timeOrigin + performance.now())}`, - ); -} - -/** - * Regex patterns for validating WAL ID formats - */ -export const WAL_ID_PATTERNS = { - /** Readable date format: yyyymmdd-hhmmss-ms */ - READABLE_DATE: /^\d{8}-\d{6}-\d{3}$/, - /** Group ID format: yyyymmdd-hhmmss-ms */ - GROUP_ID: /^\d{8}-\d{6}-\d{3}$/, - /** Shard ID format: readable-date.pid.threadId.count */ - SHARD_ID: /^\d{8}-\d{6}-\d{3}(?:\.\d+){3}$/, -} as const; - -export function sortableReadableDateString(timestampMs: string): string { - const timestamp = Number.parseInt(timestampMs, 10); - const date = new Date(timestamp); - const MILLISECONDS_PER_SECOND = 1000; - const yyyy = date.getFullYear(); - const mm = String(date.getMonth() + 1).padStart(2, '0'); - const dd = String(date.getDate()).padStart(2, '0'); - const hh = String(date.getHours()).padStart(2, '0'); - const min = String(date.getMinutes()).padStart(2, '0'); - const ss = String(date.getSeconds()).padStart(2, '0'); - // eslint-disable-next-line @typescript-eslint/no-magic-numbers - const ms = String(timestamp % MILLISECONDS_PER_SECOND).padStart(3, '0'); - - return `${yyyy}${mm}${dd}-${hh}${min}${ss}-${ms}`; -} - /** * Ensures a directory exists, creating it recursively if necessary using sync methods. * @param dirPath - The directory path to ensure exists @@ -491,7 +448,7 @@ export function getShardedFinalPath(opt: { export class ShardedWal { static instanceCount = 0; readonly #id: string = getShardedWalId(); - readonly groupId = getShardedGroupId(); + readonly groupId = getUniqueTimeId(); readonly #format: WalFormat; readonly #dir: string = process.cwd(); readonly #isCoordinator: boolean; @@ -511,7 +468,7 @@ export class ShardedWal { coordinatorIdEnvVar: string; }) { const { dir, format, groupId, coordinatorIdEnvVar } = opt; - this.groupId = groupId ?? getShardedGroupId(); + this.groupId = groupId ?? getUniqueTimeId(); if (dir) { this.#dir = dir; } @@ -531,7 +488,7 @@ export class ShardedWal { return this.#isCoordinator; } - shard(shardId: string = getShardId()) { + shard(shardId: string = getUniqueInstanceId(shardCounter)) { return new WriteAheadLogFile({ file: getShardedPath({ dir: this.#dir, diff --git a/packages/utils/src/lib/wal.unit.test.ts b/packages/utils/src/lib/wal.unit.test.ts index 4221d4f0f..fce1e44ba 100644 --- a/packages/utils/src/lib/wal.unit.test.ts +++ b/packages/utils/src/lib/wal.unit.test.ts @@ -1,16 +1,18 @@ import { vol } from 'memfs'; import { MEMFS_VOLUME } from '@code-pushup/test-utils'; +import { + ID_PATTERNS, + getUniqueInstanceId, + getUniqueTimeId, +} from './process-id.js'; import { SHARDED_WAL_COORDINATOR_ID_ENV_VAR } from './profiler/constants.js'; import { type Codec, type InvalidEntry, ShardedWal, - WAL_ID_PATTERNS, WriteAheadLogFile, createTolerantCodec, filterValidRecords, - getShardId, - getShardedGroupId, isCoordinatorProcess, parseWalFormat, recoverFromContent, @@ -504,17 +506,20 @@ describe('stringCodec', () => { }); }); -describe('getShardId', () => { +describe('getUniqueInstanceId', () => { it('should generate shard ID with readable timestamp', () => { - const result = getShardId(); + const counter = { next: () => 1 }; + const result = getUniqueInstanceId(counter); - expect(result).toMatch(WAL_ID_PATTERNS.SHARD_ID); + expect(result).toMatch(ID_PATTERNS.INSTANCE_ID); expect(result).toStartWith('20231114-221320-000.'); }); it('should generate different shard IDs for different calls', () => { - const result1 = getShardId(); - const result2 = getShardId(); + let count = 0; + const counter = { next: () => ++count }; + const result1 = getUniqueInstanceId(counter); + const result2 = getUniqueInstanceId(counter); expect(result1).not.toBe(result2); expect(result1).toStartWith('20231114-221320-000.'); @@ -522,25 +527,30 @@ describe('getShardId', () => { }); it('should handle zero values', () => { - const result = getShardId(); + const counter = { next: () => 1 }; + const result = getUniqueInstanceId(counter); expect(result).toStartWith('20231114-221320-000.'); }); it('should handle negative timestamps', () => { - const result = getShardId(); + const counter = { next: () => 1 }; + const result = getUniqueInstanceId(counter); expect(result).toStartWith('20231114-221320-000.'); }); it('should handle large timestamps', () => { - const result = getShardId(); + const counter = { next: () => 1 }; + const result = getUniqueInstanceId(counter); expect(result).toStartWith('20231114-221320-000.'); }); it('should generate incrementing counter', () => { - const result1 = getShardId(); - const result2 = getShardId(); + let count = 0; + const counter = { next: () => ++count }; + const result1 = getUniqueInstanceId(counter); + const result2 = getUniqueInstanceId(counter); const parts1 = result1.split('.'); const parts2 = result2.split('.'); @@ -553,17 +563,17 @@ describe('getShardId', () => { }); }); -describe('getShardedGroupId', () => { +describe('getUniqueTimeId', () => { it('should work with mocked timeOrigin', () => { - const result = getShardedGroupId(); + const result = getUniqueTimeId(); expect(result).toBe('20231114-221320-000'); - expect(result).toMatch(WAL_ID_PATTERNS.GROUP_ID); + expect(result).toMatch(ID_PATTERNS.TIME_ID); }); it('should be idempotent within same process', () => { - const result1 = getShardedGroupId(); - const result2 = getShardedGroupId(); + const result1 = getUniqueTimeId(); + const result2 = getUniqueTimeId(); expect(result1).toBe(result2); }); @@ -819,7 +829,7 @@ describe('ShardedWal', () => { }, coordinatorIdEnvVar: SHARDED_WAL_COORDINATOR_ID_ENV_VAR, }); - // Create the group directory (matches actual getShardedGroupId() output) + // Create the group directory (matches actual getUniqueTimeId() output) vol.mkdirSync('/empty/20231114-221320-000', { recursive: true }); const files = (sw as any).shardFiles(); expect(files).toEqual([]); diff --git a/testing/test-utils/src/index.ts b/testing/test-utils/src/index.ts index 38ce50155..5c4460e85 100644 --- a/testing/test-utils/src/index.ts +++ b/testing/test-utils/src/index.ts @@ -10,5 +10,5 @@ export * from './lib/utils/file-system.js'; export * from './lib/utils/create-npm-workshpace.js'; export * from './lib/utils/project-graph.js'; export * from './lib/utils/test-folder-setup.js'; -export * from './lib/utils/omit-trace-json.js'; export * from './lib/utils/profiler.mock.js'; +export * from './lib/utils/omit-trace-json.js';