fix(test runner): avoid internal error for step end without begin (#8327)

fix(test runner): avoid internal error for step end without begin

Consider the following scenario:
- Test finishes and starts tearing down fixtures.
- Fixture teardown starts a step S and then times out.
- We declare the test finished (with timeout).
- Dispatcher shuts down the worker and spins a new one for a retry.
  Additionally, it clears steps information for the test to be
  ready for the new retry. Step S information is lost.
- Meanwhile, during worker teardown, the step S does
  actually finish (usually with an error), and we send stepEnd for S.
- Dispatcher does not know what to do with step S end and
  prints an internal error.

The fix is to ignore certain messages from the shutting down worker that failed.

src/test/dispatcher.ts

@@ -124,6 +124,7 @@ export class Dispatcher {
 
       // When worker encounters error, we will stop it and create a new one.
       worker.stop();
+      worker.didFail = true;
 
       const retryCandidates = new Set<string>();
 
@@ -255,6 +256,11 @@ export class Dispatcher {
   _createWorker(testGroup: TestGroup) {
     const worker = new Worker(this);
     worker.on('testBegin', (params: TestBeginPayload) => {
+      if (worker.didFail) {
+        // Ignore test-related messages from failed workers, because timed out tests/fixtures
+        // may be triggering unexpected messages.
+        return;
+      }
       if (this._hasReachedMaxFailures())
         return;
       const { test, result: testRun  } = this._testById.get(params.testId)!;
@@ -263,6 +269,11 @@ export class Dispatcher {
       this._reporter.onTestBegin?.(test, testRun);
     });
     worker.on('testEnd', (params: TestEndPayload) => {
+      if (worker.didFail) {
+        // Ignore test-related messages from failed workers, because timed out tests/fixtures
+        // may be triggering unexpected messages.
+        return;
+      }
       if (this._hasReachedMaxFailures())
         return;
       const { test, result } = this._testById.get(params.testId)!;
@@ -281,6 +292,11 @@ export class Dispatcher {
       this._reportTestEnd(test, result);
     });
     worker.on('stepBegin', (params: StepBeginPayload) => {
+      if (worker.didFail) {
+        // Ignore test-related messages from failed workers, because timed out tests/fixtures
+        // may be triggering unexpected messages.
+        return;
+      }
       const { test, result, steps, stepStack } = this._testById.get(params.testId)!;
       const parentStep = [...stepStack].pop();
       const step: TestStep = {
@@ -301,6 +317,11 @@ export class Dispatcher {
       this._reporter.onStepBegin?.(test, result, step);
     });
     worker.on('stepEnd', (params: StepEndPayload) => {
+      if (worker.didFail) {
+        // Ignore test-related messages from failed workers, because timed out tests/fixtures
+        // may be triggering unexpected messages.
+        return;
+      }
       const { test, result, steps, stepStack } = this._testById.get(params.testId)!;
       const step = steps.get(params.stepId);
       if (!step) {
@@ -316,6 +337,13 @@ export class Dispatcher {
     });
     worker.on('stdOut', (params: TestOutputPayload) => {
       const chunk = chunkFromParams(params);
+      if (worker.didFail) {
+        // Note: we keep reading stdout from workers that are currently stopping after failure,
+        // to debug teardown issues. However, we avoid spoiling the test result from
+        // the next retry.
+        this._reporter.onStdOut?.(chunk);
+        return;
+      }
       const pair = params.testId ? this._testById.get(params.testId) : undefined;
       if (pair)
         pair.result.stdout.push(chunk);
@@ -323,6 +351,13 @@ export class Dispatcher {
     });
     worker.on('stdErr', (params: TestOutputPayload) => {
       const chunk = chunkFromParams(params);
+      if (worker.didFail) {
+        // Note: we keep reading stderr from workers that are currently stopping after failure,
+        // to debug teardown issues. However, we avoid spoiling the test result from
+        // the next retry.
+        this._reporter.onStdErr?.(chunk);
+        return;
+      }
       const pair = params.testId ? this._testById.get(params.testId) : undefined;
       if (pair)
         pair.result.stderr.push(chunk);
@@ -381,6 +416,7 @@ class Worker extends EventEmitter {
   hash = '';
   index: number;
   didSendStop = false;
+  didFail = false;
 
   constructor(runner: Dispatcher) {
     super();

tests/playwright-test/reporter.spec.ts

@@ -373,6 +373,28 @@ test('should report test.step', async ({ runInlineTest }) => {
   ]);
 });
 
+test('should not have internal error when steps are finished after timeout', async ({ runInlineTest }) => {
+  const result = await runInlineTest({
+    'a.test.ts': `
+      const test = pwt.test.extend({
+        page: async ({ page }, use) => {
+          await use(page);
+          // Timeout in fixture teardown that will resolve on browser.close.
+          await page.waitForNavigation();
+        },
+      });
+      test('pass', async ({ page }) => {
+        // Timeout in the test.
+        await page.click('foo');
+      });
+    `
+  }, { workers: 1, timeout: 1000, reporter: 'dot', retries: 1 });
+
+  expect(result.exitCode).toBe(1);
+  expect(result.failed).toBe(1);
+  expect(result.output).not.toContain('Internal error');
+});
+
 test('should report api step hierarchy', async ({ runInlineTest }) => {
   const expectReporterJS = `
     class Reporter {
@@ -389,7 +411,7 @@ test('should report api step hierarchy', async ({ runInlineTest }) => {
           steps: step.steps.length ? step.steps.map(s => this.distillStep(s)) : undefined,
         };
       }
-    
+
       async onEnd() {
         const processSuite = (suite: Suite) => {
           for (const child of suite.suites)