fix test timings (via #1051)

packages/allure-cucumberjs/src/reporter.ts

@@ -252,7 +252,7 @@ export default class AllureCucumberReporter extends Formatter {
       labels: [],
       links: [],
       testCaseId: md5(fullName),
-      start: Date.now(),
+      start: data.timestamp.nanos / 1000,
       fullName,
     };
 
@@ -338,7 +338,7 @@ export default class AllureCucumberReporter extends Formatter {
         };
       }
     });
-    this.allureRuntime.stopTest(testUuid);
+    this.allureRuntime.stopTest(testUuid, { stop: data.timestamp.nanos / 1000 });
     this.allureRuntime.writeTest(testUuid);
     this.testResultUuids.delete(data.testCaseStartedId);
 
@@ -373,6 +373,7 @@ export default class AllureCucumberReporter extends Formatter {
       const fixtureUuid = this.allureRuntime.startFixture(scopeUuid, type, {
         name,
         stage: Stage.RUNNING,
+        start: data.timestamp.nanos / 1000,
       });
       if (fixtureUuid) {
         this.fixtureUuids.set(data.testCaseStartedId, fixtureUuid);
@@ -399,7 +400,7 @@ export default class AllureCucumberReporter extends Formatter {
     const stepUuid = this.allureRuntime.startStep(testUuid, undefined, {
       ...createStepResult(),
       name: `${stepKeyword}${stepPickle.text}`,
-      start: data.timestamp.nanos,
+      start: data.timestamp.nanos / 1000,
     });
 
     if (!stepPickle.argument?.dataTable) {
@@ -443,8 +444,7 @@ export default class AllureCucumberReporter extends Formatter {
           });
         }
       });
-      // TODO stop from duration? use data.timestamp.nanos?
-      this.allureRuntime.stopFixture(fixtureUuid);
+      this.allureRuntime.stopFixture(fixtureUuid, { stop: data.timestamp.nanos / 1000 });
       this.fixtureUuids.delete(data.testCaseStartedId);
       return;
     }
@@ -475,8 +475,7 @@ export default class AllureCucumberReporter extends Formatter {
       }
     });
 
-    // TODO stop from duration? use data.timestamp.nanos?
-    this.allureRuntime.stopStep(currentStep);
+    this.allureRuntime.stopStep(currentStep, { stop: data.timestamp.nanos / 1000 });
   }
 
   private onAttachment(message: messages.Attachment): void {

packages/allure-jest/src/environmentFactory.ts

@@ -96,10 +96,10 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
           this.#handleTestStart(event.test);
           break;
         case "test_todo":
-          this.#handleTestTodo();
+          this.#handleTestTodo(event.test);
           break;
         case "test_fn_success":
-          this.#handleTestPass();
+          this.#handleTestPass(event.test);
           break;
         case "test_fn_failure":
           this.#handleTestFail(event.test);
@@ -199,6 +199,7 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
         {
           name: test.name,
           fullName: newTestFullName,
+          start: test.startedAt ?? undefined,
           labels: [
             {
               name: LabelName.LANGUAGE,
@@ -235,12 +236,12 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
       return testUuid;
     }
 
-    #stopTest(testUuid: string) {
+    #stopTest(testUuid: string, duration: number) {
       if (!testUuid) {
         return;
       }
 
-      this.runtime.stopTest(testUuid);
+      this.runtime.stopTest(testUuid, { duration });
       this.runtime.writeTest(testUuid);
     }
 
@@ -256,7 +257,7 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
       });
     }
 
-    #handleTestPass() {
+    #handleTestPass(test: Circus.TestEntry) {
       const testUuid = this.runContext.executables.pop();
 
       if (!testUuid) {
@@ -267,7 +268,7 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
         result.stage = Stage.FINISHED;
         result.status = Status.PASSED;
       });
-      this.#stopTest(testUuid);
+      this.#stopTest(testUuid, test.duration ?? 0);
     }
 
     #handleTestFail(test: Circus.TestEntry) {
@@ -291,7 +292,7 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
           ...details,
         };
       });
-      this.#stopTest(testUuid);
+      this.#stopTest(testUuid, test.duration ?? 0);
     }
 
     #handleTestSkip(test: Circus.TestEntry) {
@@ -311,10 +312,10 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
         result.stage = Stage.PENDING;
         result.status = Status.SKIPPED;
       });
-      this.#stopTest(testUuid);
+      this.#stopTest(testUuid, test.duration ?? 0);
     }
 
-    #handleTestTodo() {
+    #handleTestTodo(test: Circus.TestEntry) {
       const testUuid = this.runContext.executables.pop();
 
       if (!testUuid) {
@@ -325,7 +326,7 @@ const createJestEnvironment = <T extends typeof JestEnvironment>(Base: T): T =>
         result.stage = Stage.PENDING;
         result.status = Status.SKIPPED;
       });
-      this.#stopTest(testUuid);
+      this.#stopTest(testUuid, test.duration ?? 0);
     }
 
     #handleRunFinish() {

packages/allure-js-commons/src/sdk/reporter/ReporterRuntime.ts

@@ -29,9 +29,13 @@ import { resolveWriter } from "./writer/loader.js";
 
 interface StepStack {
   clear(): void;
+
   removeRoot(rootUuid: string): void;
+
   currentStep(rootUuid: string): string | undefined;
+
   addStep(rootUuid: string, stepUuid: string): void;
+
   removeStep(stepUuid: string): void;
 }
 
@@ -161,15 +165,18 @@ export class ReporterRuntime {
     updateFunc(fixture);
   };
 
-  stopFixture = (uuid: string, stop?: number): void => {
+  stopFixture = (uuid: string, opts?: { stop?: number; duration?: number }): void => {
     const fixture = this.state.getFixtureResult(uuid);
     if (!fixture) {
       // eslint-disable-next-line no-console
       console.error(`could not stop fixture: no fixture with uuid ${uuid} is found`);
       return;
     }
 
-    fixture.stop = stop ?? Date.now();
+    const startStop = this.#calculateTimings(fixture.start, opts?.stop, opts?.duration);
+    fixture.start = startStop.start;
+    fixture.stop = startStop.stop;
+
     fixture.stage = Stage.FINISHED;
   };
 
@@ -212,7 +219,7 @@ export class ReporterRuntime {
     this.notifier.afterTestResultUpdate(testResult);
   };
 
-  stopTest = (uuid: string, stop?: number) => {
+  stopTest = (uuid: string, opts?: { stop?: number; duration?: number }) => {
     const testResult = this.state.getTestResult(uuid);
     if (!testResult) {
       // eslint-disable-next-line no-console
@@ -223,7 +230,10 @@ export class ReporterRuntime {
     this.notifier.beforeTestResultStop(testResult);
     testResult.testCaseId ??= getTestResultTestCaseId(testResult);
     testResult.historyId ??= getTestResultHistoryId(testResult);
-    testResult.stop = stop ?? Date.now();
+
+    const startStop = this.#calculateTimings(testResult.start, opts?.stop, opts?.duration);
+    testResult.start = startStop.start;
+    testResult.stop = startStop.stop;
 
     this.notifier.afterTestResultStop(testResult);
   };
@@ -291,7 +301,7 @@ export class ReporterRuntime {
     updateFunc(step);
   };
 
-  stopStep = (uuid: string, stop?: number) => {
+  stopStep = (uuid: string, opts?: { stop?: number; duration?: number }) => {
     const step = this.state.getStepResult(uuid);
     if (!step) {
       // eslint-disable-next-line no-console
@@ -301,7 +311,10 @@ export class ReporterRuntime {
 
     this.notifier.beforeStepStop(step);
 
-    step.stop = stop ?? Date.now();
+    const startStop = this.#calculateTimings(step.start, opts?.stop, opts?.duration);
+    step.start = startStop.start;
+    step.stop = startStop.stop;
+
     step.stage = Stage.FINISHED;
 
     this.stepStack.removeStep(uuid);
@@ -481,7 +494,7 @@ export class ReporterRuntime {
         result.statusDetails = { ...result.statusDetails, ...message.statusDetails };
       }
     });
-    this.stopStep(stepUuid, message.stop);
+    this.stopStep(stepUuid, { stop: message.stop });
   };
 
   #handleAttachmentContentMessage = (rootUuid: string, message: RuntimeAttachmentContentMessage["data"]) => {
@@ -547,4 +560,27 @@ export class ReporterRuntime {
       afters,
     });
   };
+
+  #calculateTimings = (start?: number, stop?: number, duration?: number): { start?: number; stop?: number } => {
+    const result: { start?: number; stop?: number } = { start, stop };
+    if (duration) {
+      const normalisedDuration = Math.max(0, duration);
+      if (result.stop !== undefined) {
+        result.start = result.stop - normalisedDuration;
+      } else if (result.start !== undefined) {
+        result.stop = result.start + normalisedDuration;
+      } else {
+        result.stop = Date.now();
+        result.start = result.stop - normalisedDuration;
+      }
+    } else {
+      if (result.stop === undefined) {
+        result.stop = Date.now();
+      }
+      if (result.start === undefined) {
+        result.start = result.stop;
+      }
+    }
+    return result;
+  };
 }

packages/allure-js-commons/test/sdk/reporter/ReporterRuntime.spec.ts

@@ -21,7 +21,55 @@ const fixtures = {
   ] as Link[],
 };
 
+const randomInt = (max: number) => Math.floor(Math.random() * max);
+
 describe("ReporterRuntime", () => {
+  it("should set test stop from duration", () => {
+    const writer = mockWriter();
+    const runtime = new ReporterRuntime({ writer });
+
+    const start = randomInt(10_000_000);
+    const duration = randomInt(100_000);
+    const rootUuid = runtime.startTest({ start });
+    runtime.stopTest(rootUuid, { duration });
+    runtime.writeTest(rootUuid);
+
+    const [testResult] = writer.writeResult.mock.calls[0];
+    expect(testResult.start).toBe(start);
+    expect(testResult.stop).toBe(start + duration);
+  });
+
+  it("should set test stop from stop", () => {
+    const writer = mockWriter();
+    const runtime = new ReporterRuntime({ writer });
+
+    const start = randomInt(10_000_000);
+    const duration = randomInt(100_000);
+    const rootUuid = runtime.startTest({ start });
+    runtime.stopTest(rootUuid, { stop: start + duration });
+    runtime.writeTest(rootUuid);
+
+    const [testResult] = writer.writeResult.mock.calls[0];
+    expect(testResult.start).toBe(start);
+    expect(testResult.stop).toBe(start + duration);
+  });
+
+  it("should update test start from stop and duration", () => {
+    const writer = mockWriter();
+    const runtime = new ReporterRuntime({ writer });
+
+    const start = randomInt(10_000_000);
+    const stop = randomInt(10_000_000);
+    const duration = randomInt(100_000);
+    const rootUuid = runtime.startTest({ start });
+    runtime.stopTest(rootUuid, { stop, duration });
+    runtime.writeTest(rootUuid);
+
+    const [testResult] = writer.writeResult.mock.calls[0];
+    expect(testResult.start).toBe(stop - duration);
+    expect(testResult.stop).toBe(stop);
+  });
+
   it("should start/stop steps", () => {
     const writer = mockWriter();
     const runtime = new ReporterRuntime({ writer });
@@ -60,8 +108,36 @@ describe("ReporterRuntime", () => {
 
     const rootUuid = runtime.startTest({});
 
-    const stepUuid = runtime.startStep(rootUuid, undefined, { name: "some name", start: 123 });
-    runtime.stopStep(stepUuid!, 321);
+    const start = randomInt(10_000_000);
+    const stop = randomInt(10_000_000);
+    const stepUuid = runtime.startStep(rootUuid, undefined, { name: "some name", start });
+    runtime.stopStep(stepUuid!, { stop });
+
+    runtime.stopTest(rootUuid);
+    runtime.writeTest(rootUuid);
+
+    const [testResult] = writer.writeResult.mock.calls[0];
+    const [step] = testResult.steps;
+
+    expect(step).toEqual(
+      expect.objectContaining({
+        name: "some name",
+        start,
+        stop,
+      }),
+    );
+  });
+
+  it("should set start/stop time from duration for steps", () => {
+    const writer = mockWriter();
+    const runtime = new ReporterRuntime({ writer });
+
+    const rootUuid = runtime.startTest({});
+
+    const start = randomInt(10_000_000);
+    const duration = randomInt(10_000);
+    const stepUuid = runtime.startStep(rootUuid, undefined, { name: "some name", start });
+    runtime.stopStep(stepUuid!, { duration });
 
     runtime.stopTest(rootUuid);
     runtime.writeTest(rootUuid);
@@ -72,8 +148,8 @@ describe("ReporterRuntime", () => {
     expect(step).toEqual(
       expect.objectContaining({
         name: "some name",
-        start: 123,
-        stop: 321,
+        start,
+        stop: start + duration,
       }),
     );
   });

packages/allure-playwright/src/index.ts

@@ -259,7 +259,7 @@ export class AllureReporter implements ReporterV2 {
         stepResult.statusDetails = { ...getMessageAndTraceFromError(step.error) };
       }
     });
-    this.allureRuntime!.stopStep(currentStep, step.startTime.getTime() + step.duration);
+    this.allureRuntime!.stopStep(currentStep, { duration: step.duration });
   }
 
   async onTestEnd(test: TestCase, result: PlaywrightTestResult) {
@@ -363,7 +363,7 @@ export class AllureReporter implements ReporterV2 {
       testResult.labels = newLabels;
     });
 
-    this.allureRuntime!.stopTest(testUuid, result.startTime.getTime() + result.duration);
+    this.allureRuntime!.stopTest(testUuid, { duration: result.duration });
     this.allureRuntime!.writeTest(testUuid);
   }
 

packages/allure-vitest/src/reporter.ts

@@ -84,7 +84,7 @@ export default class AllureVitestReporter implements Reporter {
     const testFullname = getTestFullName(task, cwd());
     const testUuid = this.allureReporterRuntime!.startTest({
       name: testDisplayName,
-      start: task.result?.startTime ?? Date.now(),
+      start: task.result?.startTime,
     });
 
     this.allureReporterRuntime!.updateTest(testUuid, (result) => {
@@ -137,8 +137,7 @@ export default class AllureVitestReporter implements Reporter {
         }
       }
     });
-    const stop = task.result?.startTime ? task.result.startTime + (task.result.duration ?? 0) : undefined;
-    this.allureReporterRuntime!.stopTest(testUuid, stop);
+    this.allureReporterRuntime!.stopTest(testUuid, { duration: task.result?.duration ?? 0 });
     this.allureReporterRuntime!.writeTest(testUuid);
   }
 }