Skip to content

Commit 170bab2

Browse files
committed
fix: add exit handler to profiler
1 parent 270b474 commit 170bab2

File tree

3 files changed

+300
-1
lines changed

3 files changed

+300
-1
lines changed

packages/utils/docs/profiler.md

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
# Profile
2+
3+
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.
4+
5+
## Features
6+
7+
- **Type-Safe API**: Fully typed UserTiming API for [Chrome DevTools Extensibility API](https://developer.chrome.com/docs/devtools/performance/extension)
8+
- **Measure API**: Easy-to-use methods for measuring synchronous and asynchronous code execution times.
9+
- **Custom Track Configuration**: Fully typed reusable configurations for custom track visualization.
10+
- **Process buffered entries**: Captures and processes buffered profiling entries.
11+
- **3rd Party Profiling**: Automatically processes third-party performance entries.
12+
- **Clean measure names**: Automatically adds prefixes to measure names, as well as start/end postfix to marks, for better organization.
13+
14+
## NodeJS Features
15+
16+
- **Crash-save Write Ahead Log**: Ensures profiling data is saved even if the application crashes.
17+
- **Recoverable Profiles**: Ability to resume profiling sessions after interruptions or crash.
18+
- **Automatic Trace Generation**: Generates trace files compatible with Chrome DevTools for in-depth performance analysis.
19+
- **Multiprocess Support**: Designed to handle profiling over sharded WAL.
20+
- **Controllable over env vars**: Easily enable or disable profiling through environment variables.

packages/utils/src/lib/profiler/profiler.ts

Lines changed: 102 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,13 @@
11
import process from 'node:process';
22
import { isEnvVarEnabled } from '../env.js';
3+
import { installExitHandlers } from '../exit-process';
4+
import type { TraceEvent } from '../trace-file.type';
35
import {
46
type ActionTrackConfigs,
57
type MeasureCtxOptions,
68
type MeasureOptions,
79
asOptions,
10+
errorToMarkerPayload,
811
markerPayload,
912
measureCtx,
1013
setupTracks,
@@ -13,6 +16,7 @@ import type {
1316
ActionTrackEntryPayload,
1417
DevToolsColor,
1518
EntryMeta,
19+
UserTimingDetail,
1620
} from '../user-timing-extensibility-api.type.js';
1721
import { PROFILER_ENABLED_ENV_VAR } from './constants.js';
1822

@@ -226,3 +230,101 @@ export class Profiler<T extends ActionTrackConfigs> {
226230
}
227231
}
228232
}
233+
234+
// @TODO implement ShardedWAL
235+
type WalSink = {
236+
append(event: TraceEvent): void;
237+
open(): void;
238+
close(): void;
239+
};
240+
241+
export type NodeJsProfilerOptions<T extends ActionTrackConfigs> =
242+
ProfilerOptions<T> & {
243+
// @TODO implement WALFormat
244+
format: {
245+
encode(v: string | object): string;
246+
};
247+
};
248+
249+
export class NodeJsProfiler<T extends ActionTrackConfigs> extends Profiler<T> {
250+
protected sink: WalSink | null = null;
251+
252+
constructor(options: NodeJsProfilerOptions<T>) {
253+
super(options);
254+
// Temporary dummy sink; replaced by real WAL implementation
255+
this.sink = {
256+
append: event => {
257+
options.format.encode(event);
258+
},
259+
open: () => void 0,
260+
close: () => void 0,
261+
};
262+
this.installExitHandlers();
263+
}
264+
265+
/**
266+
* Installs process exit and error handlers to ensure proper cleanup of profiling resources.
267+
*
268+
* When an error occurs or the process exits, this automatically creates a fatal error marker
269+
* and shuts down the profiler gracefully, ensuring all buffered data is flushed.
270+
*
271+
* @protected
272+
*/
273+
protected installExitHandlers(): void {
274+
installExitHandlers({
275+
onError: (err, kind) => {
276+
if (!this.isEnabled()) {
277+
return;
278+
}
279+
this.marker('Fatal Error', {
280+
...errorToMarkerPayload(err),
281+
tooltipText: `${kind} caused fatal error`,
282+
});
283+
this.shutdown();
284+
},
285+
onExit: () => {
286+
if (!this.isEnabled()) {
287+
return;
288+
}
289+
this.shutdown();
290+
},
291+
});
292+
}
293+
294+
override setEnabled(enabled: boolean): void {
295+
super.setEnabled(enabled);
296+
enabled ? this.sink?.open() : this.sink?.close();
297+
}
298+
299+
/**
300+
* Closes the profiler and releases all associated resources.
301+
* Profiling is finished forever for this instance.
302+
*
303+
* This method should be called when profiling is complete to ensure all buffered
304+
* data is flushed and the WAL sink is properly closed.
305+
*/
306+
close(): void {
307+
this.shutdown();
308+
}
309+
310+
/**
311+
* Forces all buffered Performance Entries to be written to the WAL sink.
312+
*/
313+
flush(): void {
314+
// @TODO implement WAL flush, currently all entries are buffered in memory
315+
}
316+
317+
/**
318+
* Performs internal cleanup of profiling resources.
319+
*
320+
* Flushes any remaining buffered data and closes the WAL sink.
321+
* This method is called automatically on process exit or error.
322+
*
323+
* @protected
324+
*/
325+
protected shutdown(): void {
326+
if (!this.isEnabled()) return;
327+
this.flush();
328+
this.setEnabled(false);
329+
}
330+
}

packages/utils/src/lib/profiler/profiler.unit.test.ts

Lines changed: 178 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,11 @@
11
import { performance } from 'node:perf_hooks';
22
import { beforeEach, describe, expect, it, vi } from 'vitest';
3+
import { installExitHandlers } from '../exit-process.js';
34
import type { ActionTrackEntryPayload } from '../user-timing-extensibility-api.type.js';
4-
import { Profiler, type ProfilerOptions } from './profiler.js';
5+
import { NodeJsProfiler, Profiler, type ProfilerOptions } from './profiler.js';
6+
7+
// Spy on installExitHandlers to capture handlers
8+
vi.mock('../exit-process.js');
59

610
describe('Profiler', () => {
711
const getProfiler = (overrides?: Partial<ProfilerOptions>) =>
@@ -424,3 +428,176 @@ describe('Profiler', () => {
424428
expect(workFn).toHaveBeenCalled();
425429
});
426430
});
431+
describe('NodeJsProfiler', () => {
432+
const mockInstallExitHandlers = vi.mocked(installExitHandlers);
433+
434+
let capturedOnError:
435+
| ((
436+
error: unknown,
437+
kind: 'uncaughtException' | 'unhandledRejection',
438+
) => void)
439+
| undefined;
440+
let capturedOnExit:
441+
| ((code: number, reason: import('../exit-process.js').CloseReason) => void)
442+
| undefined;
443+
const createProfiler = (overrides?: Partial<ProfilerOptions>) =>
444+
new NodeJsProfiler({
445+
prefix: 'cp',
446+
track: 'test-track',
447+
format: {
448+
encode: v => JSON.stringify(v),
449+
},
450+
...overrides,
451+
});
452+
453+
let profiler: NodeJsProfiler<Record<string, ActionTrackEntryPayload>>;
454+
455+
beforeEach(() => {
456+
capturedOnError = undefined;
457+
capturedOnExit = undefined;
458+
459+
mockInstallExitHandlers.mockImplementation(options => {
460+
capturedOnError = options?.onError;
461+
capturedOnExit = options?.onExit;
462+
});
463+
464+
performance.clearMarks();
465+
performance.clearMeasures();
466+
// eslint-disable-next-line functional/immutable-data
467+
delete process.env.CP_PROFILING;
468+
});
469+
470+
it('installs exit handlers on construction', () => {
471+
expect(() => createProfiler()).not.toThrow();
472+
473+
expect(mockInstallExitHandlers).toHaveBeenCalledWith({
474+
onError: expect.any(Function),
475+
onExit: expect.any(Function),
476+
});
477+
});
478+
479+
it('setEnabled toggles profiler state', () => {
480+
profiler = createProfiler({ enabled: true });
481+
expect(profiler.isEnabled()).toBe(true);
482+
483+
profiler.setEnabled(false);
484+
expect(profiler.isEnabled()).toBe(false);
485+
486+
profiler.setEnabled(true);
487+
expect(profiler.isEnabled()).toBe(true);
488+
});
489+
490+
it('marks fatal errors and shuts down profiler on uncaughtException', () => {
491+
profiler = createProfiler({ enabled: true });
492+
493+
const testError = new Error('Test fatal error');
494+
capturedOnError?.call(profiler, testError, 'uncaughtException');
495+
496+
expect(performance.getEntriesByType('mark')).toStrictEqual([
497+
{
498+
name: 'Fatal Error',
499+
detail: {
500+
devtools: {
501+
color: 'error',
502+
dataType: 'marker',
503+
properties: [
504+
['Error Type', 'Error'],
505+
['Error Message', 'Test fatal error'],
506+
],
507+
tooltipText: 'uncaughtException caused fatal error',
508+
},
509+
},
510+
duration: 0,
511+
entryType: 'mark',
512+
startTime: 0,
513+
},
514+
]);
515+
});
516+
517+
it('marks fatal errors and shuts down profiler on unhandledRejection', () => {
518+
profiler = createProfiler({ enabled: true });
519+
expect(profiler.isEnabled()).toBe(true);
520+
521+
capturedOnError?.call(
522+
profiler,
523+
new Error('Test fatal error'),
524+
'unhandledRejection',
525+
);
526+
527+
expect(performance.getEntriesByType('mark')).toStrictEqual([
528+
{
529+
name: 'Fatal Error',
530+
detail: {
531+
devtools: {
532+
color: 'error',
533+
dataType: 'marker',
534+
properties: [
535+
['Error Type', 'Error'],
536+
['Error Message', 'Test fatal error'],
537+
],
538+
tooltipText: 'unhandledRejection caused fatal error',
539+
},
540+
},
541+
duration: 0,
542+
entryType: 'mark',
543+
startTime: 0,
544+
},
545+
]);
546+
});
547+
it('shutdown method shuts down profiler', () => {
548+
profiler = createProfiler({ enabled: true });
549+
const setEnabledSpy = vi.spyOn(profiler, 'setEnabled');
550+
const sinkCloseSpy = vi.spyOn((profiler as any).sink, 'close');
551+
expect(profiler.isEnabled()).toBe(true);
552+
553+
(profiler as any).shutdown();
554+
555+
expect(setEnabledSpy).toHaveBeenCalledTimes(1);
556+
expect(setEnabledSpy).toHaveBeenCalledWith(false);
557+
expect(sinkCloseSpy).toHaveBeenCalledTimes(1);
558+
expect(profiler.isEnabled()).toBe(false);
559+
});
560+
it('exit handler shuts down profiler', () => {
561+
profiler = createProfiler({ enabled: true });
562+
const shutdownSpy = vi.spyOn(profiler, 'shutdown' as any);
563+
expect(profiler.isEnabled()).toBe(true);
564+
565+
capturedOnExit?.(0, { kind: 'exit' });
566+
567+
expect(profiler.isEnabled()).toBe(false);
568+
expect(shutdownSpy).toHaveBeenCalledTimes(1);
569+
});
570+
571+
it('close method shuts down profiler', () => {
572+
profiler = createProfiler({ enabled: true });
573+
const shutdownSpy = vi.spyOn(profiler, 'shutdown' as any);
574+
expect(profiler.isEnabled()).toBe(true);
575+
576+
profiler.close();
577+
578+
expect(shutdownSpy).toHaveBeenCalledTimes(1);
579+
expect(profiler.isEnabled()).toBe(false);
580+
});
581+
582+
it('error handler does nothing when profiler is disabled', () => {
583+
profiler = createProfiler({ enabled: false }); // Start disabled
584+
expect(profiler.isEnabled()).toBe(false);
585+
586+
const testError = new Error('Test error');
587+
capturedOnError?.call(profiler, testError, 'uncaughtException');
588+
589+
// Should not create any marks when disabled
590+
expect(performance.getEntriesByType('mark')).toHaveLength(0);
591+
});
592+
593+
it('exit handler does nothing when profiler is disabled', () => {
594+
profiler = createProfiler({ enabled: false }); // Start disabled
595+
expect(profiler.isEnabled()).toBe(false);
596+
597+
// Should not call shutdown when disabled
598+
const shutdownSpy = vi.spyOn(profiler, 'shutdown' as any);
599+
capturedOnExit?.(0, { kind: 'exit' });
600+
601+
expect(shutdownSpy).not.toHaveBeenCalled();
602+
});
603+
});

0 commit comments

Comments
 (0)