feat(test runner): collect test error from worker teardown (#9190)

When the test fails (usually with timeout), we wait until all hooks are run
and worker scope is teared down before reporting test end result.

This allows us to collect any error details populated by teardown
in addition to the "timed out" message.

src/test/workerRunner.ts

@@ -74,6 +74,12 @@ export class WorkerRunner extends EventEmitter {
   async cleanup() {
     // We have to load the project to get the right deadline below.
     await this._loadIfNeeded();
+    await this._teardownScopes();
+    if (this._fatalError)
+      this.emit('teardownError', { error: this._fatalError });
+  }
+
+  private async _teardownScopes() {
     // TODO: separate timeout for teardown?
     const result = await raceAgainstDeadline((async () => {
       await this._fixtureRunner.teardownScope('test');
@@ -81,8 +87,6 @@ export class WorkerRunner extends EventEmitter {
     })(), this._deadline());
     if (result.timedOut && !this._fatalError)
       this._fatalError = { message: colors.red(`Timeout of ${this._project.config.timeout}ms exceeded while shutting down environment`) };
-    if (this._fatalError)
-      this.emit('teardownError', { error: this._fatalError });
   }
 
   unhandledError(error: Error | any) {
@@ -144,12 +148,19 @@ export class WorkerRunner extends EventEmitter {
         this._fixtureRunner.setPool(anyPool);
         await this._runSuite(suite, []);
       }
+      if (this._failedTest)
+        await this._teardownScopes();
     } catch (e) {
       // In theory, we should run above code without any errors.
       // However, in the case we screwed up, or loadTestFile failed in the worker
       // but not in the runner, let's do a fatal error.
       this.unhandledError(e);
     } finally {
+      if (this._failedTest) {
+        // Now that we did run all hooks and teared down scopes, we can
+        // report the failure, possibly with any error details revealed by teardown.
+        this.emit('testEnd', buildTestEndPayload(this._failedTest.testId, this._failedTest.testInfo));
+      }
       this._reportDone();
       runFinishedCallback();
     }
@@ -370,22 +381,15 @@ export class WorkerRunner extends EventEmitter {
       await deadlineRunner.result;
     }
 
-    this._currentDeadlineRunner = undefined;
     testInfo.duration = monotonicTime() - startTime;
-    if (reportEvents)
-      this.emit('testEnd', buildTestEndPayload(testId, testInfo));
-
-    const isFailure = testInfo.status !== 'skipped' && testInfo.status !== testInfo.expectedStatus;
-    const preserveOutput = this._loader.fullConfig().preserveOutput === 'always' ||
-      (this._loader.fullConfig().preserveOutput === 'failures-only' && isFailure);
-    if (!preserveOutput)
-      await removeFolderAsync(testInfo.outputDir).catch(e => {});
-
+    this._currentDeadlineRunner = undefined;
     this._currentTest = null;
     setCurrentTestInfo(null);
 
+    const isFailure = testInfo.status !== 'skipped' && testInfo.status !== testInfo.expectedStatus;
     if (isFailure) {
       if (test._type === 'test') {
+        // Delay reporting testEnd result until after teardownScopes is done.
         this._failedTest = testData;
       } else if (!this._fatalError) {
         if (testInfo.status === 'timedOut')
@@ -394,7 +398,14 @@ export class WorkerRunner extends EventEmitter {
           this._fatalError = testInfo.error;
       }
       this.stop();
+    } else if (reportEvents) {
+      this.emit('testEnd', buildTestEndPayload(testId, testInfo));
     }
+
+    const preserveOutput = this._loader.fullConfig().preserveOutput === 'always' ||
+      (this._loader.fullConfig().preserveOutput === 'failures-only' && isFailure);
+    if (!preserveOutput)
+      await removeFolderAsync(testInfo.outputDir).catch(e => {});
   }
 
   private async _runBeforeHooks(test: TestCase, testInfo: TestInfoImpl) {

tests/playwright-test/fixture-errors.spec.ts

@@ -95,6 +95,26 @@ test('should handle worker tear down fixture error', async ({ runInlineTest }) =
   expect(result.exitCode).toBe(1);
 });
 
+test('should handle worker tear down fixture error after failed test', async ({ runInlineTest }) => {
+  const result = await runInlineTest({
+    'a.spec.ts': `
+      const test = pwt.test.extend({
+        failure: [async ({}, runTest) => {
+          await runTest();
+          throw new Error('Worker failed');
+        }, { scope: 'worker' }]
+      });
+
+      test('timeout', async ({failure}) => {
+        await new Promise(f => setTimeout(f, 2000));
+      });
+    `
+  }, { timeout: 1000 });
+  expect(result.exitCode).toBe(1);
+  expect(result.output).toContain('Timeout of 1000ms exceeded.');
+  expect(result.output).toContain('Worker failed');
+});
+
 test('should throw when using non-defined super worker fixture', async ({ runInlineTest }) => {
   const result = await runInlineTest({
     'a.spec.ts': `

tests/playwright-test/fixtures.spec.ts

@@ -678,3 +678,24 @@ test('worker fixture should not receive TestInfo', async ({ runInlineTest }) =>
   });
   expect(result.exitCode).toBe(0);
 });
+
+test('worker teardown errors reflected in timed-out tests', async ({ runInlineTest }) => {
+  const result = await runInlineTest({
+    'a.test.js': `
+      const test = pwt.test.extend({
+        foo: [async ({}, use) => {
+          let cb;
+          await use(new Promise((f, r) => cb = r));
+          cb(new Error('Rejecting!'));
+        }, { scope: 'worker' }]
+      });
+      test('timedout', async ({ foo }) => {
+        await foo;
+      });
+    `,
+  }, { timeout: 1000 });
+  expect(result.exitCode).toBe(1);
+  expect(result.failed).toBe(1);
+  expect(result.output).toContain('Timeout of 1000ms exceeded.');
+  expect(result.output).toContain('Rejecting!');
+});

tests/playwright-test/playwright.spec.ts

@@ -272,6 +272,30 @@ test('should report error and pending operations on timeout', async ({ runInline
   expect(stripAscii(result.output)).toContain(`10 |           page.textContent('text=More missing'),`);
 });
 
+test('should report error on timeout with shared page', async ({ runInlineTest }, testInfo) => {
+  const result = await runInlineTest({
+    'a.test.ts': `
+      const { test } = pwt;
+      let page;
+      test.beforeAll(async ({ browser }) => {
+        page = await browser.newPage();
+      });
+      test('passed', async () => {
+        await page.setContent('<div>Click me</div>');
+      });
+      test('timedout', async () => {
+        await page.click('text=Missing');
+      });
+    `,
+  }, { workers: 1, timeout: 2000 });
+
+  expect(result.exitCode).toBe(1);
+  expect(result.passed).toBe(1);
+  expect(result.failed).toBe(1);
+  expect(result.output).toContain('waiting for selector "text=Missing"');
+  expect(stripAscii(result.output)).toContain(`14 |         await page.click('text=Missing');`);
+});
+
 test('should not report waitForEventInfo as pending', async ({ runInlineTest }, testInfo) => {
   const result = await runInlineTest({
     'a.test.ts': `