feat(jest-core): Add performance markers around significant lifecycle…

… events (#13859)

CHANGELOG.md

@@ -2,6 +2,8 @@
 
 ### Features
 
+- `[@jest/core]` Instrument significant lifecycle events with [`performance.mark()`](https://nodejs.org/docs/latest-v16.x/api/perf_hooks.html#performancemarkname-options) ([#13859](https://github.com/facebook/jest/pull/13859))
+
 ### Fixes
 
 - `[expect, @jest/expect]` Provide type of `actual` as a generic argument to `Matchers` to allow better-typed extensions ([#13848](https://github.com/facebook/jest/pull/13848))

packages/jest-core/src/cli/index.ts

@@ -5,6 +5,7 @@
  * LICENSE file in the root directory of this source tree.
  */
 
+import {performance} from 'perf_hooks';
 import chalk = require('chalk');
 import exit = require('exit');
 import * as fs from 'graceful-fs';
@@ -41,6 +42,7 @@ export async function runCLI(
   results: AggregatedResult;
   globalConfig: Config.GlobalConfig;
 }> {
+  performance.mark('jest/runCLI:start');
   let results: AggregatedResult | undefined;
 
   // If we output a JSON object, we can't write anything to stdout, since
@@ -133,6 +135,7 @@ export async function runCLI(
     console.error(message);
   }
 
+  performance.mark('jest/runCLI:end');
   return {globalConfig, results};
 }
 
@@ -173,6 +176,12 @@ const _run10000 = async (
   // Queries to hg/git can take a while, so we need to start the process
   // as soon as possible, so by the time we need the result it's already there.
   const changedFilesPromise = getChangedFilesPromise(globalConfig, configs);
+  if (changedFilesPromise) {
+    performance.mark('jest/getChangedFiles:start');
+    changedFilesPromise.finally(() => {
+      performance.mark('jest/getChangedFiles:end');
+    });
+  }
 
   // Filter may need to do an HTTP call or something similar to setup.
   // We will wait on an async response from this before using the filter.
@@ -204,11 +213,13 @@ const _run10000 = async (
     };
   }
 
+  performance.mark('jest/buildContextsAndHasteMaps:start');
   const {contexts, hasteMapInstances} = await buildContextsAndHasteMaps(
     configs,
     globalConfig,
     outputStream,
   );
+  performance.mark('jest/buildContextsAndHasteMaps:end');
 
   globalConfig.watch || globalConfig.watchAll
     ? await runWatch(

packages/jest-core/src/runJest.ts

@@ -6,6 +6,7 @@
  */
 
 import * as path from 'path';
+import {performance} from 'perf_hooks';
 import chalk = require('chalk');
 import exit = require('exit');
 import * as fs from 'graceful-fs';
@@ -179,6 +180,7 @@ export default async function runJest({
 
   const searchSources = contexts.map(context => new SearchSource(context));
 
+  performance.mark('jest/getTestPaths:start');
   const testRunData: TestRunData = await Promise.all(
     contexts.map(async (context, index) => {
       const searchSource = searchSources[index];
@@ -195,6 +197,7 @@ export default async function runJest({
       return {context, matches};
     }),
   );
+  performance.mark('jest/getTestPaths:end');
 
   if (globalConfig.shard) {
     if (typeof sequencer.shard !== 'function') {
@@ -260,7 +263,9 @@ export default async function runJest({
   }
 
   if (hasTests) {
+    performance.mark('jest/globalSetup:start');
     await runGlobalHook({allTests, globalConfig, moduleName: 'globalSetup'});
+    performance.mark('jest/globalSetup:end');
   }
 
   if (changedFilesPromise) {
@@ -289,14 +294,24 @@ export default async function runJest({
     ...testSchedulerContext,
   });
 
+  // @ts-expect-error - second arg is unsupported (but harmless) in Node 14
+  performance.mark('jest/scheduleAndRun:start', {
+    detail: {numTests: allTests.length},
+  });
   const results = await scheduler.scheduleTests(allTests, testWatcher);
+  performance.mark('jest/scheduleAndRun:start');
 
+  performance.mark('jest/cacheResults:start');
   sequencer.cacheResults(allTests, results);
+  performance.mark('jest/cacheResults:end');
 
   if (hasTests) {
+    performance.mark('jest/globalTeardown:start');
     await runGlobalHook({allTests, globalConfig, moduleName: 'globalTeardown'});
+    performance.mark('jest/globalTeardown:end');
   }
 
+  performance.mark('jest/processResults:start');
   await processResults(results, {
     collectHandles,
     json: globalConfig.json,
@@ -305,4 +320,5 @@ export default async function runJest({
     outputStream,
     testResultsProcessor: globalConfig.testResultsProcessor,
   });
+  performance.mark('jest/processResults:end');
 }