fix(testing): jest batch mode improvements (#13744)

nx-dev/nx-dev/jest.config.ts

@@ -1,5 +1,5 @@
 /* eslint-disable */
-const nxPreset = require('@nrwl/jest/preset');
+import nxPreset from '@nrwl/jest/preset';
 
 module.exports = {
   ...nxPreset,

packages/jest/src/executors/jest/jest.impl.ts

@@ -15,7 +15,7 @@ import {
 } from '@nrwl/devkit';
 import { getSummary } from './summary';
 import { readFileSync } from 'fs';
-
+import type { BatchResults } from 'nx/src/tasks-runner/batch/batch-messages';
 process.env.NODE_ENV ??= 'test';
 
 export async function jestExecutor(
@@ -155,7 +155,7 @@ export async function batchJest(
   inputs: Record<string, JestExecutorOptions>,
   overrides: JestExecutorOptions,
   context: ExecutorContext
-): Promise<Record<string, { success: boolean; terminalOutput: string }>> {
+): Promise<BatchResults> {
   let configPaths: string[] = [];
   let selectedProjects: string[] = [];
   let projectsWithNoName: [string, string][] = [];
@@ -202,24 +202,29 @@ export async function batchJest(
     },
     [workspaceRoot]
   );
-
   const { configs } = await readConfigs({ $0: undefined, _: [] }, configPaths);
-  const jestTaskExecutionResults: Record<
+  const jestTaskExecutionResults: BatchResults = {};
-    string,
-    { success: boolean; terminalOutput: string }
-  > = {};
 
   for (let i = 0; i < taskGraph.roots.length; i++) {
     let root = taskGraph.roots[i];
     const aggregatedResults = makeEmptyAggregatedTestResult();
     aggregatedResults.startTime = results.startTime;
-
+    let endTime: number;
     const projectRoot = join(context.root, taskGraph.tasks[root].projectRoot);
 
     let resultOutput = '';
     for (const testResult of results.testResults) {
       if (testResult.testFilePath.startsWith(projectRoot)) {
+        aggregatedResults.startTime = aggregatedResults.startTime
+          ? Math.min(aggregatedResults.startTime, testResult.perfStats.start)
+          : testResult.perfStats.start;
+
+        endTime = endTime
+          ? Math.max(testResult.perfStats.end, endTime)
+          : testResult.perfStats.end;
+
         addResult(aggregatedResults, testResult);
+
         resultOutput +=
           '\n\r' +
           jestReporterUtils.getResultHeader(
@@ -229,10 +234,15 @@ export async function batchJest(
           );
       }
     }
+
     aggregatedResults.numTotalTestSuites = aggregatedResults.testResults.length;
 
     jestTaskExecutionResults[root] = {
+      startTime: aggregatedResults.startTime,
+      endTime,
       success: aggregatedResults.numFailedTests === 0,
+      // TODO(caleb): getSummary assumed endTime is Date.now().
+      // might need to make own method to correctly set the endtime base on tests instead of _now_
       terminalOutput: resultOutput + '\n\r\n\r' + getSummary(aggregatedResults),
     };
   }

packages/nx/src/config/task-graph.ts

@@ -56,6 +56,16 @@ export interface Task {
      */
     runtime?: { [input: string]: string };
   };
+  /**
+   *
+   * Unix timestamp of when a Batch Task starts
+   **/
+  startTime?: number;
+  /**
+   *
+   * Unix timestamp of when a Batch Task ends
+   **/
+  endTime?: number;
 }
 
 /**

packages/nx/src/tasks-runner/batch/batch-messages.ts

@@ -14,7 +14,12 @@ export interface BatchTasksMessage {
  * Results of running the batch. Mapped from task id to results
  */
 export interface BatchResults {
-  [taskId: string]: { success: boolean; terminalOutput?: string };
+  [taskId: string]: {
+    success: boolean;
+    terminalOutput?: string;
+    startTime?: number;
+    endTime?: number;
+  };
 }
 export interface BatchCompleteMessage {
   type: BatchMessageType.Complete;

packages/nx/src/tasks-runner/batch/run-batch.ts

@@ -80,7 +80,6 @@ process.on('message', async (message: BatchMessage) => {
         type: BatchMessageType.Complete,
         results,
       } as BatchCompleteMessage);
-      process.exit(0);
     }
   }
 });

packages/nx/src/tasks-runner/life-cycles/store-run-information-life-cycle.spec.ts

@@ -1,5 +1,81 @@
+import { Task } from 'nx/src/config/task-graph';
+import { TaskStatus } from '../tasks-runner';
 import { StoreRunInformationLifeCycle } from './store-run-information-life-cycle';
 describe('StoreRunInformationLifeCycle', () => {
+  it.only('should handle startTime/endTime in TaskResults', () => {
+    let runDetails;
+    const store = new StoreRunInformationLifeCycle(
+      'nx run-many --target=test',
+      (res) => (runDetails = res),
+      () => 'DATE'
+    );
+
+    store.startCommand();
+
+    store.startTasks([{ id: 'proj1:test' }, { id: 'proj2:test' }] as any);
+
+    store.endTasks([
+      {
+        task: {
+          id: 'proj1:test',
+          target: { target: 'test', project: 'proj1' },
+          hash: 'hash1',
+          startTime: new Date('2020-01-0T10:00:00:000Z').getTime(),
+          endTime: new Date('2020-01-0T10:00:02:000Z').getTime(),
+        },
+        status: 'cache-miss',
+        code: 0,
+      },
+      {
+        task: {
+          id: 'proj2:test',
+          target: { target: 'test', project: 'proj2' },
+          hash: 'hash2',
+          startTime: new Date('2020-01-0T10:00:01:000Z').getTime(),
+          endTime: new Date('2020-01-0T10:00:04:000Z').getTime(),
+        },
+        status: 'cache-miss',
+        code: 0,
+      },
+    ] as any);
+
+    store.endCommand();
+    expect(runDetails).toMatchInlineSnapshot(`
+      Object {
+        "run": Object {
+          "command": "nx run-many --target=test",
+          "endTime": "DATE",
+          "inner": false,
+          "startTime": "DATE",
+        },
+        "tasks": Array [
+          Object {
+            "cacheStatus": "cache-miss",
+            "endTime": "DATE",
+            "hash": "hash1",
+            "params": "",
+            "projectName": "proj1",
+            "startTime": "DATE",
+            "status": 0,
+            "target": "test",
+            "taskId": "proj1:test",
+          },
+          Object {
+            "cacheStatus": "cache-miss",
+            "endTime": "DATE",
+            "hash": "hash2",
+            "params": "",
+            "projectName": "proj2",
+            "startTime": "DATE",
+            "status": 0,
+            "target": "test",
+            "taskId": "proj2:test",
+          },
+        ],
+      }
+    `);
+  });
+
   it('should create run details', () => {
     let runDetails;
     const store = new StoreRunInformationLifeCycle(
@@ -15,7 +91,7 @@ describe('StoreRunInformationLifeCycle', () => {
       { id: 'proj2:test' },
       { id: 'proj3:test' },
       { id: 'proj4:test' },
-    ] as any);
+    ] as Task[]);
 
     store.endTasks([
       {
@@ -54,7 +130,7 @@ describe('StoreRunInformationLifeCycle', () => {
         status: 'cache-miss',
         code: 1,
       },
-    ] as any);
+    ] as Array<{ task: Task; status: TaskStatus; code: number }>);
 
     store.endCommand();
 

packages/nx/src/tasks-runner/life-cycles/store-run-information-life-cycle.ts

@@ -40,7 +40,15 @@ export class StoreRunInformationLifeCycle implements LifeCycle {
     taskResults: Array<{ task: Task; status: TaskStatus; code: number }>
   ): void {
     for (let tr of taskResults) {
-      this.timings[tr.task.id].end = this.now();
+      if (tr.task.endTime && tr.task.startTime) {
+        this.timings[tr.task.id].start = new Date(
+          tr.task.startTime
+        ).toISOString();
+
+        this.timings[tr.task.id].end = new Date(tr.task.endTime).toISOString();
+      } else {
+        this.timings[tr.task.id].end = this.now();
+      }
     }
     this.taskResults.push(...taskResults);
   }

packages/nx/src/tasks-runner/life-cycles/task-profiling-life-cycle.ts

@@ -37,9 +37,12 @@ export class TaskProfilingLifeCycle implements LifeCycle {
     metadata: TaskMetadata
   ): void {
     for (let tr of taskResults) {
-      this.timings[
+      if (tr.task.endTime && tr.task.startTime) {
-        `${tr.task.target.project}:${tr.task.target.target}`
+        this.timings[tr.task.id].perfStart = tr.task.startTime;
-      ].perfEnd = performance.now();
+        this.timings[tr.task.id].perfEnd = tr.task.endTime;
+      } else {
+        this.timings[tr.task.id].perfEnd = performance.now();
+      }
     }
     this.recordTaskCompletions(taskResults, metadata);
   }
@@ -54,8 +57,7 @@ export class TaskProfilingLifeCycle implements LifeCycle {
     { groupId }: TaskMetadata
   ) {
     for (const { task, status } of tasks) {
-      const { perfStart, perfEnd } =
+      const { perfStart, perfEnd } = this.timings[task.id];
-        this.timings[`${task.target.project}:${task.target.target}`];
       this.profile.push({
         name: task.id,
         cat: Object.values(task.target).join(','),

packages/nx/src/tasks-runner/life-cycles/task-timings-life-cycle.ts

@@ -12,7 +12,7 @@ export class TaskTimingsLifeCycle implements LifeCycle {
 
   startTasks(tasks: Task[]): void {
     for (let t of tasks) {
-      this.timings[`${t.target.project}:${t.target.target}`] = {
+      this.timings[t.id] = {
         start: new Date().getTime(),
         end: undefined,
       };
@@ -20,11 +20,19 @@ export class TaskTimingsLifeCycle implements LifeCycle {
   }
 
   endTasks(
-    taskResults: Array<{ task: Task; status: TaskStatus; code: number }>
+    taskResults: Array<{
+      task: Task;
+      status: TaskStatus;
+      code: number;
+    }>
   ): void {
     for (let tr of taskResults) {
-      this.timings[`${tr.task.target.project}:${tr.task.target.target}`].end =
+      if (tr.task.endTime && tr.task.startTime) {
-        new Date().getTime();
+        this.timings[tr.task.id].start = tr.task.startTime;
+        this.timings[tr.task.id].end = tr.task.endTime;
+      } else {
+        this.timings[tr.task.id].end = new Date().getTime();
+      }
     }
   }
 

packages/nx/src/tasks-runner/run-command.ts

@@ -161,6 +161,9 @@ export async function runCommand(
       }
 
       const tasks = Object.values(taskGraph.tasks);
+      if (process.env.NX_BATCH_MODE === 'true') {
+        nxArgs.outputStyle = 'stream';
+      }
       if (nxArgs.outputStyle == 'stream') {
         process.env.NX_STREAM_OUTPUT = 'true';
         process.env.NX_PREFIX_OUTPUT = 'true';

packages/nx/src/tasks-runner/task-orchestrator.ts

@@ -229,6 +229,7 @@ export class TaskOrchestrator {
       );
       const batchResultEntries = Object.entries(results);
       return batchResultEntries.map(([taskId, result]) => ({
+        ...result,
         task: this.taskGraph.tasks[taskId],
         status: (result.success ? 'success' : 'failure') as TaskStatus,
         terminalOutput: result.terminalOutput,
@@ -359,7 +360,6 @@ export class TaskOrchestrator {
           this.cache.put(task, terminalOutput, outputs, code)
         )
     );
-
     this.options.lifeCycle.endTasks(
       results.map((result) => {
         const code =
@@ -370,6 +370,7 @@ export class TaskOrchestrator {
             ? 0
             : 1;
         return {
+          ...result,
           task: result.task,
           status: result.status,
           code,