Skip to content

Commit 08133d2

Browse files
committed
feat(core): add --trace flag to dump Perfetto-compatible profile
When `--trace` is passed (or `performance.trace: true` is set in config), each test file's lifecycle is recorded as Perfetto-compatible events and written at run end to `<rootPath>/.rstest/trace-<timestamp>.json`. The trace contains: - per-phase `ph: 'X'` spans (prepare, envSetup, load, setupFiles, collect, tests, coverage, teardown) - per-suite / per-case `ph: 'X'` spans via the runner's existing lifecycle hooks (zero intrusion into runner.ts) - heap-usage counter samples (`ph: 'C'`) at each phase boundary so memory pressure shows up as a track in Perfetto UI Each `PhaseTracker` (one per test file) gets a unique per-process `tid`, so workers with `isolate: false` render multiple files as distinct thread tracks instead of collapsing onto the first file's label. A tiny localhost HTTP server on port 9001 (the only port allowed by Perfetto UI's CSP) starts in TTY runs so the printed `ui.perfetto.dev` deep-link loads the trace directly; in non-TTY (CI) runs the file is written without spawning the server so `rstest run` exits cleanly.
1 parent 5034f79 commit 08133d2

16 files changed

Lines changed: 685 additions & 17 deletions

File tree

.gitignore

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
.DS_Store
22
*.log*
33
*.cpuprofile
4+
*.dump
45
node_modules/
56

67
.cache/
@@ -48,6 +49,7 @@ packages/vscode/*.vsix
4849
packages/vscode/icon.png
4950

5051
.rstest-temp/
52+
.rstest/
5153
lefthook-local.yml
5254

5355
# Generated memory benchmark fixture

packages/core/src/cli/commands.ts

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,7 @@ const runtimeOptionDefinitions: OptionDefinition[] = [
6767
],
6868
['--disableConsoleIntercept', 'Disable console intercept'],
6969
['--logHeapUsage', 'Log heap usage after each test'],
70+
['--trace', 'Dump a Perfetto-compatible performance trace JSON file'],
7071
[
7172
'--slowTestThreshold <value>',
7273
'The number of milliseconds after which a test or suite is considered slow',
@@ -321,7 +322,7 @@ export const runRest = async ({
321322
});
322323

323324
rstest = createRstest(
324-
{ config, configFilePath, projects },
325+
{ config, configFilePath, projects, trace: options.trace },
325326
command,
326327
effectiveFilters,
327328
fileFilterMode,

packages/core/src/cli/init.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,7 @@ export type CommonOptions = {
6767
silent?: boolean | 'passed-only';
6868
printConsoleTrace?: boolean;
6969
logHeapUsage?: boolean;
70+
trace?: boolean;
7071
disableConsoleIntercept?: boolean;
7172
update?: boolean;
7273
testNamePattern?: RegExp | string;

packages/core/src/core/index.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,10 +13,13 @@ export function createRstest(
1313
config,
1414
projects,
1515
configFilePath,
16+
trace,
1617
}: {
1718
config: RstestConfig;
1819
configFilePath?: string;
1920
projects: Project[];
21+
/** CLI-only `--trace` switch; not exposed via user config. */
22+
trace?: boolean;
2023
},
2124
command: RstestCommand,
2225
fileFilters: string[],
@@ -30,6 +33,7 @@ export function createRstest(
3033
fileFilterMode,
3134
configFilePath,
3235
projects,
36+
trace,
3337
},
3438
config,
3539
);

packages/core/src/core/rstest.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -49,6 +49,7 @@ type Options = {
4949
fileFilterMode?: FileFilterMode;
5050
configFilePath?: string;
5151
projects: Project[];
52+
trace?: boolean;
5253
};
5354

5455
export class Rstest implements RstestContext {
@@ -61,6 +62,7 @@ export class Rstest implements RstestContext {
6162
public configFilePath?: string;
6263
public reporters: Reporter[];
6364
public snapshotManager: SnapshotManager;
65+
public trace: boolean;
6466
public version: string;
6567
public rootPath: string;
6668
public originalConfig: RstestConfig;
@@ -96,11 +98,13 @@ export class Rstest implements RstestContext {
9698
fileFilterMode,
9799
configFilePath,
98100
projects,
101+
trace = false,
99102
}: Options,
100103
userConfig: RstestConfig,
101104
) {
102105
this.cwd = cwd;
103106
this.command = command;
107+
this.trace = trace;
104108
this.fileFilters = fileFilters;
105109
this.fileFilterMode = fileFilterMode;
106110
this.configFilePath = configFilePath;

packages/core/src/core/runTests.ts

Lines changed: 25 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,17 @@
11
import { constants as osConstants } from 'node:os';
22
import { cleanCoverageReports, createCoverageProvider } from '../coverage';
33
import { createPool } from '../pool';
4-
import type { EntryInfo, ProjectEntries, SourceMapInput } from '../types';
4+
import type {
5+
Duration,
6+
EntryInfo,
7+
ProjectEntries,
8+
SourceMapInput,
9+
} from '../types';
510
import type { CoverageMap } from '../types/coverage';
611
import {
712
clearScreen,
813
color,
14+
createTraceController,
915
getTestEntries,
1016
logger,
1117
resolveShardedEntries,
@@ -110,11 +116,7 @@ const notifyReportersOnTestRunEnd = async ({
110116
}: {
111117
context: Rstest;
112118
coverage?: CoverageMap;
113-
duration: {
114-
totalTime: number;
115-
buildTime: number;
116-
testTime: number;
117-
};
119+
duration: Duration;
118120
getSourcemap: (sourcePath: string) => Promise<SourceMapInput | null>;
119121
unhandledErrors?: Error[];
120122
filterRerunTestPaths?: string[];
@@ -434,6 +436,11 @@ export async function runTests(context: Rstest): Promise<void> {
434436

435437
type Mode = 'all' | 'on-demand';
436438

439+
const traceController = createTraceController({
440+
enabled: context.trace,
441+
rootPath,
442+
});
443+
437444
const run = async ({
438445
fileFilters,
439446
mode = 'all',
@@ -460,6 +467,8 @@ export async function runTests(context: Rstest): Promise<void> {
460467
? coverageProvider.createCoverageMap()
461468
: undefined;
462469

470+
const traceRun = traceController.beginRun();
471+
463472
const returns = await Promise.all(
464473
projects.map(async (p) => {
465474
const {
@@ -548,6 +557,7 @@ export async function runTests(context: Rstest): Promise<void> {
548557
project: p,
549558
updateSnapshot: context.snapshotManager.options.updateSnapshot,
550559
onCoverageResult: (coverage) => mergedCoverageMap?.merge(coverage),
560+
onTraceEvents: traceRun.onEvents,
551561
});
552562

553563
return {
@@ -599,7 +609,7 @@ export async function runTests(context: Rstest): Promise<void> {
599609
};
600610

601611
// When unifying reporter output, combine browser and node durations
602-
const duration =
612+
const duration: Duration =
603613
shouldUnifyReporter && browserResult
604614
? {
605615
totalTime:
@@ -680,6 +690,8 @@ export async function runTests(context: Rstest): Promise<void> {
680690
await generateCoverage(context, mergedCoverageMap!, coverageProvider);
681691
}
682692

693+
await traceRun.finalize();
694+
683695
if (isFailure) {
684696
const bail = context.normalizedConfig.bail;
685697

@@ -711,6 +723,7 @@ export async function runTests(context: Rstest): Promise<void> {
711723
await runGlobalTeardown();
712724
await pool.close();
713725
await closeServer();
726+
await traceController.close();
714727
} catch (error) {
715728
logger.log(color.red(`Error during cleanup: ${error}`));
716729
}
@@ -750,6 +763,7 @@ export async function runTests(context: Rstest): Promise<void> {
750763
await runGlobalTeardown();
751764
await pool.close();
752765
await closeServer();
766+
await traceController.close();
753767
});
754768

755769
let buildStart: number | undefined;
@@ -771,6 +785,7 @@ export async function runTests(context: Rstest): Promise<void> {
771785
closeServer: async () => {
772786
await pool.close();
773787
await closeServer();
788+
await traceController.close();
774789
},
775790
runAll: async () => {
776791
clearScreen();
@@ -898,6 +913,7 @@ export async function runTests(context: Rstest): Promise<void> {
898913
await runGlobalTeardown();
899914
await pool.close();
900915
await closeServer();
916+
await traceController.close();
901917
} catch (error) {
902918
logger.log(color.red(`Error during cleanup: ${error}`));
903919
}
@@ -952,5 +968,7 @@ export async function runTests(context: Rstest): Promise<void> {
952968
process.off('SIGTERM', handleSignal);
953969
process.off('SIGTSTP', handleSignal);
954970
}
971+
972+
await traceController.waitForExit();
955973
}
956974
}

packages/core/src/pool/index.ts

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@ import {
2525
isDeno,
2626
needFlagExperimentalDetectModule,
2727
} from '../utils';
28+
import type { TraceEvent } from '../utils/trace';
2829
import { isMemorySufficient } from '../utils/memory';
2930
import { Pool } from './pool';
3031

@@ -192,6 +193,7 @@ const buildTask = async ({
192193
rootPath: context.rootPath,
193194
projectRoot: project.rootPath,
194195
runtimeConfig,
196+
trace: context.trace,
195197
},
196198
type,
197199
setupEntries,
@@ -267,6 +269,8 @@ export const createPool = async ({
267269
project: ProjectContext;
268270
/** When provided, coverage data is passed to this callback immediately for caller-owned merging. */
269271
onCoverageResult?: (coverage: CoverageMapData) => void;
272+
/** Perfetto trace events forwarded for caller-owned dumping. */
273+
onTraceEvents?: (events: TraceEvent[]) => void;
270274
}) => Promise<{
271275
results: TestFileResult[];
272276
testResults: TestResult[];
@@ -449,6 +453,7 @@ export const createPool = async ({
449453
project,
450454
updateSnapshot,
451455
onCoverageResult,
456+
onTraceEvents,
452457
}) => {
453458
const projectName = project.name;
454459
const runtimeConfig = getRuntimeConfig(project);
@@ -488,6 +493,10 @@ export const createPool = async ({
488493
onCoverageResult?.(result.coverage);
489494
delete result.coverage;
490495
}
496+
if (result.traceEvents) {
497+
onTraceEvents?.(result.traceEvents);
498+
delete result.traceEvents;
499+
}
491500
context.stateManager.onTestFileResult(result);
492501
reporters.map((reporter) => reporter.onTestFileResult?.(result));
493502
return result;

packages/core/src/runtime/util.ts

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,14 @@ export const getRealTimers = (): typeof REAL_TIMERS => {
2828
return REAL_TIMERS;
2929
};
3030

31+
/**
32+
* Stable reference to `Date.now`, captured before `@sinonjs/fake-timers`
33+
* can hijack the global. Phase boundaries straddling `tests` rely on this.
34+
*/
35+
const realNow = Date.now.bind(Date);
36+
37+
export const getRealNow = (): number => realNow();
38+
3139
export const formatTestError = async (
3240
err: any,
3341
test?: Test,

0 commit comments

Comments
 (0)