Fix flakey XCTest parallel test failure reporting (#1343)

The `ParallelXCTestRunStateProxy` in `XCTestOutputParser.ts` wraps the
test run state and only allows issues to be recorded using the terminal
output of the test run. The remaining test run state is filled in with
the xml xUnit output. This is because SwiftPM only dumps test output to
the terminal if there is a failure. Using these two sources we can
(almost) fully reconstruct a regular test run.

When parsing XCTest output from the terminal failure messages might be
broken up over multiple lines. In order to capture all these lines and
group them in to a single failure message even if the message is broken
up across terminal buffer chunks we maintain an `excess` variable on the
TestRunState, which we check at the beginning of chunk parsing to know
if we need to continue an error message.

However, the `ParallelXCTestRunStateProxy` that wraps the test run state
was not forwarding along the setting of `excess`. Instead `excess` was
set on the proxy, which is recreated for every chunk of output parsed.

This manifested as XCTests _sometimes_ not correctly reporting their
error message when run in the Parallel test profile, instead reporting
the message "Failed".

Issue: #1334

Author: plemarquand

src/TestExplorer/TestParsers/XCTestOutputParser.ts

@@ -92,8 +92,9 @@ export class ParallelXCTestOutputParser implements IXCTestOutputParser {
     public parseResult(output: string, runState: ITestRunState) {
         // From 5.7 to 5.10 running with the --parallel option dumps the test results out
         // to the console with no newlines, so it isn't possible to distinguish where errors
-        // begin and end. Consequently we can't record them, and so we manually mark them
-        // as passed or failed here with a manufactured issue.
+        // begin and end. Consequently we can't record them. For these versions we rely on the
+        // generated xunit XML, which we can parse and mark tests as passed or failed here with
+        // manufactured issues.
         // Don't attempt to parse the console output of parallel tests between 5.7 and 5.10
         // as it doesn't have newlines. You might get lucky and find the output is split
         // in the right spot, but more often than not we wont be able to parse it.
@@ -112,8 +113,42 @@ export class ParallelXCTestOutputParser implements IXCTestOutputParser {
 
 /* eslint-disable @typescript-eslint/no-unused-vars */
 class ParallelXCTestRunStateProxy implements ITestRunState {
+    // Note this must remain stateless as its recreated on
+    // every `parseResult` call in `ParallelXCTestOutputParser`
     constructor(private runState: ITestRunState) {}
 
+    get excess(): typeof this.runState.excess {
+        return this.runState.excess;
+    }
+
+    set excess(value: typeof this.runState.excess) {
+        this.runState.excess = value;
+    }
+
+    get activeSuite(): typeof this.runState.activeSuite {
+        return this.runState.activeSuite;
+    }
+
+    set activeSuite(value: typeof this.runState.activeSuite) {
+        this.runState.activeSuite = value;
+    }
+
+    get pendingSuiteOutput(): typeof this.runState.pendingSuiteOutput {
+        return this.runState.pendingSuiteOutput;
+    }
+
+    set pendingSuiteOutput(value: typeof this.runState.pendingSuiteOutput) {
+        this.runState.pendingSuiteOutput = value;
+    }
+
+    get failedTest(): typeof this.runState.failedTest {
+        return this.runState.failedTest;
+    }
+
+    set failedTest(value: typeof this.runState.failedTest) {
+        this.runState.failedTest = value;
+    }
+
     getTestItemIndex(id: string, filename: string | undefined): number {
         return this.runState.getTestItemIndex(id, filename);
     }

src/TestExplorer/TestXUnitParser.ts

@@ -13,8 +13,8 @@
 //===----------------------------------------------------------------------===//
 
 import * as xml2js from "xml2js";
-import { TestRunnerTestRunState } from "./TestRunner";
-import { OutputChannel } from "vscode";
+import { ITestRunState } from "./TestParsers/TestRunState";
+import { SwiftOutputChannel } from "../ui/SwiftOutputChannel";
 
 export interface TestResults {
     tests: number;
@@ -49,8 +49,8 @@ export class TestXUnitParser {
 
     async parse(
         buffer: string,
-        runState: TestRunnerTestRunState,
-        outputChannel: OutputChannel
+        runState: ITestRunState,
+        outputChannel: SwiftOutputChannel
     ): Promise<TestResults | undefined> {
         const xml = await xml2js.parseStringPromise(buffer);
         try {
@@ -63,7 +63,8 @@ export class TestXUnitParser {
     }
 
     // eslint-disable-next-line @typescript-eslint/no-unused-vars
-    async parseXUnit(xUnit: XUnit, runState: TestRunnerTestRunState): Promise<TestResults> {
+    async parseXUnit(xUnit: XUnit, runState: ITestRunState): Promise<TestResults> {
+        // eslint-disable-next-line no-console
         let tests = 0;
         let failures = 0;
         let errors = 0;
@@ -77,7 +78,7 @@ export class TestXUnitParser {
             testsuite.testcase.forEach(testcase => {
                 className = testcase.$.classname;
                 const id = `${className}/${testcase.$.name}`;
-                const index = runState.getTestItemIndex(id);
+                const index = runState.getTestItemIndex(id, undefined);
 
                 // From 5.7 to 5.10 running with the --parallel option dumps the test results out
                 // to the console with no newlines, so it isn't possible to distinguish where errors
@@ -86,7 +87,8 @@ export class TestXUnitParser {
                 if (!!testcase.failure && !this.hasMultiLineParallelTestOutput) {
                     runState.recordIssue(
                         index,
-                        testcase.failure.shift()?.$.message ?? "Test Failed"
+                        testcase.failure.shift()?.$.message ?? "Test Failed",
+                        false
                     );
                 }
                 runState.completed(index, { duration: testcase.$.time });

test/integration-tests/testexplorer/TestExplorerIntegration.test.ts

@@ -563,7 +563,7 @@ suite("Test Explorer Suite", function () {
                         });
                     });
 
-                    test(`Runs failing test (${runProfile})`, async function () {
+                    test(`swift-testing Runs failing test (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,
@@ -585,7 +585,7 @@ suite("Test Explorer Suite", function () {
                         });
                     });
 
-                    test(`Runs Suite (${runProfile})`, async function () {
+                    test(`swift-testing Runs Suite (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,
@@ -610,7 +610,7 @@ suite("Test Explorer Suite", function () {
                         });
                     });
 
-                    test(`Runs parameterized test (${runProfile})`, async function () {
+                    test(`swift-testing Runs parameterized test (${runProfile})`, async function () {
                         const testId = "PackageTests.parameterizedTest(_:)";
                         const testRun = await runTest(testExplorer, runProfile, testId);
 
@@ -660,7 +660,7 @@ suite("Test Explorer Suite", function () {
                         assert.deepEqual(unrunnableChildren, [true, true, true]);
                     });
 
-                    test(`Runs Suite (${runProfile})`, async function () {
+                    test(`swift-testing Runs Suite (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,
@@ -685,7 +685,7 @@ suite("Test Explorer Suite", function () {
                         });
                     });
 
-                    test(`Runs All (${runProfile})`, async function () {
+                    test(`swift-testing Runs All (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,
@@ -724,7 +724,7 @@ suite("Test Explorer Suite", function () {
                 });
 
                 suite(`XCTests (${runProfile})`, () => {
-                    test("Runs passing test", async function () {
+                    test(`XCTest Runs passing test (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,
@@ -739,7 +739,7 @@ suite("Test Explorer Suite", function () {
                         });
                     });
 
-                    test("Runs failing test", async function () {
+                    test(`XCTest Runs failing test (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,
@@ -760,7 +760,7 @@ suite("Test Explorer Suite", function () {
                         });
                     });
 
-                    test("Runs Suite", async function () {
+                    test(`XCTest Runs Suite (${runProfile})`, async function () {
                         const testRun = await runTest(
                             testExplorer,
                             runProfile,

test/integration-tests/testexplorer/utilities.ts

@@ -160,7 +160,11 @@ export function assertTestResults(
             skipped: (state.skipped ?? []).sort(),
             errored: (state.errored ?? []).sort(),
             unknown: 0,
-        }
+        },
+        `
+        Build Output:
+        ${testRun.runState.output.join("\n")}
+        `
     );
 }
 
@@ -280,6 +284,9 @@ export async function runTest(
     const testItems = await gatherTests(testExplorer.controller, ...tests);
     const request = new vscode.TestRunRequest(testItems);
 
+    // The first promise is the return value, the second promise builds and runs
+    // the tests, populating the TestRunProxy with results and blocking the return
+    // of that TestRunProxy until the test run is complete.
     return (
         await Promise.all([
             eventPromise(testExplorer.onCreateTestRun),