From 9622704a8a88e2de5b7a29f2660c4617112a9fac Mon Sep 17 00:00:00 2001
From: Dmitry Gozman <dgozman@gmail.com>
Date: Wed, 10 Nov 2021 16:02:27 -0800
Subject: [PATCH] fix(test runner): update TestInfo.duration before running
 afterEach hooks (#10228)

---
 docs/src/test-api/class-testinfo.md          | 2 +-
 packages/playwright-test/src/types.ts        | 1 -
 packages/playwright-test/src/workerRunner.ts | 4 +---
 packages/playwright-test/types/test.d.ts     | 1 +
 tests/playwright-test/hooks.spec.ts          | 9 +++++----
 5 files changed, 8 insertions(+), 9 deletions(-)

diff --git a/docs/src/test-api/class-testinfo.md b/docs/src/test-api/class-testinfo.md
index 4bb3d010ae..9fdabd6551 100644
--- a/docs/src/test-api/class-testinfo.md
+++ b/docs/src/test-api/class-testinfo.md
@@ -81,7 +81,7 @@ Processed configuration from the [configuration file](./test-configuration.md).
 ## property: TestInfo.duration
 - type: <[int]>
 
-The number of milliseconds the test took to finish. Always zero before the test finishes, either successfully or not.
+The number of milliseconds the test took to finish. Always zero before the test finishes, either successfully or not. Can be used in [`method: Test.afterEach`] hook.
 
 
 ## property: TestInfo.error
diff --git a/packages/playwright-test/src/types.ts b/packages/playwright-test/src/types.ts
index e8c959e9a4..2b974694b7 100644
--- a/packages/playwright-test/src/types.ts
+++ b/packages/playwright-test/src/types.ts
@@ -35,6 +35,5 @@ export interface TestStepInternal {
 }
 
 export interface TestInfoImpl extends TestInfo {
-  _testFinished: Promise<void>;
   _addStep: (data: Omit<TestStepInternal, 'complete'>) => TestStepInternal;
 }
diff --git a/packages/playwright-test/src/workerRunner.ts b/packages/playwright-test/src/workerRunner.ts
index 61e5e12383..5028e1f3df 100644
--- a/packages/playwright-test/src/workerRunner.ts
+++ b/packages/playwright-test/src/workerRunner.ts
@@ -246,7 +246,6 @@ export class WorkerRunner extends EventEmitter {
       return path.join(this._project.config.snapshotDir, relativeTestFilePath + '-snapshots');
     })();
 
-    let testFinishedCallback = () => {};
     let lastStepId = 0;
     const testInfo: TestInfoImpl = {
       workerIndex: this._params.workerIndex,
@@ -299,7 +298,6 @@ export class WorkerRunner extends EventEmitter {
         if (deadlineRunner)
           deadlineRunner.updateDeadline(deadline());
       },
-      _testFinished: new Promise(f => testFinishedCallback = f),
       _addStep: data => {
         const stepId = `${data.category}@${data.title}@${++lastStepId}`;
         let callbackHandled = false;
@@ -389,7 +387,7 @@ export class WorkerRunner extends EventEmitter {
     // Do not overwrite test failure upon hook timeout.
     if (result.timedOut && testInfo.status === 'passed')
       testInfo.status = 'timedOut';
-    testFinishedCallback();
+    testInfo.duration = monotonicTime() - startTime;
 
     if (!result.timedOut) {
       this._currentDeadlineRunner = deadlineRunner = new DeadlineRunner(this._runAfterHooks(test, testInfo), deadline());
diff --git a/packages/playwright-test/types/test.d.ts b/packages/playwright-test/types/test.d.ts
index 9e88be609f..0d0174b1d5 100644
--- a/packages/playwright-test/types/test.d.ts
+++ b/packages/playwright-test/types/test.d.ts
@@ -1329,6 +1329,7 @@ export interface TestInfo {
   retry: number;
   /**
    * The number of milliseconds the test took to finish. Always zero before the test finishes, either successfully or not.
+   * Can be used in [test.afterEach(hookFunction)](https://playwright.dev/docs/api/class-test#test-after-each) hook.
    */
   duration: number;
   /**
diff --git a/tests/playwright-test/hooks.spec.ts b/tests/playwright-test/hooks.spec.ts
index 4688f44e0b..8e1c6e82bb 100644
--- a/tests/playwright-test/hooks.spec.ts
+++ b/tests/playwright-test/hooks.spec.ts
@@ -494,12 +494,13 @@ test('beforeAll and afterAll timeouts at the same time should be reported', asyn
   expect(result.output).toContain('Timeout of 1000ms exceeded in beforeAll hook.');
 });
 
-test('afterEach should get the test status right away', async ({ runInlineTest }) => {
+test('afterEach should get the test status and duration right away', async ({ runInlineTest }) => {
   const result = await runInlineTest({
     'a.test.js': `
       const { test } = pwt;
       test.afterEach(({}, testInfo) => {
-        console.log('\\n%%' + testInfo.title + ': ' + testInfo.status);
+        const duration = testInfo.duration ? 'XXms' : 'none';
+        console.log('\\n%%' + testInfo.title + ': ' + testInfo.status + '; ' + duration);
       });
       test('failing', () => {
         throw new Error('Oh my!');
@@ -513,8 +514,8 @@ test('afterEach should get the test status right away', async ({ runInlineTest }
   expect(result.exitCode).toBe(1);
   expect(result.failed).toBe(2);
   expect(result.output.split('\n').filter(line => line.startsWith('%%'))).toEqual([
-    '%%failing: failed',
-    '%%timing out: timedOut',
+    '%%failing: failed; XXms',
+    '%%timing out: timedOut; XXms',
   ]);
 });