From 323e037cf386112a630e6055bf0b27bcd0136bba Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 11:19:36 +0530 Subject: [PATCH 1/9] fix(cli): record a timed-out mocha test's failure when mocha reports it (SDK-7843) wdio runs a test's afterTest inside the test's runnable, after the body. When a test hits mocha's timeout, mocha fails it while the body and its afterTest are still pending. With `bail`, or when it is the worker's last test, wdio then runs after() BEFORE that afterTest. On the CLI flow everything after() does then runs without the failure: - AutomateModule.onAfterExecute marks the session `passed`, because its results only come from afterTest. - The test's TestRunFinished is stranded, so Test Hub reaps the build as `timeout` about 60 min later. The classic flow never had this, because it reads the session status from after(result), which is mocha's own failure count. Since 9.39.3 the CLI also boots for App Automate accounts whose bin-session config has no `apis` (#261), so those accounts now hit it. One customer had 78 timed-out sessions marked passed in 6 days, against 0 the week before. Fix at the source: the service registers a finisher per mocha test in beforeTest (cli/earlyTestFinish.ts). The reporter's onTestFail, which mocha drives at the moment it fails the test, reports the failure through it with mocha's own result. after() awaits those finishes before its deferred-finish flush and EXECUTE/POST. The late afterTest then sees the test was already reported and stands down. A normal failure is still reported by afterTest, which runs before mocha's `fail`, so the reporter is a no-op for it. Co-Authored-By: Claude Opus 5.5 --- .../src/cli/earlyTestFinish.ts | 75 ++++++++++++ packages/browserstack-service/src/reporter.ts | 23 ++++ packages/browserstack-service/src/service.ts | 71 ++++++++---- .../tests/cli/earlyTestFinish.test.ts | 71 ++++++++++++ .../tests/reporter.onTestFail.test.ts | 58 ++++++++++ .../tests/service.timedOutTestFinish.test.ts | 109 ++++++++++++++++++ 6 files changed, 387 insertions(+), 20 deletions(-) create mode 100644 packages/browserstack-service/src/cli/earlyTestFinish.ts create mode 100644 packages/browserstack-service/tests/cli/earlyTestFinish.test.ts create mode 100644 packages/browserstack-service/tests/reporter.onTestFail.test.ts create mode 100644 packages/browserstack-service/tests/service.timedOutTestFinish.test.ts diff --git a/packages/browserstack-service/src/cli/earlyTestFinish.ts b/packages/browserstack-service/src/cli/earlyTestFinish.ts new file mode 100644 index 00000000..c37001f6 --- /dev/null +++ b/packages/browserstack-service/src/cli/earlyTestFinish.ts @@ -0,0 +1,75 @@ +import util from 'node:util' +import type { Frameworks } from '@wdio/types' + +import { BStackLogger } from '../bstackLogger.js' + +/** + * SDK-7843: finish a mocha test on the CLI flow at the moment mocha reports it failed. + * + * wdio runs a test's `afterTest` hook inside the test's own runnable, after the body. When the + * test hits mocha's timeout, mocha marks it failed (and emits `fail` to reporters) while the body + * and its `afterTest` are still pending. With `bail`, or when it was the worker's last test, wdio + * then runs `after()` BEFORE that `afterTest` fires, so everything `after()` does on the CLI flow + * runs without the failure: the session status is marked `passed`, and the test's TestRunFinished + * is stranded until Test Hub reaps the build as `timeout`. The classic flow never had this, because + * it reads the session status from `after(result)` — mocha's own failure count. + * + * So the service registers a finisher per running test in `beforeTest`; whichever comes first — + * `afterTest` (normal case) or the reporter's `onTestFail` (timeout case) — claims it and reports + * the finish exactly once. `after()` awaits any finish the reporter started. + */ +type CliTestFinisher = (result: Frameworks.TestResult) => Promise + +const finishers = new Map() +/** Tests the reporter already finished; their late afterTest must not report them again. */ +const reportedOnFailure = new Set() +const inFlight = new Set>() + +/** beforeTest: this test's finish is now owed, by afterTest or by the reporter. */ +export function registerCliTestFinisher(identifier: string, finisher: CliTestFinisher): void { + finishers.set(identifier, finisher) +} + +/** + * afterTest: claim the finish. Returns false only when the reporter already reported it (the + * test timed out), in which case afterTest must not report it again. A test that was never + * registered still belongs to afterTest. + */ +export function claimCliTestFinish(identifier: string): boolean { + finishers.delete(identifier) + return !reportedOnFailure.delete(identifier) +} + +/** + * Reporter `onTestFail`: if afterTest has not reported this test yet, report its failure now, + * from mocha's own result. Returns whether a finish was started. + */ +export function finishCliTestOnFailure(identifier: string, result: Frameworks.TestResult): boolean { + const finisher = finishers.get(identifier) + if (!finisher) { + return false + } + finishers.delete(identifier) + reportedOnFailure.add(identifier) + BStackLogger.debug(`finishCliTestOnFailure: mocha reported '${identifier}' failed before its afterTest; reporting the finish now`) + const work = finisher(result).catch((err: unknown) => { + BStackLogger.debug(`finishCliTestOnFailure: reporting '${identifier}' failed: ${util.format(err)}`) + }) + inFlight.add(work) + work.finally(() => inFlight.delete(work)) + return true +} + +/** after(): wait for finishes the reporter started, before the session status and the flush. */ +export async function awaitCliTestFinishesOnFailure(): Promise { + while (inFlight.size > 0) { + await Promise.all([...inFlight]) + } +} + +/** Test-only reset of the module state. */ +export function resetCliTestFinishers(): void { + finishers.clear() + reportedOnFailure.clear() + inFlight.clear() +} diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index 68d77738..a91101f8 100644 --- a/packages/browserstack-service/src/reporter.ts +++ b/packages/browserstack-service/src/reporter.ts @@ -5,6 +5,7 @@ import WDIOReporter from '@wdio/reporter' import type { Options, Frameworks } from '@wdio/types' import { BrowserstackCLI } from './cli/index.js' import { reportSkippedTest, resolveSpecFile } from './cli/skipReporter.js' +import { finishCliTestOnFailure } from './cli/earlyTestFinish.js' import * as url from 'node:url' import { v4 as uuidv4 } from 'uuid' @@ -149,6 +150,28 @@ class _TestReporter extends WDIOReporter { } } + /** + * SDK-7843: mocha emits `fail` for a timed-out test while its body and wdio's `afterTest` are + * still pending, and with `bail` (or on the worker's last test) `after()` runs before that + * `afterTest`. On the CLI flow, report the failure now, from mocha's own result, so `after()` + * marks the session and closes the test with it. A normal failure is already reported by + * `afterTest` before mocha's `fail`, so this is a no-op for it. + */ + onTestFail(testStats: TestStats) { + if (this._config?.framework !== 'mocha' || !BrowserstackCLI.getInstance().isRunning()) { + return + } + const attempts = testStats.retries ?? 0 + finishCliTestOnFailure(`${testStats.parent} - ${testStats.title}`, { + passed: false, + error: testStats.error, + duration: testStats._duration, + retries: { attempts, limit: attempts }, + exception: testStats.error?.message ?? '', + status: 'failed' + }) + } + async onTestEnd(testStats: TestStats) { if (!this.needToSendData('test', 'end')) { return diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index 8854e15c..b61e6168 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -17,6 +17,7 @@ import type { BrowserstackConfig, BrowserstackOptions, MultiRemoteAction } from import type { Pickle, Feature, ITestCaseHookParameter, CucumberHook } from './cucumber-types.js' import InsightsHandler from './insights-handler.js' import TestReporter from './reporter.js' +import { awaitCliTestFinishesOnFailure, claimCliTestFinish, registerCliTestFinisher } from './cli/earlyTestFinish.js' import { DEFAULT_OPTIONS, NOT_ALLOWED_KEYS_IN_CAPS, PERF_MEASUREMENT_ENV } from './constants.js' import CrashReporter from './crash-reporter.js' import AccessibilityHandler from './accessibility-handler.js' @@ -625,6 +626,12 @@ export default class BrowserstackService implements Services.ServiceInstance { // this test reports its own finish (incl. runtime `this.skip()`), so the // skip reporter must never re-report it from onTestSkip markTestStarted(getUniqueIdentifier(test, this._config.framework)) + // SDK-7843: this test's finish is owed from here on. Normally afterTest reports it; if + // the test times out, mocha reports the failure to the reporter first and the reporter + // reports it (see cli/earlyTestFinish.ts). + if (this._config.framework === 'mocha') { + registerCliTestFinisher(getUniqueIdentifier(test, this._config.framework), (result) => this.finishCliTest(test, result)) + } this._insightsHandler?.setTestData(test, uuid) await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) return @@ -653,27 +660,13 @@ export default class BrowserstackService implements Services.ServiceInstance { } if (BrowserstackCLI.getInstance().isRunning()) { - // the CLI test-finish reads test_uuid from the single mutable per-worker - // tracked instance, which a later INIT_TEST may have overwritten with the NEXT test's - // uuid. `test` is `originalTest` — already the correct (timed-out) identity, snapshotted - // pre-await by the testFnWrapper — so restore THAT test's minted uuid onto the tracked - // instance so the POST carries it and the binary closes the correct test_run. Without - // this, the finish would carry the next test's uuid and orphan the finishing one. - if (this._config.framework === 'mocha') { - const identifier = getUniqueIdentifier(test, this._config.framework) - const resolvedUuid = this._cliTestUuids.get(identifier) - if (resolvedUuid) { - const trackedInstance = TestFramework.getTrackedInstance() - if (trackedInstance) { - TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) - } - // Clean up so the per-worker map does not grow across the run. - this._cliTestUuids.delete(identifier) - } + if (this._config.framework === 'mocha' && !claimCliTestFinish(getUniqueIdentifier(test, this._config.framework))) { + // SDK-7843: the test timed out, and the reporter already reported its failure when + // mocha did; reporting it again here would arrive after after() anyway. + BStackLogger.debug(`afterTest: '${getUniqueIdentifier(test, this._config.framework)}' was already reported when mocha failed it`) + return } - await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) - await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) - await this.reportBailSkippedTests(test, results) + await this.finishCliTest(test, results) return } @@ -682,6 +675,35 @@ export default class BrowserstackService implements Services.ServiceInstance { await this._percyHandler?.afterTest() } + /** + * Report a mocha test's finish on the CLI flow: its result, its TEST/POST, and the bail cascade. + * Called exactly once per test, from afterTest or (when the test timed out) from the reporter + * when mocha failed it (SDK-7843). + */ + private async finishCliTest(test: Frameworks.Test, results: Frameworks.TestResult) { + // the CLI test-finish reads test_uuid from the single mutable per-worker + // tracked instance, which a later INIT_TEST may have overwritten with the NEXT test's + // uuid. `test` is `originalTest` — already the correct (timed-out) identity, snapshotted + // pre-await by the testFnWrapper — so restore THAT test's minted uuid onto the tracked + // instance so the POST carries it and the binary closes the correct test_run. Without + // this, the finish would carry the next test's uuid and orphan the finishing one. + if (this._config.framework === 'mocha') { + const identifier = getUniqueIdentifier(test, this._config.framework) + const resolvedUuid = this._cliTestUuids.get(identifier) + if (resolvedUuid) { + const trackedInstance = TestFramework.getTrackedInstance() + if (trackedInstance) { + TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) + } + // Clean up so the per-worker map does not grow across the run. + this._cliTestUuids.delete(identifier) + } + } + await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) + await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) + await this.reportBailSkippedTests(test, results) + } + /** * Whether this failure will be retried, in which case mocha has not dropped anything yet and * the tests after it are still going to run. @@ -764,6 +786,15 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (skipDrainErr) { BStackLogger.debug(`Exception draining skip reports in after(): ${util.format(skipDrainErr)}`) } + // SDK-7843: a test that timed out was reported by the reporter when mocha failed it, + // which can still be in flight. Wait for it before the flush below (its TEST/POST is + // deferred into that stash) and before EXECUTE/POST, which marks the session status + // from the results recorded so far. + try { + await awaitCliTestFinishesOnFailure() + } catch (finishErr) { + BStackLogger.debug(`Exception awaiting failed-test finishes in after(): ${util.format(finishErr)}`) + } // Flush a test-finish event deferred past the after-each hook window — the last // test of the worker has no next-test boundary to trigger the flush. Must run // before worker teardown so the event isn't dropped. diff --git a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts new file mode 100644 index 00000000..fd5c35b8 --- /dev/null +++ b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts @@ -0,0 +1,71 @@ +import path from 'node:path' +import { describe, expect, it, vi, beforeEach } from 'vitest' +import type { Frameworks } from '@wdio/types' + +import { + awaitCliTestFinishesOnFailure, + claimCliTestFinish, + finishCliTestOnFailure, + registerCliTestFinisher, + resetCliTestFinishers +} from '../../src/cli/earlyTestFinish.js' +import * as bstackLogger from '../../src/bstackLogger.js' + +vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +const failed = { passed: false, error: new Error('Timeout of 300000ms exceeded.'), duration: 300000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult + +describe('SDK-7843 — a mocha test finish is reported exactly once, by whichever comes first', () => { + beforeEach(() => { + resetCliTestFinishers() + }) + + it('reports a timed-out test when mocha fails it, and the late afterTest then stands down', async () => { + const finisher = vi.fn().mockResolvedValue(undefined) + registerCliTestFinisher('Suite - times out', finisher) + + expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) + await awaitCliTestFinishesOnFailure() + + expect(finisher).toHaveBeenCalledOnce() + expect(finisher).toHaveBeenCalledWith(failed) + // wdio's afterTest for the same test arrives after after(); it must not report it again + expect(claimCliTestFinish('Suite - times out')).toBe(false) + }) + + it('leaves a normal failure to afterTest, which runs before mocha reports it', () => { + const finisher = vi.fn().mockResolvedValue(undefined) + registerCliTestFinisher('Suite - fails normally', finisher) + + expect(claimCliTestFinish('Suite - fails normally')).toBe(true) + expect(finishCliTestOnFailure('Suite - fails normally', failed)).toBe(false) + expect(finisher).not.toHaveBeenCalled() + }) + + it('keeps afterTest responsible for a test that was never registered', () => { + expect(claimCliTestFinish('Suite - never registered')).toBe(true) + expect(finishCliTestOnFailure('Suite - never registered', failed)).toBe(false) + }) + + it('makes after() wait for a finish that is still in flight', async () => { + let done = false + registerCliTestFinisher('Suite - slow finish', () => new Promise((resolve) => setTimeout(() => { + done = true + resolve() + }, 100))) + + finishCliTestOnFailure('Suite - slow finish', failed) + await awaitCliTestFinishesOnFailure() + + expect(done).toBe(true) + }) + + it('does not let a failing finish break after()', async () => { + registerCliTestFinisher('Suite - finish throws', () => Promise.reject(new Error('gRPC down'))) + + finishCliTestOnFailure('Suite - finish throws', failed) + + await expect(awaitCliTestFinishesOnFailure()).resolves.toBeUndefined() + }) +}) diff --git a/packages/browserstack-service/tests/reporter.onTestFail.test.ts b/packages/browserstack-service/tests/reporter.onTestFail.test.ts new file mode 100644 index 00000000..d7a2b6e7 --- /dev/null +++ b/packages/browserstack-service/tests/reporter.onTestFail.test.ts @@ -0,0 +1,58 @@ +import path from 'node:path' +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' + +import TestReporter from '../src/reporter.js' +import { BrowserstackCLI } from '../src/cli/index.js' +import * as earlyTestFinish from '../src/cli/earlyTestFinish.js' +import * as bstackLogger from '../src/bstackLogger.js' + +vi.mock('@wdio/reporter', () => import(path.join(process.cwd(), '__mocks__', '@wdio/reporter'))) +vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) +vi.mock('../src/cli/earlyTestFinish.js', () => ({ finishCliTestOnFailure: vi.fn().mockReturnValue(true) })) +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +describe('reporter onTestFail — hands mocha\'s failure to the CLI finish (SDK-7843)', () => { + const timeout = new Error('Timeout of 300000ms exceeded. The execution in the test took too long.') + const testStats = { title: 'should navigate via bottom nav', parent: 'Smoke: Home Navigation', error: timeout, _duration: 300004, retries: 0 } + + const makeReporter = (framework: string) => { + const reporter = new TestReporter({}) + ;(reporter as unknown as { _config: unknown })._config = { framework } + return reporter + } + + beforeEach(() => { + vi.mocked(earlyTestFinish.finishCliTestOnFailure).mockClear() + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + it('reports a mocha failure on the CLI flow under the same identity the service registered', () => { + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true } as never) + + makeReporter('mocha').onTestFail(testStats as never) + + expect(earlyTestFinish.finishCliTestOnFailure).toHaveBeenCalledWith( + 'Smoke: Home Navigation - should navigate via bottom nav', + expect.objectContaining({ passed: false, error: timeout, duration: 300004, status: 'failed', exception: timeout.message }) + ) + }) + + it('does nothing on the classic flow, which sets the session status from after(result)', () => { + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => false } as never) + + makeReporter('mocha').onTestFail(testStats as never) + + expect(earlyTestFinish.finishCliTestOnFailure).not.toHaveBeenCalled() + }) + + it('does nothing for other frameworks, whose afterTest is not run after after()', () => { + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true } as never) + + makeReporter('cucumber').onTestFail(testStats as never) + + expect(earlyTestFinish.finishCliTestOnFailure).not.toHaveBeenCalled() + }) +}) diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts new file mode 100644 index 00000000..e6e751d6 --- /dev/null +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -0,0 +1,109 @@ +import path from 'node:path' +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import type { Frameworks } from '@wdio/types' + +import BrowserstackService from '../src/service.js' +import { BrowserstackCLI } from '../src/cli/index.js' +import TestFramework from '../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' +import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' +import { HookState } from '../src/cli/states/hookState.js' +import { finishCliTestOnFailure, resetCliTestFinishers } from '../src/cli/earlyTestFinish.js' +import * as bstackLogger from '../src/bstackLogger.js' + +vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +/** + * SDK-7843 — with a mocha timeout, mocha fails the test (and tells reporters) while its body and + * wdio's afterTest are still pending; with `bail`, wdio then runs after() before that afterTest. + * These drive the service hooks in exactly that order. + */ +describe('service — a timed-out mocha test is finished when mocha fails it (SDK-7843)', () => { + let events: string[] + let testTrackEvent: ReturnType + let flush: ReturnType + + const timedOutTest = { title: 'times out', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test + const failed = { passed: false, error: new Error('Timeout of 300000ms exceeded.'), duration: 300000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult + + const makeService = () => new BrowserstackService( + { testObservability: false } as never, + [] as never, + { user: 'foo', key: 'bar', framework: 'mocha', mochaOpts: { bail: true } } as never + ) + + beforeEach(() => { + resetCliTestFinishers() + events = [] + // gRPC sends take real time; an instant mock would hide after() not waiting for the finish + testTrackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown, args: { result?: Frameworks.TestResult }) => { + await new Promise((resolve) => setTimeout(resolve, 30)) + events.push(`${String(state)}/${String(hook)}${args?.result ? ` passed=${args.result.passed}` : ''}`) + }) + flush = vi.fn().mockImplementation(async () => { + events.push('flushPendingTestFinishEvent') + }) + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ + isRunning: () => true, + getTestFramework: () => ({ trackEvent: testTrackEvent }), + getAutomationFramework: () => ({ + trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + events.push(`${String(state)}/${String(hook)}`) + }) + }), + modules: { TestHubModule: { flushPendingTestFinishEvent: flush } } + } as never) + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as never) + vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid-timed-out' as never) + vi.spyOn(TestFramework, 'setState').mockImplementation(() => {}) + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + it('reports the failure, then marks the session, then ignores the late afterTest', async () => { + const service = makeService() + await service.beforeTest(timedOutTest) + events.length = 0 + + // mocha's `fail` reaches the reporter first... + expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) + // ...then wdio runs after() before the timed-out test's afterTest + await service.after(1) + // ...and only then the late afterTest + await service.afterTest(timedOutTest, undefined as never, { ...failed }) + + const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false`) + const flushAt = events.indexOf('flushPendingTestFinishEvent') + const sessionStatusAt = events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`) + expect(testPost).toBeGreaterThanOrEqual(0) + // the failure is recorded before the deferred-finish flush and before EXECUTE/POST, + // which is where AutomateModule marks the session status + expect(testPost).toBeLessThan(flushAt) + expect(flushAt).toBeLessThan(sessionStatusAt) + // reported once: the late afterTest added no second LOG_REPORT/TEST POST + expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + expect(events.filter((e) => e.startsWith(`${TestFrameworkState.LOG_REPORT}/${HookState.POST}`))).toHaveLength(1) + }) + + it('still reports a normal failure from afterTest, and the reporter then does nothing', async () => { + const service = makeService() + await service.beforeTest(timedOutTest) + events.length = 0 + + await service.afterTest(timedOutTest, undefined as never, { ...failed }) + expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(false) + + expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + }) + + it('reports afterTest for a test it never saw start, as before', async () => { + const service = makeService() + + await service.afterTest({ title: 'unseen', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test, undefined as never, { passed: true } as Frameworks.TestResult) + + expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + }) +}) From 937350bfb2cceb00e53a5070875a45d7990d4055 Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" <41898282+github-actions[bot]@users.noreply.github.com> Date: Wed, 7 Oct 2026 05:50:56 +0000 Subject: [PATCH 2/9] chore(changeset): auto-generate from PR template (patch) --- .changeset/pr-272.md | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 .changeset/pr-272.md diff --git a/.changeset/pr-272.md b/.changeset/pr-272.md new file mode 100644 index 00000000..7a204751 --- /dev/null +++ b/.changeset/pr-272.md @@ -0,0 +1,5 @@ +--- +"@wdio/browserstack-service": patch +--- + +- Fixed mocha tests that fail by exceeding their timeout being marked "passed" on the Automate / App Automate dashboard, and their builds ending as "timeout" in Test Reporting about an hour after the run. Such tests are now reported as failed, with the timeout error as the reason. From 998e371a634180b286cf7ffb2a71e3d65470559b Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 16:18:23 +0530 Subject: [PATCH 3/9] fix(cli): drop a log written before the first mocha hook instead of logging an ERROR (SDK-7843) Console output from wdio's `before` hook reaches trackEvent(LOG, POST) before mocha's first hook, when no test or hook instance exists, so resolveInstance printed "resolveInstance: unable to resolve/create instance ... LOG POST" on every worker. Drop it at debug level, as the classic path does. Same change as #264. Co-Authored-By: Claude Opus 5.5 --- .../cli/frameworks/wdioMochaTestFramework.ts | 9 +++ .../wdioMochaTestFramework.preTestLog.test.ts | 56 +++++++++++++++++++ 2 files changed, 65 insertions(+) create mode 100644 packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index 8a885982..8bc2be62 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -55,6 +55,15 @@ export default class WdioMochaTestFramework extends TestFramework { logger.info(`trackEvent: testFrameworkState=${testFrameworkState} hookState=${hookState}`) await super.trackEvent(testFrameworkState, hookState, args) + // Console output from wdio's `before` hook (after the service has patched console) + // arrives before mocha's first hook, so there is no test or hook to attach it to yet and + // resolveInstance cannot create one for LOG. The classic path drops such a log silently; do the same instead of + // printing an ERROR on every worker (SDK-7843). + if (testFrameworkState === TestFrameworkState.LOG && !TestFramework.getTrackedInstance()) { + logger.debug(`trackEvent: no test or hook started yet, dropping log for testFrameworkState=${testFrameworkState} hookState=${hookState}`) + return + } + const instance = this.resolveInstance(testFrameworkState, hookState, args) if (instance === null) { logger.error(`trackEvent: instance not found for testFrameworkState=${testFrameworkState} hookState=${hookState}`) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts new file mode 100644 index 00000000..1ee5a019 --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts @@ -0,0 +1,56 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import * as bstackLogger from '../../src/bstackLogger.js' + +import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramework.js' +import TestFramework from '../../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +describe('SDK-7843 — a log written before the first mocha hook is dropped quietly', () => { + let framework: WdioMochaTestFramework + let errorSpy: ReturnType + + beforeEach(() => { + framework = new WdioMochaTestFramework(['WebdriverIO', 'mocha'], {}, 'bin-session-id') + errorSpy = vi.spyOn(cliLogger, 'error').mockImplementation(() => {}) + vi.spyOn(cliLogger, 'info').mockImplementation(() => {}) + vi.spyOn(cliLogger, 'debug').mockImplementation(() => {}) + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + it('does not log an ERROR for console output from wdio\'s `before` hook', async () => { + // wdio's `before` runs before mocha's `before all`, so no instance is tracked yet. + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue(null as any) + const resolveSpy = vi.spyOn(framework, 'resolveInstance') + + await framework.trackEvent(TestFrameworkState.LOG, HookState.POST, { + logEntry: { kind: 'TEST_LOG', message: '[SelfHealer] Installed', level: 'info', timestamp: new Date().toISOString() } + }) + + expect(errorSpy).not.toHaveBeenCalled() + expect(resolveSpy).not.toHaveBeenCalled() + }) + + it('still resolves the instance for a log once a test or hook is tracked', async () => { + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as any) + const resolveSpy = vi.spyOn(framework, 'resolveInstance').mockReturnValue(null) + + await framework.trackEvent(TestFrameworkState.LOG, HookState.POST, { logEntry: {} }) + + expect(resolveSpy).toHaveBeenCalledOnce() + }) + + it('still reports a missing instance for non-log events', async () => { + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue(null as any) + + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, {}) + + expect(errorSpy).toHaveBeenCalledWith(expect.stringContaining('resolveInstance: unable to resolve/create instance')) + }) +}) From f495501e5e5917c37d67c026118a0d7ce88a7b82 Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" <41898282+github-actions[bot]@users.noreply.github.com> Date: Wed, 7 Oct 2026 10:49:30 +0000 Subject: [PATCH 4/9] chore(changeset): auto-generate from PR template (patch) --- .changeset/pr-272.md | 1 + 1 file changed, 1 insertion(+) diff --git a/.changeset/pr-272.md b/.changeset/pr-272.md index 7a204751..415d660b 100644 --- a/.changeset/pr-272.md +++ b/.changeset/pr-272.md @@ -3,3 +3,4 @@ --- - Fixed mocha tests that fail by exceeding their timeout being marked "passed" on the Automate / App Automate dashboard, and their builds ending as "timeout" in Test Reporting about an hour after the run. Such tests are now reported as failed, with the timeout error as the reason. +- Removed the `resolveInstance: unable to resolve/create instance ... LOG POST` error printed when a wdio `before` hook writes to the console. From 7c9e8c09e9ec4d53f64e2343b35c3bb179f3867a Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 18:19:13 +0530 Subject: [PATCH 5/9] fix(cli): address review on the timed-out mocha test finish (SDK-7843) - Finish a test mocha already failed from after() when no reporter claimed it, using mocha's own runnable, so the fix holds with Test Reporting, Accessibility and Percy all off (the reporter is only registered when Test Hub events are on). - Key the finish hand-off and the uuid snapshot per retry attempt, so a retried attempt's late afterTest closes that attempt and not the next one. - Pin the test's uuid again right before TEST/POST, since mocha moves on while a finish started on failure awaits LOG_REPORT, then hand the slot back to the test now running. - Drop the try/catch around awaitCliTestFinishesOnFailure(); every finish catches its own error. - Tests: no reporter, retries, bail cascade from the reporter path, uuid re-pin. Co-Authored-By: Claude Opus 5.5 --- .../src/cli/earlyTestFinish.ts | 76 ++++++++---- packages/browserstack-service/src/reporter.ts | 5 +- packages/browserstack-service/src/service.ts | 73 +++++++---- .../tests/cli/earlyTestFinish.test.ts | 46 +++++++ .../tests/reporter.onTestFail.test.ts | 16 ++- .../tests/service.timedOutTestFinish.test.ts | 117 ++++++++++++++++-- 6 files changed, 270 insertions(+), 63 deletions(-) diff --git a/packages/browserstack-service/src/cli/earlyTestFinish.ts b/packages/browserstack-service/src/cli/earlyTestFinish.ts index c37001f6..518eb10f 100644 --- a/packages/browserstack-service/src/cli/earlyTestFinish.ts +++ b/packages/browserstack-service/src/cli/earlyTestFinish.ts @@ -14,54 +14,86 @@ import { BStackLogger } from '../bstackLogger.js' * is stranded until Test Hub reaps the build as `timeout`. The classic flow never had this, because * it reads the session status from `after(result)` — mocha's own failure count. * - * So the service registers a finisher per running test in `beforeTest`; whichever comes first — - * `afterTest` (normal case) or the reporter's `onTestFail` (timeout case) — claims it and reports - * the finish exactly once. `after()` awaits any finish the reporter started. + * So the service registers a finisher per running test attempt in `beforeTest`; whichever comes + * first — `afterTest` (normal case) or the reporter's `onTestFail` (timeout case) — claims it and + * reports the finish exactly once. The reporter is only registered when Test Hub events are on, so + * `after()` also finishes any test mocha already failed that nobody claimed, from mocha's own + * runnable, and then awaits every finish started here. */ type CliTestFinisher = (result: Frameworks.TestResult) => Promise -const finishers = new Map() -/** Tests the reporter already finished; their late afterTest must not report them again. */ +/** The live mocha runnable of an attempt; mocha sets `state` before it emits `fail`. */ +interface MochaRunnable { + state?: string + timedOut?: boolean + duration?: number + timeout?: () => number +} + +const finishers = new Map() +/** Attempts the reporter already finished; their late afterTest must not report them again. */ const reportedOnFailure = new Set() const inFlight = new Set>() -/** beforeTest: this test's finish is now owed, by afterTest or by the reporter. */ -export function registerCliTestFinisher(identifier: string, finisher: CliTestFinisher): void { - finishers.set(identifier, finisher) +/** + * Key one attempt of a test. With mocha retries, a timed-out attempt's late afterTest can arrive + * while the next attempt of the same test is running, so the hand-off must not be shared between + * attempts. The service reads the attempt from mocha's `_currentRetry`, the reporter from + * `TestStats.retries`; both count retries of this test so far. + */ +export function cliTestAttemptKey(identifier: string, attempt?: number): string { + return attempt ? `${identifier} (retry ${attempt})` : identifier +} + +/** beforeTest: this attempt's finish is now owed, by afterTest or by the reporter. */ +export function registerCliTestFinisher(key: string, finisher: CliTestFinisher, runnable?: MochaRunnable): void { + finishers.set(key, { finisher, runnable }) } /** - * afterTest: claim the finish. Returns false only when the reporter already reported it (the + * afterTest: claim the finish. Returns false only when it was already reported on failure (the * test timed out), in which case afterTest must not report it again. A test that was never * registered still belongs to afterTest. */ -export function claimCliTestFinish(identifier: string): boolean { - finishers.delete(identifier) - return !reportedOnFailure.delete(identifier) +export function claimCliTestFinish(key: string): boolean { + finishers.delete(key) + return !reportedOnFailure.delete(key) } /** - * Reporter `onTestFail`: if afterTest has not reported this test yet, report its failure now, + * Reporter `onTestFail`: if afterTest has not reported this attempt yet, report its failure now, * from mocha's own result. Returns whether a finish was started. */ -export function finishCliTestOnFailure(identifier: string, result: Frameworks.TestResult): boolean { - const finisher = finishers.get(identifier) - if (!finisher) { +export function finishCliTestOnFailure(key: string, result: Frameworks.TestResult): boolean { + const entry = finishers.get(key) + if (!entry) { return false } - finishers.delete(identifier) - reportedOnFailure.add(identifier) - BStackLogger.debug(`finishCliTestOnFailure: mocha reported '${identifier}' failed before its afterTest; reporting the finish now`) - const work = finisher(result).catch((err: unknown) => { - BStackLogger.debug(`finishCliTestOnFailure: reporting '${identifier}' failed: ${util.format(err)}`) + finishers.delete(key) + reportedOnFailure.add(key) + BStackLogger.debug(`finishCliTestOnFailure: mocha reported '${key}' failed before its afterTest; reporting the finish now`) + const work = entry.finisher(result).catch((err: unknown) => { + BStackLogger.debug(`finishCliTestOnFailure: reporting '${key}' failed: ${util.format(err)}`) }) inFlight.add(work) work.finally(() => inFlight.delete(work)) return true } -/** after(): wait for finishes the reporter started, before the session status and the flush. */ +/** + * after(): finish every attempt mocha already failed that neither afterTest nor the reporter + * claimed (no reporter registered), then wait for all finishes started on failure. Runs before + * the deferred-finish flush and before the session status is marked. + */ export async function awaitCliTestFinishesOnFailure(): Promise { + for (const [key, { runnable }] of [...finishers]) { + if (runnable?.state !== 'failed') { + continue + } + const ms = typeof runnable.timeout === 'function' ? runnable.timeout() : undefined + const error = new Error(runnable.timedOut && ms ? `Timeout of ${ms}ms exceeded.` : 'Test failed before its afterTest ran.') + finishCliTestOnFailure(key, { passed: false, error, duration: runnable.duration ?? 0, retries: { attempts: 0, limit: 0 }, exception: error.message, status: 'failed' }) + } while (inFlight.size > 0) { await Promise.all([...inFlight]) } diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index a91101f8..96edc4a2 100644 --- a/packages/browserstack-service/src/reporter.ts +++ b/packages/browserstack-service/src/reporter.ts @@ -5,7 +5,7 @@ import WDIOReporter from '@wdio/reporter' import type { Options, Frameworks } from '@wdio/types' import { BrowserstackCLI } from './cli/index.js' import { reportSkippedTest, resolveSpecFile } from './cli/skipReporter.js' -import { finishCliTestOnFailure } from './cli/earlyTestFinish.js' +import { cliTestAttemptKey, finishCliTestOnFailure } from './cli/earlyTestFinish.js' import * as url from 'node:url' import { v4 as uuidv4 } from 'uuid' @@ -162,7 +162,8 @@ class _TestReporter extends WDIOReporter { return } const attempts = testStats.retries ?? 0 - finishCliTestOnFailure(`${testStats.parent} - ${testStats.title}`, { + // `retries` is this test's retry count so far, i.e. the attempt mocha just failed + finishCliTestOnFailure(cliTestAttemptKey(`${testStats.parent} - ${testStats.title}`, attempts), { passed: false, error: testStats.error, duration: testStats._duration, diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index b61e6168..24707e63 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -17,7 +17,7 @@ import type { BrowserstackConfig, BrowserstackOptions, MultiRemoteAction } from import type { Pickle, Feature, ITestCaseHookParameter, CucumberHook } from './cucumber-types.js' import InsightsHandler from './insights-handler.js' import TestReporter from './reporter.js' -import { awaitCliTestFinishesOnFailure, claimCliTestFinish, registerCliTestFinisher } from './cli/earlyTestFinish.js' +import { awaitCliTestFinishesOnFailure, claimCliTestFinish, cliTestAttemptKey, registerCliTestFinisher } from './cli/earlyTestFinish.js' import { DEFAULT_OPTIONS, NOT_ALLOWED_KEYS_IN_CAPS, PERF_MEASUREMENT_ENV } from './constants.js' import CrashReporter from './crash-reporter.js' import AccessibilityHandler from './accessibility-handler.js' @@ -79,7 +79,7 @@ export default class BrowserstackService implements Services.ServiceInstance { * past the mocha timeout, the NEXT test's INIT_TEST overwrites the slot before the hung test's * afterTest POST fires, so the POST would carry the wrong (next) test's uuid and the binary * would close the wrong test_run — orphaning the hung one. We snapshot each test's uuid here, - * keyed by the same identity the legacy `_tests` map uses, and at afterTest we restore the + * keyed per attempt (cliTestAttemptKey over the identity the legacy `_tests` map uses), and at afterTest we restore the * finishing test's minted uuid onto the tracked instance before the POST so it closes the * correct test_run. The finishing identity is `originalTest` (already snapshotted pre-await by * the testFnWrapper, so it is the timed-out runnable's own identity, not the next test's). @@ -601,6 +601,9 @@ export default class BrowserstackService implements Services.ServiceInstance { @PerformanceTester.Measure(PERFORMANCE_SDK_EVENTS.EVENTS.SDK_HOOK, { hookType: 'beforeTest' }) async beforeTest (test: Frameworks.Test) { this._currentTest = test + // mocha's live runnable for this attempt; read before any await, since the suite's + // shared context moves on to the next runnable + const runnable = test.ctx?.test let suiteTitle = this._suiteTitle if (test.fullName) { @@ -619,9 +622,9 @@ export default class BrowserstackService implements Services.ServiceInstance { const uuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) // snapshot this test's freshly-minted uuid keyed by its identity, so a later // afterTest can restore it even after a subsequent INIT_TEST has overwritten the single - // mutable tracked-instance slot. Keyed exactly like the legacy `_tests` map. + // mutable tracked-instance slot. Keyed per attempt, so a retried attempt keeps its own. if (this._config.framework === 'mocha' && uuid) { - this._cliTestUuids.set(getUniqueIdentifier(test, this._config.framework), uuid as string) + this._cliTestUuids.set(this.cliAttemptKey(test), uuid as string) } // this test reports its own finish (incl. runtime `this.skip()`), so the // skip reporter must never re-report it from onTestSkip @@ -630,7 +633,7 @@ export default class BrowserstackService implements Services.ServiceInstance { // the test times out, mocha reports the failure to the reporter first and the reporter // reports it (see cli/earlyTestFinish.ts). if (this._config.framework === 'mocha') { - registerCliTestFinisher(getUniqueIdentifier(test, this._config.framework), (result) => this.finishCliTest(test, result)) + registerCliTestFinisher(this.cliAttemptKey(test), (result) => this.finishCliTest(test, result), runnable) } this._insightsHandler?.setTestData(test, uuid) await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) @@ -660,10 +663,10 @@ export default class BrowserstackService implements Services.ServiceInstance { } if (BrowserstackCLI.getInstance().isRunning()) { - if (this._config.framework === 'mocha' && !claimCliTestFinish(getUniqueIdentifier(test, this._config.framework))) { - // SDK-7843: the test timed out, and the reporter already reported its failure when - // mocha did; reporting it again here would arrive after after() anyway. - BStackLogger.debug(`afterTest: '${getUniqueIdentifier(test, this._config.framework)}' was already reported when mocha failed it`) + if (this._config.framework === 'mocha' && !claimCliTestFinish(this.cliAttemptKey(test))) { + // SDK-7843: the test timed out, and its failure was already reported when mocha + // failed it; reporting it again here would arrive after after() anyway. + BStackLogger.debug(`afterTest: '${this.cliAttemptKey(test)}' was already reported when mocha failed it`) return } await this.finishCliTest(test, results) @@ -687,23 +690,42 @@ export default class BrowserstackService implements Services.ServiceInstance { // pre-await by the testFnWrapper — so restore THAT test's minted uuid onto the tracked // instance so the POST carries it and the binary closes the correct test_run. Without // this, the finish would carry the next test's uuid and orphan the finishing one. + let resolvedUuid: string | undefined if (this._config.framework === 'mocha') { - const identifier = getUniqueIdentifier(test, this._config.framework) - const resolvedUuid = this._cliTestUuids.get(identifier) - if (resolvedUuid) { - const trackedInstance = TestFramework.getTrackedInstance() - if (trackedInstance) { - TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) - } - // Clean up so the per-worker map does not grow across the run. - this._cliTestUuids.delete(identifier) + const key = this.cliAttemptKey(test) + resolvedUuid = this._cliTestUuids.get(key) + // Clean up so the per-worker map does not grow across the run. + this._cliTestUuids.delete(key) + } + /** Put this test's uuid on the tracked instance; returns another test's uuid it replaced. */ + const pinUuid = (): unknown => { + const trackedInstance = TestFramework.getTrackedInstance() + if (!resolvedUuid || !trackedInstance) { + return undefined } + const current = TestFramework.getState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID) + TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) + return current && current !== resolvedUuid ? current : undefined } + pinUuid() await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) + // SDK-7843: when this finish was started on failure, mocha moved on during the await + // above, and the next test's INIT_TEST may have taken the slot. Pin this test's uuid again + // for its TEST/POST, then hand the slot back to the test now running. + const displacedUuid = pinUuid() await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) + const trackedInstance = TestFramework.getTrackedInstance() + if (displacedUuid && trackedInstance && TestFramework.getState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID) === resolvedUuid) { + TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, displacedUuid) + } await this.reportBailSkippedTests(test, results) } + /** One attempt of a mocha test; see cliTestAttemptKey. */ + private cliAttemptKey(test: Frameworks.Test): string { + return cliTestAttemptKey(getUniqueIdentifier(test, this._config.framework), (test as { _currentRetry?: number })._currentRetry) + } + /** * Whether this failure will be retried, in which case mocha has not dropped anything yet and * the tests after it are still going to run. @@ -786,15 +808,12 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (skipDrainErr) { BStackLogger.debug(`Exception draining skip reports in after(): ${util.format(skipDrainErr)}`) } - // SDK-7843: a test that timed out was reported by the reporter when mocha failed it, - // which can still be in flight. Wait for it before the flush below (its TEST/POST is - // deferred into that stash) and before EXECUTE/POST, which marks the session status - // from the results recorded so far. - try { - await awaitCliTestFinishesOnFailure() - } catch (finishErr) { - BStackLogger.debug(`Exception awaiting failed-test finishes in after(): ${util.format(finishErr)}`) - } + // SDK-7843: a test that timed out is finished when mocha failed it (or here, from + // mocha's runnable, when no reporter is registered), and that finish can still be in + // flight. Wait for it before the flush below (its TEST/POST is deferred into that + // stash) and before EXECUTE/POST, which marks the session status from the results + // recorded so far. Every finish catches its own error, so this cannot reject. + await awaitCliTestFinishesOnFailure() // Flush a test-finish event deferred past the after-each hook window — the last // test of the worker has no next-test boundary to trigger the flush. Must run // before worker teardown so the event isn't dropped. diff --git a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts index fd5c35b8..8b804025 100644 --- a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts +++ b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts @@ -5,6 +5,7 @@ import type { Frameworks } from '@wdio/types' import { awaitCliTestFinishesOnFailure, claimCliTestFinish, + cliTestAttemptKey, finishCliTestOnFailure, registerCliTestFinisher, resetCliTestFinishers @@ -68,4 +69,49 @@ describe('SDK-7843 — a mocha test finish is reported exactly once, by whicheve await expect(awaitCliTestFinishesOnFailure()).resolves.toBeUndefined() }) + + it('keeps each retry attempt separate, so a late afterTest of one attempt cannot claim the next', () => { + const first = vi.fn().mockResolvedValue(undefined) + const second = vi.fn().mockResolvedValue(undefined) + registerCliTestFinisher(cliTestAttemptKey('Suite - flaky', 0), first) + registerCliTestFinisher(cliTestAttemptKey('Suite - flaky', 1), second) + + // attempt 0 timed out and was retried (mocha emits `retry`, not `fail`); its afterTest arrives late + expect(claimCliTestFinish(cliTestAttemptKey('Suite - flaky', 0))).toBe(true) + // attempt 1 is still owed, and can still be reported when mocha fails it + expect(finishCliTestOnFailure(cliTestAttemptKey('Suite - flaky', 1), failed)).toBe(true) + expect(second).toHaveBeenCalledWith(failed) + expect(first).not.toHaveBeenCalled() + }) + + it('keys the first attempt by the plain identity', () => { + expect(cliTestAttemptKey('Suite - t', 0)).toBe('Suite - t') + expect(cliTestAttemptKey('Suite - t', undefined)).toBe('Suite - t') + expect(cliTestAttemptKey('Suite - t', 2)).toBe('Suite - t (retry 2)') + }) + + it('without a reporter, after() finishes a test mocha already failed, from mocha\'s runnable', async () => { + const finisher = vi.fn().mockResolvedValue(undefined) + registerCliTestFinisher('Suite - times out', finisher, { state: 'failed', timedOut: true, duration: 10002, timeout: () => 10000 }) + + await awaitCliTestFinishesOnFailure() + + expect(finisher).toHaveBeenCalledOnce() + const result = finisher.mock.calls[0][0] as Frameworks.TestResult + expect(result.passed).toBe(false) + expect(result.duration).toBe(10002) + expect((result.error as Error).message).toBe('Timeout of 10000ms exceeded.') + // its late afterTest then stands down + expect(claimCliTestFinish('Suite - times out')).toBe(false) + }) + + it('leaves a test mocha has not failed to its afterTest', async () => { + const finisher = vi.fn().mockResolvedValue(undefined) + registerCliTestFinisher('Suite - still running', finisher, { state: undefined }) + + await awaitCliTestFinishesOnFailure() + + expect(finisher).not.toHaveBeenCalled() + expect(claimCliTestFinish('Suite - still running')).toBe(true) + }) }) diff --git a/packages/browserstack-service/tests/reporter.onTestFail.test.ts b/packages/browserstack-service/tests/reporter.onTestFail.test.ts index d7a2b6e7..376d1a84 100644 --- a/packages/browserstack-service/tests/reporter.onTestFail.test.ts +++ b/packages/browserstack-service/tests/reporter.onTestFail.test.ts @@ -8,7 +8,10 @@ import * as bstackLogger from '../src/bstackLogger.js' vi.mock('@wdio/reporter', () => import(path.join(process.cwd(), '__mocks__', '@wdio/reporter'))) vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) -vi.mock('../src/cli/earlyTestFinish.js', () => ({ finishCliTestOnFailure: vi.fn().mockReturnValue(true) })) +vi.mock('../src/cli/earlyTestFinish.js', async (importOriginal) => ({ + ...(await importOriginal()), + finishCliTestOnFailure: vi.fn().mockReturnValue(true) +})) vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) describe('reporter onTestFail — hands mocha\'s failure to the CLI finish (SDK-7843)', () => { @@ -55,4 +58,15 @@ describe('reporter onTestFail — hands mocha\'s failure to the CLI finish (SDK- expect(earlyTestFinish.finishCliTestOnFailure).not.toHaveBeenCalled() }) + + it('reports a retried attempt under that attempt\'s key', () => { + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true } as never) + + makeReporter('mocha').onTestFail({ ...testStats, retries: 1 } as never) + + expect(earlyTestFinish.finishCliTestOnFailure).toHaveBeenCalledWith( + 'Smoke: Home Navigation - should navigate via bottom nav (retry 1)', + expect.objectContaining({ passed: false }) + ) + }) }) diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts index e6e751d6..c55ea90a 100644 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -8,7 +8,7 @@ import TestFramework from '../src/cli/frameworks/testFramework.js' import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' -import { finishCliTestOnFailure, resetCliTestFinishers } from '../src/cli/earlyTestFinish.js' +import { cliTestAttemptKey, finishCliTestOnFailure, resetCliTestFinishers } from '../src/cli/earlyTestFinish.js' import * as bstackLogger from '../src/bstackLogger.js' vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) @@ -23,8 +23,13 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD let events: string[] let testTrackEvent: ReturnType let flush: ReturnType + // the single tracked-instance slot the CLI reads the test uuid from + let slotUuid: string | undefined + let minted: number - const timedOutTest = { title: 'times out', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test + const makeTest = (title: string, extra: Record = {}) => + ({ title, parent: 'Suite', ctx: { test: {} }, ...extra }) as unknown as Frameworks.Test + const timedOutTest = makeTest('times out') const failed = { passed: false, error: new Error('Timeout of 300000ms exceeded.'), duration: 300000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult const makeService = () => new BrowserstackService( @@ -36,10 +41,19 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD beforeEach(() => { resetCliTestFinishers() events = [] + slotUuid = undefined + minted = 0 // gRPC sends take real time; an instant mock would hide after() not waiting for the finish - testTrackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown, args: { result?: Frameworks.TestResult }) => { + testTrackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown, args: { result?: Frameworks.TestResult, test?: Frameworks.Test }) => { + if (state === TestFrameworkState.INIT_TEST) { + slotUuid = `uuid-${++minted}` + return + } + // the CLI reads the uuid when the event is handled, before the send + const uuid = slotUuid await new Promise((resolve) => setTimeout(resolve, 30)) - events.push(`${String(state)}/${String(hook)}${args?.result ? ` passed=${args.result.passed}` : ''}`) + const result = args?.result ? ` ${args.result.skipped ? 'skipped' : `passed=${args.result.passed}`}` : '' + events.push(`${String(state)}/${String(hook)}${result}${state === TestFrameworkState.TEST && hook === HookState.POST ? ` ${args.test?.title} ${uuid}` : ''}`) }) flush = vi.fn().mockImplementation(async () => { events.push('flushPendingTestFinishEvent') @@ -55,14 +69,18 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD modules: { TestHubModule: { flushPendingTestFinishEvent: flush } } } as never) vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as never) - vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid-timed-out' as never) - vi.spyOn(TestFramework, 'setState').mockImplementation(() => {}) + vi.spyOn(TestFramework, 'getState').mockImplementation(() => slotUuid as never) + vi.spyOn(TestFramework, 'setState').mockImplementation((_instance: unknown, _key: unknown, value: unknown) => { + slotUuid = value as string + }) }) afterEach(() => { vi.restoreAllMocks() }) + const testPosts = () => events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`)) + it('reports the failure, then marks the session, then ignores the late afterTest', async () => { const service = makeService() await service.beforeTest(timedOutTest) @@ -75,7 +93,7 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD // ...and only then the late afterTest await service.afterTest(timedOutTest, undefined as never, { ...failed }) - const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false`) + const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out uuid-1`) const flushAt = events.indexOf('flushPendingTestFinishEvent') const sessionStatusAt = events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`) expect(testPost).toBeGreaterThanOrEqual(0) @@ -84,10 +102,87 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD expect(testPost).toBeLessThan(flushAt) expect(flushAt).toBeLessThan(sessionStatusAt) // reported once: the late afterTest added no second LOG_REPORT/TEST POST - expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + expect(testPosts()).toHaveLength(1) expect(events.filter((e) => e.startsWith(`${TestFrameworkState.LOG_REPORT}/${HookState.POST}`))).toHaveLength(1) }) + it('without a reporter, after() still finishes a test mocha failed, from mocha\'s runnable', async () => { + const service = makeService() + const runnable = { state: undefined as string | undefined, timedOut: false, timeout: () => 10000, duration: 0 } + const test = makeTest('times out unreported', { ctx: { test: runnable } }) + await service.beforeTest(test) + events.length = 0 + + // mocha's timeout: Runner#fail sets the state; no reporter hears the `fail` + Object.assign(runnable, { state: 'failed', timedOut: true, duration: 10001 }) + await service.after(1) + await service.afterTest(test, undefined as never, { ...failed }) + + const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out unreported uuid-1`) + expect(testPost).toBeGreaterThanOrEqual(0) + expect(testPost).toBeLessThan(events.indexOf('flushPendingTestFinishEvent')) + expect(testPost).toBeLessThan(events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`)) + expect(testPosts()).toHaveLength(1) + }) + + it('runs the bail cascade from the reporter path, before the flush', async () => { + const service = makeService() + const root: { title: string, tests: unknown[], suites: unknown[], parent?: unknown } = { title: '', tests: [], suites: [] } + const suite = { title: 'Suite', parent: root, tests: [] as unknown[], suites: [] } + root.suites.push(suite) + suite.tests.push({ title: 'never reached', parent: suite, state: undefined, file: '/spec.js', body: '' }) + const test = makeTest('times out with bail', { ctx: { test: { parent: suite } } }) + await service.beforeTest(test) + events.length = 0 + + expect(finishCliTestOnFailure('Suite - times out with bail', failed)).toBe(true) + await service.after(1) + + const failedAt = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out with bail uuid-1`) + const skippedAt = events.findIndex((e) => e.includes('skipped never reached')) + const flushAt = events.indexOf('flushPendingTestFinishEvent') + expect(failedAt).toBeGreaterThanOrEqual(0) + expect(skippedAt).toBeGreaterThan(failedAt) + expect(skippedAt).toBeLessThan(flushAt) + }) + + it('closes the timed-out test with its own uuid even when the next test took the slot meanwhile', async () => { + const service = makeService() + const next = makeTest('next test') + await service.beforeTest(timedOutTest) + events.length = 0 + + // the reporter starts the finish; mocha (no bail) moves on to the next test during its LOG_REPORT send + expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) + await service.beforeTest(next) + await new Promise((resolve) => setTimeout(resolve, 100)) + + expect(testPosts()).toEqual([`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out uuid-1`]) + // and the slot is handed back to the test now running + expect(slotUuid).toBe('uuid-2') + }) + + it('lets a retried attempt\'s late afterTest close that attempt, not the next one', async () => { + const service = makeService() + const attempt0 = makeTest('flaky', { _currentRetry: 0 }) + const attempt1 = makeTest('flaky', { _currentRetry: 1 }) + await service.beforeTest(attempt0) + // attempt 0 timed out and is retried (mocha emits `retry`, not `fail`); attempt 1 starts + await service.beforeTest(attempt1) + events.length = 0 + + // attempt 0's late afterTest + await service.afterTest(attempt0, undefined as never, { ...failed }) + // attempt 1 times out too: the reporter can still report it + expect(finishCliTestOnFailure(cliTestAttemptKey('Suite - flaky', 1), failed)).toBe(true) + await service.after(1) + + expect(testPosts()).toEqual([ + `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky uuid-1`, + `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky uuid-2` + ]) + }) + it('still reports a normal failure from afterTest, and the reporter then does nothing', async () => { const service = makeService() await service.beforeTest(timedOutTest) @@ -96,14 +191,14 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD await service.afterTest(timedOutTest, undefined as never, { ...failed }) expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(false) - expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + expect(testPosts()).toHaveLength(1) }) it('reports afterTest for a test it never saw start, as before', async () => { const service = makeService() - await service.afterTest({ title: 'unseen', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test, undefined as never, { passed: true } as Frameworks.TestResult) + await service.afterTest(makeTest('unseen'), undefined as never, { passed: true } as Frameworks.TestResult) - expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + expect(testPosts()).toHaveLength(1) }) }) From 092e69b5a3a3e31ae7d4ec8a6e0d142d0faedf2f Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 19:10:42 +0530 Subject: [PATCH 6/9] fix(cli): keep mocha's verdict for a late afterTest and the bail cascade (SDK-7843) - With no reporter, a timed-out test whose body finishes late gets an afterTest saying only whether the body threw. If mocha already failed that attempt, claimCliTestFinish now reports mocha's failure and afterTest stands down, instead of reporting it passed. - A finish started on failure runs after mocha moved on, so the suite's shared ctx.test points at a hook (which inherits the suite's retries) or the next test. Pass the runnable captured in beforeTest to hasRetryPending and the bail cascade, so the cascade is not skipped. - Hand the slot back after TEST/POST also when the first uuid pin displaced another test. - Wait for in-flight finishes in the uuid test instead of a fixed sleep. Co-Authored-By: Claude Opus 5.5 --- .../src/cli/earlyTestFinish.ts | 27 +++++++++---- packages/browserstack-service/src/service.ts | 26 ++++++------ .../tests/cli/earlyTestFinish.test.ts | 11 +++++ .../tests/service.timedOutTestFinish.test.ts | 40 ++++++++++++++++++- 4 files changed, 82 insertions(+), 22 deletions(-) diff --git a/packages/browserstack-service/src/cli/earlyTestFinish.ts b/packages/browserstack-service/src/cli/earlyTestFinish.ts index 518eb10f..74a4ea1e 100644 --- a/packages/browserstack-service/src/cli/earlyTestFinish.ts +++ b/packages/browserstack-service/src/cli/earlyTestFinish.ts @@ -50,12 +50,26 @@ export function registerCliTestFinisher(key: string, finisher: CliTestFinisher, finishers.set(key, { finisher, runnable }) } +/** The failure mocha recorded on an attempt's runnable (it keeps no error object on it). */ +function failureFromRunnable(runnable: MochaRunnable): Frameworks.TestResult { + const ms = typeof runnable.timeout === 'function' ? runnable.timeout() : undefined + const error = new Error(runnable.timedOut && ms ? `Timeout of ${ms}ms exceeded.` : 'Test failed before its afterTest ran.') + return { passed: false, error, duration: runnable.duration ?? 0, retries: { attempts: 0, limit: 0 }, exception: error.message, status: 'failed' } +} + /** - * afterTest: claim the finish. Returns false only when it was already reported on failure (the - * test timed out), in which case afterTest must not report it again. A test that was never - * registered still belongs to afterTest. + * afterTest: claim the finish. Returns false when the attempt is reported on failure instead — + * already by the reporter, or now, because mocha already failed it (a timed-out test whose body + * finished late, with no reporter registered). wdio's result for such a body says only whether + * the body threw, not that mocha timed it out. In both cases afterTest must not report it. + * A normal failure is untouched: its afterTest runs before mocha marks the runnable failed. + * A test that was never registered still belongs to afterTest. */ export function claimCliTestFinish(key: string): boolean { + const runnable = finishers.get(key)?.runnable + if (runnable?.state === 'failed') { + finishCliTestOnFailure(key, failureFromRunnable(runnable)) + } finishers.delete(key) return !reportedOnFailure.delete(key) } @@ -87,12 +101,9 @@ export function finishCliTestOnFailure(key: string, result: Frameworks.TestResul */ export async function awaitCliTestFinishesOnFailure(): Promise { for (const [key, { runnable }] of [...finishers]) { - if (runnable?.state !== 'failed') { - continue + if (runnable?.state === 'failed') { + finishCliTestOnFailure(key, failureFromRunnable(runnable)) } - const ms = typeof runnable.timeout === 'function' ? runnable.timeout() : undefined - const error = new Error(runnable.timedOut && ms ? `Timeout of ${ms}ms exceeded.` : 'Test failed before its afterTest ran.') - finishCliTestOnFailure(key, { passed: false, error, duration: runnable.duration ?? 0, retries: { attempts: 0, limit: 0 }, exception: error.message, status: 'failed' }) } while (inFlight.size > 0) { await Promise.all([...inFlight]) diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index 24707e63..00a148ae 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -633,7 +633,7 @@ export default class BrowserstackService implements Services.ServiceInstance { // the test times out, mocha reports the failure to the reporter first and the reporter // reports it (see cli/earlyTestFinish.ts). if (this._config.framework === 'mocha') { - registerCliTestFinisher(this.cliAttemptKey(test), (result) => this.finishCliTest(test, result), runnable) + registerCliTestFinisher(this.cliAttemptKey(test), (result) => this.finishCliTest(test, result, runnable), runnable) } this._insightsHandler?.setTestData(test, uuid) await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) @@ -680,10 +680,11 @@ export default class BrowserstackService implements Services.ServiceInstance { /** * Report a mocha test's finish on the CLI flow: its result, its TEST/POST, and the bail cascade. - * Called exactly once per test, from afterTest or (when the test timed out) from the reporter - * when mocha failed it (SDK-7843). + * Called exactly once per test, from afterTest or (when the test timed out) when mocha failed + * it (SDK-7843). That second path runs after mocha has moved on, so it passes the runnable + * captured in beforeTest; the suite's shared `test.ctx.test` then points at a hook or the next test. */ - private async finishCliTest(test: Frameworks.Test, results: Frameworks.TestResult) { + private async finishCliTest(test: Frameworks.Test, results: Frameworks.TestResult, runnable?: unknown) { // the CLI test-finish reads test_uuid from the single mutable per-worker // tracked instance, which a later INIT_TEST may have overwritten with the NEXT test's // uuid. `test` is `originalTest` — already the correct (timed-out) identity, snapshotted @@ -707,18 +708,18 @@ export default class BrowserstackService implements Services.ServiceInstance { TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) return current && current !== resolvedUuid ? current : undefined } - pinUuid() + const displacedFirst = pinUuid() await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) // SDK-7843: when this finish was started on failure, mocha moved on during the await // above, and the next test's INIT_TEST may have taken the slot. Pin this test's uuid again // for its TEST/POST, then hand the slot back to the test now running. - const displacedUuid = pinUuid() + const displacedUuid = pinUuid() ?? displacedFirst await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) const trackedInstance = TestFramework.getTrackedInstance() if (displacedUuid && trackedInstance && TestFramework.getState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID) === resolvedUuid) { TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, displacedUuid) } - await this.reportBailSkippedTests(test, results) + await this.reportBailSkippedTests(test, results, runnable) } /** One attempt of a mocha test; see cliTestAttemptKey. */ @@ -736,8 +737,8 @@ export default class BrowserstackService implements Services.ServiceInstance { * runnable state for that case, otherwise the cascade fires on the first attempt and reports * tests as skipped that the retry then actually runs. */ - private hasRetryPending(test: Frameworks.Test, results: Frameworks.TestResult): boolean { - const mochaTest = test.ctx?.test as { currentRetry?: () => number, retries?: () => number } | undefined + private hasRetryPending(test: Frameworks.Test, results: Frameworks.TestResult, runnable?: unknown): boolean { + const mochaTest = (runnable ?? test.ctx?.test) as { currentRetry?: () => number, retries?: () => number } | undefined if (typeof mochaTest?.currentRetry === 'function' && typeof mochaTest.retries === 'function') { if (mochaTest.currentRetry() < mochaTest.retries()) { return true @@ -756,18 +757,19 @@ export default class BrowserstackService implements Services.ServiceInstance { * it is handed to one mocha instance. Cascading across them is still correct: bail aborts that * whole runner, so those tests do not run either. */ - private async reportBailSkippedTests(test: Frameworks.Test, results: Frameworks.TestResult) { + private async reportBailSkippedTests(test: Frameworks.Test, results: Frameworks.TestResult, runnable?: unknown) { if (!this._mochaBail || results.passed || results.skipped) { return } try { // inside the boundary: hasRetryPending reaches into mocha's own runnable, which this // SDK does not own - if (this.hasRetryPending(test, results)) { + if (this.hasRetryPending(test, results, runnable)) { return } const framework = BrowserstackCLI.getInstance().getTestFramework() - let suite = test.ctx?.test?.parent + const mochaTest: typeof test.ctx = runnable ?? test.ctx?.test + let suite = mochaTest?.parent if (!framework || !suite) { return } diff --git a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts index 8b804025..2c5df3b0 100644 --- a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts +++ b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts @@ -114,4 +114,15 @@ describe('SDK-7843 — a mocha test finish is reported exactly once, by whicheve expect(finisher).not.toHaveBeenCalled() expect(claimCliTestFinish('Suite - still running')).toBe(true) }) + + it('a late afterTest of an attempt mocha already failed reports the failure instead (no reporter)', async () => { + const finisher = vi.fn().mockResolvedValue(undefined) + registerCliTestFinisher('Suite - times out', finisher, { state: 'failed', timedOut: true, duration: 10002, timeout: () => 10000 }) + + expect(claimCliTestFinish('Suite - times out')).toBe(false) + await awaitCliTestFinishesOnFailure() + + expect(finisher).toHaveBeenCalledOnce() + expect((finisher.mock.calls[0][0] as Frameworks.TestResult).passed).toBe(false) + }) }) diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts index c55ea90a..abd665d0 100644 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -8,7 +8,7 @@ import TestFramework from '../src/cli/frameworks/testFramework.js' import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' -import { cliTestAttemptKey, finishCliTestOnFailure, resetCliTestFinishers } from '../src/cli/earlyTestFinish.js' +import { awaitCliTestFinishesOnFailure, cliTestAttemptKey, finishCliTestOnFailure, resetCliTestFinishers } from '../src/cli/earlyTestFinish.js' import * as bstackLogger from '../src/bstackLogger.js' vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) @@ -155,7 +155,7 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD // the reporter starts the finish; mocha (no bail) moves on to the next test during its LOG_REPORT send expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) await service.beforeTest(next) - await new Promise((resolve) => setTimeout(resolve, 100)) + await awaitCliTestFinishesOnFailure() expect(testPosts()).toEqual([`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out uuid-1`]) // and the slot is handed back to the test now running @@ -201,4 +201,40 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD expect(testPosts()).toHaveLength(1) }) + + it('without a reporter, a timed-out test whose body finishes late is still reported failed', async () => { + const service = makeService() + const runnable = { state: undefined as string | undefined, timedOut: false, timeout: () => 10000, duration: 0 } + const test = makeTest('times out then succeeds', { ctx: { test: runnable } }) + await service.beforeTest(test) + events.length = 0 + + // mocha times it out (no reporter hears it); the body then succeeds, so wdio's late + // afterTest says passed — before after() runs + Object.assign(runnable, { state: 'failed', timedOut: true, duration: 10001 }) + await service.afterTest(test, undefined as never, { passed: true } as Frameworks.TestResult) + await service.after(1) + + expect(testPosts()).toEqual([`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out then succeeds uuid-1`]) + }) + + it('runs the bail cascade from the runnable it captured, not the hook mocha moved on to', async () => { + const service = makeService() + const root: { title: string, tests: unknown[], suites: unknown[] } = { title: '', tests: [], suites: [] } + const suite = { title: 'Suite', parent: root, tests: [] as unknown[], suites: [] } + root.suites.push(suite) + suite.tests.push({ title: 'dropped by bail', parent: suite, state: undefined, file: '/spec.js', body: '' }) + // final attempt of a test under `retries: 1` + const ctx = { test: { parent: suite, currentRetry: () => 1, retries: () => 1 } as unknown } + const test = makeTest('times out on last attempt', { ctx, _currentRetry: 1 }) + await service.beforeTest(test) + events.length = 0 + + // mocha fails it and moves on to an afterEach hook, which inherits the suite's retries + ctx.test = { parent: suite, currentRetry: () => 0, retries: () => 1 } + expect(finishCliTestOnFailure(cliTestAttemptKey('Suite - times out on last attempt', 1), failed)).toBe(true) + await service.after(1) + + expect(events.some((e) => e.includes('skipped dropped by bail'))).toBe(true) + }) }) From 26a587264017e1b329ec31a9c27c451573ce41e0 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Thu, 8 Oct 2026 19:54:29 +0530 Subject: [PATCH 7/9] refactor(cli): route the timed-out test finish through trackEvent (SDK-7843) Review: keep service.ts / reporter.ts to feeding the existing CLI events and leave product logic to the CLI layer, instead of a side-channel util. - reporter onTestFail sends LOG_REPORT/POST + TEST/POST through framework.trackEvent (as skipReporter does), with mocha's result. TestHubModule and AutomateModule already handle a failed TEST/POST; the only problem was that it arrived after after(). - WdioMochaTestFramework tracks each mocha test attempt from TEST/PRE: the finish is reported once, against the instance the attempt started on (replaces the service's _cliTestUuids pin), keeps mocha's failure when a late afterTest says passed, and runs the bail cascade (moved from service.ts, using the runnable captured at TEST/PRE). - settleTestFinishes() (TestFramework, no-op by default) waits for finishes wdio does not await and finishes tests mocha already failed when no reporter is registered; after() calls it before the flush and EXECUTE/POST. - beforeTest passes mocha's bail through its TEST/PRE call. - cli/earlyTestFinish.ts removed. Co-Authored-By: Claude Opus 5.5 --- .../src/cli/earlyTestFinish.ts | 118 ---------- .../src/cli/frameworks/testFramework.ts | 7 + .../cli/frameworks/wdioMochaTestFramework.ts | 214 +++++++++++++++++- packages/browserstack-service/src/reporter.ts | 25 +- packages/browserstack-service/src/service.ts | 169 ++------------ .../tests/cli/earlyTestFinish.test.ts | 128 ----------- ...wdioMochaTestFramework.bailCascade.test.ts | 170 ++++++++++++++ ...dioMochaTestFramework.timedOutTest.test.ts | 159 +++++++++++++ .../tests/reporter.onTestFail.test.ts | 69 +++--- .../tests/service.afterSkipOrdering.test.ts | 1 - .../tests/service.test.ts | 145 ++---------- .../tests/service.timedOutTestFinish.test.ts | 211 +++-------------- 12 files changed, 659 insertions(+), 757 deletions(-) delete mode 100644 packages/browserstack-service/src/cli/earlyTestFinish.ts delete mode 100644 packages/browserstack-service/tests/cli/earlyTestFinish.test.ts create mode 100644 packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts create mode 100644 packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts diff --git a/packages/browserstack-service/src/cli/earlyTestFinish.ts b/packages/browserstack-service/src/cli/earlyTestFinish.ts deleted file mode 100644 index 74a4ea1e..00000000 --- a/packages/browserstack-service/src/cli/earlyTestFinish.ts +++ /dev/null @@ -1,118 +0,0 @@ -import util from 'node:util' -import type { Frameworks } from '@wdio/types' - -import { BStackLogger } from '../bstackLogger.js' - -/** - * SDK-7843: finish a mocha test on the CLI flow at the moment mocha reports it failed. - * - * wdio runs a test's `afterTest` hook inside the test's own runnable, after the body. When the - * test hits mocha's timeout, mocha marks it failed (and emits `fail` to reporters) while the body - * and its `afterTest` are still pending. With `bail`, or when it was the worker's last test, wdio - * then runs `after()` BEFORE that `afterTest` fires, so everything `after()` does on the CLI flow - * runs without the failure: the session status is marked `passed`, and the test's TestRunFinished - * is stranded until Test Hub reaps the build as `timeout`. The classic flow never had this, because - * it reads the session status from `after(result)` — mocha's own failure count. - * - * So the service registers a finisher per running test attempt in `beforeTest`; whichever comes - * first — `afterTest` (normal case) or the reporter's `onTestFail` (timeout case) — claims it and - * reports the finish exactly once. The reporter is only registered when Test Hub events are on, so - * `after()` also finishes any test mocha already failed that nobody claimed, from mocha's own - * runnable, and then awaits every finish started here. - */ -type CliTestFinisher = (result: Frameworks.TestResult) => Promise - -/** The live mocha runnable of an attempt; mocha sets `state` before it emits `fail`. */ -interface MochaRunnable { - state?: string - timedOut?: boolean - duration?: number - timeout?: () => number -} - -const finishers = new Map() -/** Attempts the reporter already finished; their late afterTest must not report them again. */ -const reportedOnFailure = new Set() -const inFlight = new Set>() - -/** - * Key one attempt of a test. With mocha retries, a timed-out attempt's late afterTest can arrive - * while the next attempt of the same test is running, so the hand-off must not be shared between - * attempts. The service reads the attempt from mocha's `_currentRetry`, the reporter from - * `TestStats.retries`; both count retries of this test so far. - */ -export function cliTestAttemptKey(identifier: string, attempt?: number): string { - return attempt ? `${identifier} (retry ${attempt})` : identifier -} - -/** beforeTest: this attempt's finish is now owed, by afterTest or by the reporter. */ -export function registerCliTestFinisher(key: string, finisher: CliTestFinisher, runnable?: MochaRunnable): void { - finishers.set(key, { finisher, runnable }) -} - -/** The failure mocha recorded on an attempt's runnable (it keeps no error object on it). */ -function failureFromRunnable(runnable: MochaRunnable): Frameworks.TestResult { - const ms = typeof runnable.timeout === 'function' ? runnable.timeout() : undefined - const error = new Error(runnable.timedOut && ms ? `Timeout of ${ms}ms exceeded.` : 'Test failed before its afterTest ran.') - return { passed: false, error, duration: runnable.duration ?? 0, retries: { attempts: 0, limit: 0 }, exception: error.message, status: 'failed' } -} - -/** - * afterTest: claim the finish. Returns false when the attempt is reported on failure instead — - * already by the reporter, or now, because mocha already failed it (a timed-out test whose body - * finished late, with no reporter registered). wdio's result for such a body says only whether - * the body threw, not that mocha timed it out. In both cases afterTest must not report it. - * A normal failure is untouched: its afterTest runs before mocha marks the runnable failed. - * A test that was never registered still belongs to afterTest. - */ -export function claimCliTestFinish(key: string): boolean { - const runnable = finishers.get(key)?.runnable - if (runnable?.state === 'failed') { - finishCliTestOnFailure(key, failureFromRunnable(runnable)) - } - finishers.delete(key) - return !reportedOnFailure.delete(key) -} - -/** - * Reporter `onTestFail`: if afterTest has not reported this attempt yet, report its failure now, - * from mocha's own result. Returns whether a finish was started. - */ -export function finishCliTestOnFailure(key: string, result: Frameworks.TestResult): boolean { - const entry = finishers.get(key) - if (!entry) { - return false - } - finishers.delete(key) - reportedOnFailure.add(key) - BStackLogger.debug(`finishCliTestOnFailure: mocha reported '${key}' failed before its afterTest; reporting the finish now`) - const work = entry.finisher(result).catch((err: unknown) => { - BStackLogger.debug(`finishCliTestOnFailure: reporting '${key}' failed: ${util.format(err)}`) - }) - inFlight.add(work) - work.finally(() => inFlight.delete(work)) - return true -} - -/** - * after(): finish every attempt mocha already failed that neither afterTest nor the reporter - * claimed (no reporter registered), then wait for all finishes started on failure. Runs before - * the deferred-finish flush and before the session status is marked. - */ -export async function awaitCliTestFinishesOnFailure(): Promise { - for (const [key, { runnable }] of [...finishers]) { - if (runnable?.state === 'failed') { - finishCliTestOnFailure(key, failureFromRunnable(runnable)) - } - } - while (inFlight.size > 0) { - await Promise.all([...inFlight]) - } -} - -/** Test-only reset of the module state. */ -export function resetCliTestFinishers(): void { - finishers.clear() - reportedOnFailure.clear() - inFlight.clear() -} diff --git a/packages/browserstack-service/src/cli/frameworks/testFramework.ts b/packages/browserstack-service/src/cli/frameworks/testFramework.ts index f291505c..4266ed79 100644 --- a/packages/browserstack-service/src/cli/frameworks/testFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/testFramework.ts @@ -84,6 +84,13 @@ export default class TestFramework { logger.info(`trackEvent: testFrameworkState=${testFrameworkState}; hookState=${hookState}; args=${args}`) } + /** + * Wait for test finishes that are still being reported. A module calls this before it reads the + * final results of the run (session status, the last deferred test finish). + * @returns {Promise} + */ + async settleTestFinishes(): Promise {} + /** * run test hooks * @param {TestFrameworkInstance} instance diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index 8bc2be62..b745f725 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -12,6 +12,7 @@ import { BStackLogger as logger } from '../cliLogger.js' import type { Frameworks } from '@wdio/types' import { getMochaTestHierarchy, getTestTags, getUniqueIdentifier, isUndefined, removeAnsiColors } from '../../util.js' import { TEST_ANALYTICS_ID } from '../../constants.js' +import { reportSuiteSkipped } from '../skipReporter.js' /** * File-path pair sent with every test/hook event. @@ -31,10 +32,68 @@ const resolveTestFilePaths = (filename: string | undefined) => ({ : undefined, }) +/** mocha's live runnable of a test attempt; mocha sets `state` before it emits `fail`. */ +interface MochaRunnable { + state?: string + timedOut?: boolean + duration?: number + timeout?: () => number + currentRetry?: () => number + retries?: () => number + parent?: MochaSuite +} + +interface MochaSuite { + parent?: MochaSuite + tests?: unknown[] + suites?: unknown[] +} + +/** A mocha test attempt that has started (TEST/PRE) and not finished yet (SDK-7843). */ +interface TestAttempt { + instance: TestFrameworkInstance + test: Frameworks.Test + suiteTitle?: unknown + runnable?: MochaRunnable + /** mocha's `bail`: a failure drops every test the spec has not reached yet. */ + bail?: boolean + /** Who is reporting this attempt's finish: wdio's afterTest, or the reporter's `fail`. */ + finishingFrom?: 'afterTest' | 'fail' +} + +/** The failure mocha recorded on a runnable (it keeps no error object on it). */ +const failureFromRunnable = (runnable: MochaRunnable): Frameworks.TestResult => { + const ms = typeof runnable.timeout === 'function' ? runnable.timeout() : undefined + const error = new Error(runnable.timedOut && ms ? `Timeout of ${ms}ms exceeded.` : 'Test failed before its afterTest ran.') + return { passed: false, error, duration: runnable.duration ?? 0, retries: { attempts: 0, limit: 0 }, exception: error.message, status: 'failed' } +} + export default class WdioMochaTestFramework extends TestFramework { static KEY_HOOK_LAST_STARTED = 'test_hook_last_started' static KEY_HOOK_LAST_FINISHED = 'test_hook_last_finished' + /** + * SDK-7843: mocha test attempts that started and have not finished, keyed per attempt. + * + * wdio runs `afterTest` inside the test's own runnable, after the body. When a test hits + * mocha's timeout, mocha fails it (and emits `fail` to reporters) while the body and its + * `afterTest` are still pending; mocha then moves on, and with `bail` (or on the worker's last + * test) wdio runs `after()` before that `afterTest`. So a test's finish can arrive from the + * reporter's `fail`, from a late `afterTest` while another test holds the tracked-instance + * slot, or not at all before the session status is marked. Each attempt keeps the instance it + * started on, so its finish is reported against its own test run, once. + */ + private openAttempts = new Map() + private finishedAttempts = new Set() + private pendingFinishes = new Set>() + + /** One attempt of a test: mocha retries a test as a new runnable with `_currentRetry` + 1. */ + static attemptKey(test: Frameworks.Test): string { + const retry = (test as { _currentRetry?: number })._currentRetry + const identifier = getUniqueIdentifier(test, 'mocha') + return retry ? `${identifier} (retry ${retry})` : identifier + } + /** * Constructor for the TestFramework * @param {Array} testFrameworks - List of Test frameworks @@ -52,6 +111,20 @@ export default class WdioMochaTestFramework extends TestFramework { * @param {*} args */ async trackEvent(testFrameworkState: State, hookState: State, args: Record = {}) { + if (args.fromMochaFail) { + // the reporter's `fail` (SDK-7843): wdio does not await reporter callbacks, so keep the + // send visible to settleTestFinishes() + const work = this.trackTestEvent(testFrameworkState, hookState, args).catch((err: unknown) => { + logger.debug(`trackEvent: reporting a failed test failed: ${err}`) + }) + this.pendingFinishes.add(work) + work.finally(() => this.pendingFinishes.delete(work)) + return work + } + await this.trackTestEvent(testFrameworkState, hookState, args) + } + + private async trackTestEvent(testFrameworkState: State, hookState: State, args: Record) { logger.info(`trackEvent: testFrameworkState=${testFrameworkState} hookState=${hookState}`) await super.trackEvent(testFrameworkState, hookState, args) @@ -64,11 +137,24 @@ export default class WdioMochaTestFramework extends TestFramework { return } - const instance = this.resolveInstance(testFrameworkState, hookState, args) + const attempt = this.resolveTestAttempt(testFrameworkState, hookState, args) + if (attempt === null) { + return + } + let instance: TestFrameworkInstance | null + if (attempt) { + instance = attempt.instance + this.updateInstanceState(instance, testFrameworkState, hookState) + } else { + instance = this.resolveInstance(testFrameworkState, hookState, args) + } if (instance === null) { logger.error(`trackEvent: instance not found for testFrameworkState=${testFrameworkState} hookState=${hookState}`) return } + if (testFrameworkState === TestFrameworkState.TEST && hookState === HookState.PRE && args.test) { + this.openTestAttempt(instance, args) + } try { // matchHookRegex expects the short state name (e.g. AFTER_EACH); `toString()` yields @@ -121,6 +207,132 @@ export default class WdioMochaTestFramework extends TestFramework { } args.instance = instance await this.runHooks(instance, testFrameworkState, hookState, args) + if (attempt && testFrameworkState === TestFrameworkState.TEST) { + await this.reportBailSkippedTests(attempt, args.result as Frameworks.TestResult) + } + } + + /** + * Whether this failure will be retried, in which case mocha has not dropped anything yet and + * the tests after it are still going to run. + * + * `results.retries` only tracks wdio's spec-file retries — `@wdio/utils` builds it as + * `{ attempts: 0, limit: repeatTest }` and `@wdio/mocha-framework` never feeds `mochaOpts.retries` + * into it, so under mocha-level retries it stays `{0, 0}` and tells us nothing. Read mocha's own + * runnable state for that case, otherwise the cascade fires on the first attempt and reports + * tests as skipped that the retry then actually runs. The runnable is the one captured at + * TEST/PRE: once mocha fails a timed-out test it moves on, and the suite's shared + * `ctx.test` then points at a hook, which inherits the suite's `retries` (SDK-7843). + */ + private hasRetryPending(runnable: MochaRunnable | undefined, results: Frameworks.TestResult): boolean { + if (typeof runnable?.currentRetry === 'function' && typeof runnable.retries === 'function') { + if (runnable.currentRetry() < runnable.retries()) { + return true + } + } + return Boolean(results.retries && results.retries.attempts < results.retries.limit) + } + + /** + * mocha's `bail` aborts the run on the first failure, so every test the spec had not reached + * yet is dropped without emitting any event and never appears on the dashboard. Report them + * as skipped — same cascade the failed-hook path uses, from the spec's root suite so sibling + * describes are covered too (bail kills the whole spec, not just the failing describe). + * + * The root can span more than one file when specs are grouped — `MochaAdapter` adds every spec + * it is handed to one mocha instance. Cascading across them is still correct: bail aborts that + * whole runner, so those tests do not run either. + * + * Runs as part of the failed test's finish, so it lands before the session status is marked + * and the last test finish is flushed, also when that finish came from mocha's `fail` (SDK-7843). + */ + private async reportBailSkippedTests(attempt: TestAttempt, results: Frameworks.TestResult | undefined) { + if (!attempt.bail || !results || results.passed || results.skipped) { + return + } + try { + // inside the boundary: hasRetryPending reaches into mocha's own runnable, which this + // SDK does not own + if (this.hasRetryPending(attempt.runnable, results)) { + return + } + let suite = attempt.runnable?.parent + if (!suite) { + return + } + while (suite.parent) { + suite = suite.parent + } + await reportSuiteSkipped(this, suite) + } catch (err) { + logger.debug(`Failed reporting bail-skipped tests: ${err}`) + } + } + + /** TEST/PRE: this attempt's finish is owed from here on, against this instance. */ + private openTestAttempt(instance: TestFrameworkInstance, args: Record) { + const test = args.test as Frameworks.Test + this.openAttempts.set(WdioMochaTestFramework.attemptKey(test), { + instance, + test, + suiteTitle: args.suiteTitle, + runnable: test.ctx?.test as MochaRunnable | undefined, + bail: args.bail === true + }) + } + + /** + * LOG_REPORT/POST and TEST/POST of a mocha test: the attempt to report against. Returns + * undefined for any other event, and for a test this framework never saw start (resolved as + * before); null to drop the event, when the attempt is already finished or another source is + * finishing it. + */ + private resolveTestAttempt(testFrameworkState: State, hookState: State, args: Record): TestAttempt | null | undefined { + const isFinish = hookState === HookState.POST && (testFrameworkState === TestFrameworkState.TEST || testFrameworkState === TestFrameworkState.LOG_REPORT) + if (!isFinish || !args.test) { + return undefined + } + const key = WdioMochaTestFramework.attemptKey(args.test as Frameworks.Test) + const source = args.fromMochaFail ? 'fail' : 'afterTest' + const attempt = this.openAttempts.get(key) + if (this.finishedAttempts.has(key) || (attempt?.finishingFrom && attempt.finishingFrom !== source)) { + logger.debug(`trackEvent: '${key}' was already reported, dropping ${testFrameworkState} ${hookState} from ${source}`) + return null + } + if (!attempt) { + // the reporter's `fail` for a hook, or for a test that never started + return source === 'fail' ? null : undefined + } + attempt.finishingFrom = source + args.suiteTitle ??= attempt.suiteTitle + // a timed-out test whose body finished late: wdio's result says only whether the body + // threw, not that mocha already failed it + if (attempt.runnable?.state === 'failed' && (args.result as Frameworks.TestResult | undefined)?.passed) { + args.result = failureFromRunnable(attempt.runnable) + } + if (testFrameworkState === TestFrameworkState.TEST) { + this.openAttempts.delete(key) + this.finishedAttempts.add(key) + } + return attempt + } + + /** + * Before the session status is marked and the last test finish is flushed: finish every attempt + * mocha already failed that nothing reported (no reporter is registered when Test Reporting, + * Accessibility and Percy are all off), then wait for every finish the reporter started. + */ + async settleTestFinishes(): Promise { + for (const attempt of [...this.openAttempts.values()]) { + if (attempt.runnable?.state === 'failed' && !attempt.finishingFrom) { + const result = failureFromRunnable(attempt.runnable) + await this.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: attempt.test, result, fromMochaFail: true }) + await this.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: attempt.test, result, suiteTitle: attempt.suiteTitle, fromMochaFail: true }) + } + } + while (this.pendingFinishes.size > 0) { + await Promise.all([...this.pendingFinishes]) + } } /** diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index 96edc4a2..b2b7234c 100644 --- a/packages/browserstack-service/src/reporter.ts +++ b/packages/browserstack-service/src/reporter.ts @@ -5,7 +5,8 @@ import WDIOReporter from '@wdio/reporter' import type { Options, Frameworks } from '@wdio/types' import { BrowserstackCLI } from './cli/index.js' import { reportSkippedTest, resolveSpecFile } from './cli/skipReporter.js' -import { cliTestAttemptKey, finishCliTestOnFailure } from './cli/earlyTestFinish.js' +import { TestFrameworkState } from './cli/states/testFrameworkState.js' +import { HookState } from './cli/states/hookState.js' import * as url from 'node:url' import { v4 as uuidv4 } from 'uuid' @@ -153,24 +154,32 @@ class _TestReporter extends WDIOReporter { /** * SDK-7843: mocha emits `fail` for a timed-out test while its body and wdio's `afterTest` are * still pending, and with `bail` (or on the worker's last test) `after()` runs before that - * `afterTest`. On the CLI flow, report the failure now, from mocha's own result, so `after()` - * marks the session and closes the test with it. A normal failure is already reported by - * `afterTest` before mocha's `fail`, so this is a no-op for it. + * `afterTest`. On the CLI flow, send the test's finish now, with mocha's own result, so it is + * recorded before the session status is marked. The CLI framework reports each test once, so + * this is dropped for a normal failure, which afterTest has already reported. */ - onTestFail(testStats: TestStats) { + async onTestFail(testStats: TestStats) { if (this._config?.framework !== 'mocha' || !BrowserstackCLI.getInstance().isRunning()) { return } - const attempts = testStats.retries ?? 0 + const framework = BrowserstackCLI.getInstance().getTestFramework() + if (!framework) { + return + } // `retries` is this test's retry count so far, i.e. the attempt mocha just failed - finishCliTestOnFailure(cliTestAttemptKey(`${testStats.parent} - ${testStats.title}`, attempts), { + const attempts = testStats.retries ?? 0 + const stats = testStats as TestStats & { parent?: string, file?: string } + const test = { title: stats.title, parent: stats.parent, fullTitle: stats.fullTitle, file: stats.file, _currentRetry: attempts } as unknown as Frameworks.Test + const result: Frameworks.TestResult = { passed: false, error: testStats.error, duration: testStats._duration, retries: { attempts, limit: attempts }, exception: testStats.error?.message ?? '', status: 'failed' - }) + } + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, fromMochaFail: true }) } async onTestEnd(testStats: TestStats) { diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index 00a148ae..0349751a 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -17,7 +17,6 @@ import type { BrowserstackConfig, BrowserstackOptions, MultiRemoteAction } from import type { Pickle, Feature, ITestCaseHookParameter, CucumberHook } from './cucumber-types.js' import InsightsHandler from './insights-handler.js' import TestReporter from './reporter.js' -import { awaitCliTestFinishesOnFailure, claimCliTestFinish, cliTestAttemptKey, registerCliTestFinisher } from './cli/earlyTestFinish.js' import { DEFAULT_OPTIONS, NOT_ALLOWED_KEYS_IN_CAPS, PERF_MEASUREMENT_ENV } from './constants.js' import CrashReporter from './crash-reporter.js' import AccessibilityHandler from './accessibility-handler.js' @@ -71,20 +70,6 @@ export default class BrowserstackService implements Services.ServiceInstance { private _specsRan: boolean = false private _observability private _currentTest?: Frameworks.Test | ITestCaseHookParameter - /** - * CLI/gRPC path: map of test identity -> the test_uuid minted for it at - * INIT_TEST/PRE. The CLI mints a fresh uuid into a SINGLE mutable per-worker tracked instance - * (`trackWdioMochaInstance` overwrites `TestFramework.instances[ctxId]` wholesale on every - * INIT_TEST), and the gRPC test-finish reads the uuid from that single slot. When a test hangs - * past the mocha timeout, the NEXT test's INIT_TEST overwrites the slot before the hung test's - * afterTest POST fires, so the POST would carry the wrong (next) test's uuid and the binary - * would close the wrong test_run — orphaning the hung one. We snapshot each test's uuid here, - * keyed per attempt (cliTestAttemptKey over the identity the legacy `_tests` map uses), and at afterTest we restore the - * finishing test's minted uuid onto the tracked instance before the POST so it closes the - * correct test_run. The finishing identity is `originalTest` (already snapshotted pre-await by - * the testFnWrapper, so it is the timed-out runnable's own identity, not the next test's). - */ - private _cliTestUuids: Map = new Map() private _insightsHandler?: InsightsHandler private _accessibility private _accessibilityHandler?: AccessibilityHandler @@ -601,9 +586,6 @@ export default class BrowserstackService implements Services.ServiceInstance { @PerformanceTester.Measure(PERFORMANCE_SDK_EVENTS.EVENTS.SDK_HOOK, { hookType: 'beforeTest' }) async beforeTest (test: Frameworks.Test) { this._currentTest = test - // mocha's live runnable for this attempt; read before any await, since the suite's - // shared context moves on to the next runnable - const runnable = test.ctx?.test let suiteTitle = this._suiteTitle if (test.fullName) { @@ -620,23 +602,11 @@ export default class BrowserstackService implements Services.ServiceInstance { if (BrowserstackCLI.getInstance().isRunning()) { await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) const uuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) - // snapshot this test's freshly-minted uuid keyed by its identity, so a later - // afterTest can restore it even after a subsequent INIT_TEST has overwritten the single - // mutable tracked-instance slot. Keyed per attempt, so a retried attempt keeps its own. - if (this._config.framework === 'mocha' && uuid) { - this._cliTestUuids.set(this.cliAttemptKey(test), uuid as string) - } // this test reports its own finish (incl. runtime `this.skip()`), so the // skip reporter must never re-report it from onTestSkip markTestStarted(getUniqueIdentifier(test, this._config.framework)) - // SDK-7843: this test's finish is owed from here on. Normally afterTest reports it; if - // the test times out, mocha reports the failure to the reporter first and the reporter - // reports it (see cli/earlyTestFinish.ts). - if (this._config.framework === 'mocha') { - registerCliTestFinisher(this.cliAttemptKey(test), (result) => this.finishCliTest(test, result, runnable), runnable) - } this._insightsHandler?.setTestData(test, uuid) - await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) + await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle, bail: this._mochaBail }) return } @@ -663,13 +633,12 @@ export default class BrowserstackService implements Services.ServiceInstance { } if (BrowserstackCLI.getInstance().isRunning()) { - if (this._config.framework === 'mocha' && !claimCliTestFinish(this.cliAttemptKey(test))) { - // SDK-7843: the test timed out, and its failure was already reported when mocha - // failed it; reporting it again here would arrive after after() anyway. - BStackLogger.debug(`afterTest: '${this.cliAttemptKey(test)}' was already reported when mocha failed it`) - return - } - await this.finishCliTest(test, results) + // `test` is `originalTest`, the timed-out runnable's own identity; the CLI framework + // reports the finish against the instance that test started on, even when a later + // test has taken the tracked-instance slot, drops it if mocha's `fail` already + // reported it, and runs the bail cascade (SDK-7843) + await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) + await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) return } @@ -678,110 +647,6 @@ export default class BrowserstackService implements Services.ServiceInstance { await this._percyHandler?.afterTest() } - /** - * Report a mocha test's finish on the CLI flow: its result, its TEST/POST, and the bail cascade. - * Called exactly once per test, from afterTest or (when the test timed out) when mocha failed - * it (SDK-7843). That second path runs after mocha has moved on, so it passes the runnable - * captured in beforeTest; the suite's shared `test.ctx.test` then points at a hook or the next test. - */ - private async finishCliTest(test: Frameworks.Test, results: Frameworks.TestResult, runnable?: unknown) { - // the CLI test-finish reads test_uuid from the single mutable per-worker - // tracked instance, which a later INIT_TEST may have overwritten with the NEXT test's - // uuid. `test` is `originalTest` — already the correct (timed-out) identity, snapshotted - // pre-await by the testFnWrapper — so restore THAT test's minted uuid onto the tracked - // instance so the POST carries it and the binary closes the correct test_run. Without - // this, the finish would carry the next test's uuid and orphan the finishing one. - let resolvedUuid: string | undefined - if (this._config.framework === 'mocha') { - const key = this.cliAttemptKey(test) - resolvedUuid = this._cliTestUuids.get(key) - // Clean up so the per-worker map does not grow across the run. - this._cliTestUuids.delete(key) - } - /** Put this test's uuid on the tracked instance; returns another test's uuid it replaced. */ - const pinUuid = (): unknown => { - const trackedInstance = TestFramework.getTrackedInstance() - if (!resolvedUuid || !trackedInstance) { - return undefined - } - const current = TestFramework.getState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID) - TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) - return current && current !== resolvedUuid ? current : undefined - } - const displacedFirst = pinUuid() - await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) - // SDK-7843: when this finish was started on failure, mocha moved on during the await - // above, and the next test's INIT_TEST may have taken the slot. Pin this test's uuid again - // for its TEST/POST, then hand the slot back to the test now running. - const displacedUuid = pinUuid() ?? displacedFirst - await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) - const trackedInstance = TestFramework.getTrackedInstance() - if (displacedUuid && trackedInstance && TestFramework.getState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID) === resolvedUuid) { - TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, displacedUuid) - } - await this.reportBailSkippedTests(test, results, runnable) - } - - /** One attempt of a mocha test; see cliTestAttemptKey. */ - private cliAttemptKey(test: Frameworks.Test): string { - return cliTestAttemptKey(getUniqueIdentifier(test, this._config.framework), (test as { _currentRetry?: number })._currentRetry) - } - - /** - * Whether this failure will be retried, in which case mocha has not dropped anything yet and - * the tests after it are still going to run. - * - * `results.retries` only tracks wdio's spec-file retries — `@wdio/utils` builds it as - * `{ attempts: 0, limit: repeatTest }` and `@wdio/mocha-framework` never feeds `mochaOpts.retries` - * into it, so under mocha-level retries it stays `{0, 0}` and tells us nothing. Read mocha's own - * runnable state for that case, otherwise the cascade fires on the first attempt and reports - * tests as skipped that the retry then actually runs. - */ - private hasRetryPending(test: Frameworks.Test, results: Frameworks.TestResult, runnable?: unknown): boolean { - const mochaTest = (runnable ?? test.ctx?.test) as { currentRetry?: () => number, retries?: () => number } | undefined - if (typeof mochaTest?.currentRetry === 'function' && typeof mochaTest.retries === 'function') { - if (mochaTest.currentRetry() < mochaTest.retries()) { - return true - } - } - return Boolean(results.retries && results.retries.attempts < results.retries.limit) - } - - /** - * mocha's `bail` aborts the run on the first failure, so every test the spec had not reached - * yet is dropped without emitting any event and never appears on the dashboard. Report them - * as skipped — same cascade the failed-hook path uses, from the spec's root suite so sibling - * describes are covered too (bail kills the whole spec, not just the failing describe). - * - * The root can span more than one file when specs are grouped — `MochaAdapter` adds every spec - * it is handed to one mocha instance. Cascading across them is still correct: bail aborts that - * whole runner, so those tests do not run either. - */ - private async reportBailSkippedTests(test: Frameworks.Test, results: Frameworks.TestResult, runnable?: unknown) { - if (!this._mochaBail || results.passed || results.skipped) { - return - } - try { - // inside the boundary: hasRetryPending reaches into mocha's own runnable, which this - // SDK does not own - if (this.hasRetryPending(test, results, runnable)) { - return - } - const framework = BrowserstackCLI.getInstance().getTestFramework() - const mochaTest: typeof test.ctx = runnable ?? test.ctx?.test - let suite = mochaTest?.parent - if (!framework || !suite) { - return - } - while (suite.parent) { - suite = suite.parent - } - await reportSuiteSkipped(framework, suite) - } catch (err) { - BStackLogger.debug(`Failed reporting bail-skipped tests: ${err}`) - } - } - @PerformanceTester.Measure(PERFORMANCE_SDK_EVENTS.EVENTS.SDK_HOOK, { hookType: 'after' }) async after (result: number) { try { @@ -810,12 +675,14 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (skipDrainErr) { BStackLogger.debug(`Exception draining skip reports in after(): ${util.format(skipDrainErr)}`) } - // SDK-7843: a test that timed out is finished when mocha failed it (or here, from - // mocha's runnable, when no reporter is registered), and that finish can still be in - // flight. Wait for it before the flush below (its TEST/POST is deferred into that - // stash) and before EXECUTE/POST, which marks the session status from the results - // recorded so far. Every finish catches its own error, so this cannot reject. - await awaitCliTestFinishesOnFailure() + // SDK-7843: a test that timed out is reported when mocha failed it, and that report + // can still be in flight; settle it before the flush below and before EXECUTE/POST, + // where the session status is marked from the results recorded so far + try { + await BrowserstackCLI.getInstance().getTestFramework()?.settleTestFinishes() + } catch (settleErr) { + BStackLogger.debug(`Exception settling test finishes in after(): ${util.format(settleErr)}`) + } // Flush a test-finish event deferred past the after-each hook window — the last // test of the worker has no next-test boundary to trigger the flush. Must run // before worker teardown so the event isn't dropped. @@ -902,12 +769,6 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (sweepErr) { BStackLogger.debug('Exception in sweepUnfinished during after(): ' + util.format(sweepErr)) } - // The sweep closes the _tests entries, but the CLI uuid snapshots (_cliTestUuids) are - // only drained in afterTest — the callback that never fires for a test the sweep just - // handled (e.g. one that timed out). Clear them here at per-worker teardown so stale - // snapshots cannot leak across the worker. Safe to clear: this runs after the sweep and - // no further afterTest will consume them in this worker. - this._cliTestUuids.clear() // Track Listener cleanup PerformanceTester.start(EVENTS.SDK_LISTENER_WORKER_END) diff --git a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts b/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts deleted file mode 100644 index 2c5df3b0..00000000 --- a/packages/browserstack-service/tests/cli/earlyTestFinish.test.ts +++ /dev/null @@ -1,128 +0,0 @@ -import path from 'node:path' -import { describe, expect, it, vi, beforeEach } from 'vitest' -import type { Frameworks } from '@wdio/types' - -import { - awaitCliTestFinishesOnFailure, - claimCliTestFinish, - cliTestAttemptKey, - finishCliTestOnFailure, - registerCliTestFinisher, - resetCliTestFinishers -} from '../../src/cli/earlyTestFinish.js' -import * as bstackLogger from '../../src/bstackLogger.js' - -vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) -vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) - -const failed = { passed: false, error: new Error('Timeout of 300000ms exceeded.'), duration: 300000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult - -describe('SDK-7843 — a mocha test finish is reported exactly once, by whichever comes first', () => { - beforeEach(() => { - resetCliTestFinishers() - }) - - it('reports a timed-out test when mocha fails it, and the late afterTest then stands down', async () => { - const finisher = vi.fn().mockResolvedValue(undefined) - registerCliTestFinisher('Suite - times out', finisher) - - expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) - await awaitCliTestFinishesOnFailure() - - expect(finisher).toHaveBeenCalledOnce() - expect(finisher).toHaveBeenCalledWith(failed) - // wdio's afterTest for the same test arrives after after(); it must not report it again - expect(claimCliTestFinish('Suite - times out')).toBe(false) - }) - - it('leaves a normal failure to afterTest, which runs before mocha reports it', () => { - const finisher = vi.fn().mockResolvedValue(undefined) - registerCliTestFinisher('Suite - fails normally', finisher) - - expect(claimCliTestFinish('Suite - fails normally')).toBe(true) - expect(finishCliTestOnFailure('Suite - fails normally', failed)).toBe(false) - expect(finisher).not.toHaveBeenCalled() - }) - - it('keeps afterTest responsible for a test that was never registered', () => { - expect(claimCliTestFinish('Suite - never registered')).toBe(true) - expect(finishCliTestOnFailure('Suite - never registered', failed)).toBe(false) - }) - - it('makes after() wait for a finish that is still in flight', async () => { - let done = false - registerCliTestFinisher('Suite - slow finish', () => new Promise((resolve) => setTimeout(() => { - done = true - resolve() - }, 100))) - - finishCliTestOnFailure('Suite - slow finish', failed) - await awaitCliTestFinishesOnFailure() - - expect(done).toBe(true) - }) - - it('does not let a failing finish break after()', async () => { - registerCliTestFinisher('Suite - finish throws', () => Promise.reject(new Error('gRPC down'))) - - finishCliTestOnFailure('Suite - finish throws', failed) - - await expect(awaitCliTestFinishesOnFailure()).resolves.toBeUndefined() - }) - - it('keeps each retry attempt separate, so a late afterTest of one attempt cannot claim the next', () => { - const first = vi.fn().mockResolvedValue(undefined) - const second = vi.fn().mockResolvedValue(undefined) - registerCliTestFinisher(cliTestAttemptKey('Suite - flaky', 0), first) - registerCliTestFinisher(cliTestAttemptKey('Suite - flaky', 1), second) - - // attempt 0 timed out and was retried (mocha emits `retry`, not `fail`); its afterTest arrives late - expect(claimCliTestFinish(cliTestAttemptKey('Suite - flaky', 0))).toBe(true) - // attempt 1 is still owed, and can still be reported when mocha fails it - expect(finishCliTestOnFailure(cliTestAttemptKey('Suite - flaky', 1), failed)).toBe(true) - expect(second).toHaveBeenCalledWith(failed) - expect(first).not.toHaveBeenCalled() - }) - - it('keys the first attempt by the plain identity', () => { - expect(cliTestAttemptKey('Suite - t', 0)).toBe('Suite - t') - expect(cliTestAttemptKey('Suite - t', undefined)).toBe('Suite - t') - expect(cliTestAttemptKey('Suite - t', 2)).toBe('Suite - t (retry 2)') - }) - - it('without a reporter, after() finishes a test mocha already failed, from mocha\'s runnable', async () => { - const finisher = vi.fn().mockResolvedValue(undefined) - registerCliTestFinisher('Suite - times out', finisher, { state: 'failed', timedOut: true, duration: 10002, timeout: () => 10000 }) - - await awaitCliTestFinishesOnFailure() - - expect(finisher).toHaveBeenCalledOnce() - const result = finisher.mock.calls[0][0] as Frameworks.TestResult - expect(result.passed).toBe(false) - expect(result.duration).toBe(10002) - expect((result.error as Error).message).toBe('Timeout of 10000ms exceeded.') - // its late afterTest then stands down - expect(claimCliTestFinish('Suite - times out')).toBe(false) - }) - - it('leaves a test mocha has not failed to its afterTest', async () => { - const finisher = vi.fn().mockResolvedValue(undefined) - registerCliTestFinisher('Suite - still running', finisher, { state: undefined }) - - await awaitCliTestFinishesOnFailure() - - expect(finisher).not.toHaveBeenCalled() - expect(claimCliTestFinish('Suite - still running')).toBe(true) - }) - - it('a late afterTest of an attempt mocha already failed reports the failure instead (no reporter)', async () => { - const finisher = vi.fn().mockResolvedValue(undefined) - registerCliTestFinisher('Suite - times out', finisher, { state: 'failed', timedOut: true, duration: 10002, timeout: () => 10000 }) - - expect(claimCliTestFinish('Suite - times out')).toBe(false) - await awaitCliTestFinishesOnFailure() - - expect(finisher).toHaveBeenCalledOnce() - expect((finisher.mock.calls[0][0] as Frameworks.TestResult).passed).toBe(false) - }) -}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts new file mode 100644 index 00000000..2d89ce19 --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts @@ -0,0 +1,170 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import * as bstackLogger from '../../src/bstackLogger.js' +import * as util from '../../src/util.js' + +import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramework.js' +import TestFramework from '../../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +describe('mocha bail skip cascade (SDK-7063), run by the CLI framework with the test\'s finish', () => { + let framework: WdioMochaTestFramework + let trackEvent: ReturnType + + // reportSkippedTest de-dupes on `${parent} - ${title}` in a module-scope Set that outlives + // each test, so every case here needs its own titles. + const buildTree = (tag: string) => { + const root: any = { title: '', tests: [], suites: [], parent: undefined } + const suiteA: any = { title: `${tag} Suite A`, tests: [], suites: [], parent: root } + const suiteB: any = { title: `${tag} Suite B`, tests: [], suites: [], parent: root } + root.suites.push(suiteA, suiteB) + + const ran: any = { title: `${tag} A1`, state: 'passed', parent: suiteA, file: '/spec/a.js' } + const failing: any = { title: `${tag} A2`, state: 'failed', parent: suiteA, file: '/spec/a.js' } + const dropped: any = { title: `${tag} A3`, parent: suiteA, file: '/spec/a.js' } + suiteA.tests.push(ran, failing, dropped) + // sibling top-level describe — only reachable because the cascade walks up to root + suiteB.tests.push({ title: `${tag} B1`, parent: suiteB, file: '/spec/a.js' }) + + failing.ctx = { test: { parent: suiteA } } + return { failing, root } + } + + /** beforeTest's events, then afterTest's, as the service sends them. */ + const runTest = async (failing: any, results: Record, bail = true) => { + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail }) + trackEvent.mockClear() + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: results }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: results, suiteTitle: 'suite' }) + } + + // WHICH tests got reported, not just how many events fired — a cascade that swept the wrong + // tests still produces the same call count. Pairs with the count assertions, which catch the + // opposite failure (a test emitted twice). + const skippedTitles = () => [...new Set( + trackEvent.mock.calls + .filter(([, , payload]: any[]) => payload?.result?.skipped === true) + .map(([, , payload]: any[]) => payload.test.title as string) + )].sort() + + beforeEach(() => { + TestFramework.instances.clear() + framework = new WdioMochaTestFramework(['WebdriverIO-mocha'], { 'WebdriverIO-mocha': '9' }, 'bin-session-id') + vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) + vi.spyOn(util, 'getTestTags').mockReturnValue([]) + for (const level of ['info', 'debug', 'error'] as const) { + vi.spyOn(cliLogger, level).mockImplementation(() => {}) + } + vi.spyOn(framework, 'runHooks').mockResolvedValue(undefined) + trackEvent = vi.spyOn(framework, 'trackEvent') + }) + + afterEach(() => { + vi.restoreAllMocks() + TestFramework.instances.clear() + }) + + it('reports un-run tests across sibling describes when mocha bail is on', async () => { + const { failing } = buildTree('bail1') + await runTest(failing, { passed: false }) + + // 2 events close the failing test (LOG_REPORT/POST + TEST/POST), then 4 per skipped test. + // A3 (same describe) and B1 (SIBLING describe) => 2 skipped => 8. + expect(trackEvent).toHaveBeenCalledTimes(2 + 8) + // exactly the un-run tests: A1 already passed and A2 is the failure being reported, + // so sweeping either of them in would be a defect the count alone cannot see + expect(skippedTitles()).toEqual(['bail1 A3', 'bail1 B1']) + }) + + it('does not cascade without mocha bail', async () => { + const { failing } = buildTree('bail2') + await runTest(failing, { passed: false }, false) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade while a wdio spec-file retry is still queued', async () => { + const { failing } = buildTree('bail3') + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 2 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade while a MOCHA-level retry is still queued', async () => { + // wdio's `results.retries` only tracks spec-file retries — @wdio/mocha-framework never + // feeds mochaOpts.retries into it, so it reads {0,0} here and cannot be relied on. + // Without reading mocha's own runnable state the cascade fires on attempt 1 and reports + // tests as skipped that the retry then actually runs. + const { failing } = buildTree('bail5') + failing.ctx.test.currentRetry = () => 0 + failing.ctx.test.retries = () => 1 + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 0 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('cascades once the final mocha retry has been used', async () => { + const { failing } = buildTree('bail6') + failing.ctx.test.currentRetry = () => 1 + failing.ctx.test.retries = () => 1 + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 0 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2 + 8) + expect(skippedTitles()).toEqual(['bail6 A3', 'bail6 B1']) + }) + + it('cascades from the runnable the test started on, not the hook mocha moved on to (SDK-7843)', async () => { + // the final attempt under `retries: 1` times out; mocha moves on to an afterEach hook, + // which inherits the suite's retries, before the finish is reported + const { failing } = buildTree('bail9') + failing.ctx.test.currentRetry = () => 1 + failing.ctx.test.retries = () => 1 + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + failing.ctx.test = { parent: failing.parent, currentRetry: () => 0, retries: () => 1 } + trackEvent.mockClear() + + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + + expect(skippedTitles()).toEqual(['bail9 A3', 'bail9 B1']) + }) + + it('does not cascade when the test passed', async () => { + const { failing } = buildTree('bail4') + await runTest(failing, { passed: true }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade when the test was itself skipped', async () => { + // a skipped test does not abort the spec, and the pre-existing skip paths already + // report it — cascading here would double-report the rest of the suite + const { failing } = buildTree('bail7') + await runTest(failing, { passed: false, skipped: true }) + + // A2 is the test being reported and its own result is legitimately `skipped`; what must + // NOT appear is A3/B1, which the cascade would have added. + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual(['bail7 A2']) + }) + + it('never throws out of the finish when mocha state is hostile', async () => { + // afterTest is awaited by wdio; anything escaping this cascade would surface as a + // framework-level error in the user's run + const { failing } = buildTree('bail8') + failing.ctx.test.currentRetry = () => { throw new Error('mocha exploded') } + failing.ctx.test.retries = () => 1 + + await runTest(failing, { passed: false }) + expect(skippedTitles()).toEqual([]) + }) +}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts new file mode 100644 index 00000000..932ce0ae --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts @@ -0,0 +1,159 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import type { Frameworks } from '@wdio/types' +import * as bstackLogger from '../../src/bstackLogger.js' +import * as util from '../../src/util.js' + +import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramework.js' +import TestFramework from '../../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.js' +import type TestFrameworkInstance from '../../src/cli/instances/testFrameworkInstance.js' +import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +/** + * SDK-7843 — when a mocha test hits its timeout, mocha fails it (the reporter's `fail`) while its + * body and wdio's afterTest are still pending, and moves on. These drive the real framework in + * that order and record what the product modules (TestHubModule, AutomateModule) would observe. + */ +describe('WdioMochaTestFramework — a test finish is reported once, against its own test run', () => { + let framework: WdioMochaTestFramework + let finishes: string[] + + const runnable = () => ({ state: undefined as string | undefined, timedOut: false, duration: 0, timeout: () => 10000 }) + const makeTest = (title: string, extra: Record = {}) => + ({ title, parent: 'Suite', file: '/spec.js', body: '', ctx: { test: runnable() }, ...extra }) as unknown as Frameworks.Test + const failed = { passed: false, error: new Error('Timeout of 10000ms exceeded.'), duration: 10001, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult + const passed = { passed: true, duration: 40000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'passed' } as Frameworks.TestResult + + const start = async (test: Frameworks.Test) => { + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle: 'Suite' }) + return TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) as string + } + const afterTest = async (test: Frameworks.Test, result: Frameworks.TestResult) => { + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, suiteTitle: 'Suite' }) + } + /** What the reporter sends from `fail`; wdio does not await it. */ + const reporterFail = (test: Frameworks.Test, result = failed) => { + void framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result, fromMochaFail: true }) + void framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, fromMochaFail: true }) + } + + beforeEach(() => { + TestFramework.instances.clear() + framework = new WdioMochaTestFramework(['WebdriverIO-mocha'], { 'WebdriverIO-mocha': '9' }, 'bin-session-id') + finishes = [] + vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) + vi.spyOn(util, 'getTestTags').mockReturnValue([]) + for (const level of ['info', 'debug', 'error'] as const) { + vi.spyOn(cliLogger, level).mockImplementation(() => {}) + } + // record the TEST/POST each product module would observe, with the test run it closes; + // the modules' gRPC sends take real time, so an instant mock would hide a missing wait + vi.spyOn(framework, 'runHooks').mockImplementation(async (instance: TestFrameworkInstance, state: State, hook: State, args: unknown) => { + if (state === TestFrameworkState.TEST && hook === HookState.POST) { + const { test, result } = args as { test: Frameworks.Test, result: Frameworks.TestResult } + const uuid = TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_UUID) + await new Promise((resolve) => setTimeout(resolve, 20)) + finishes.push(`${test.title} ${uuid} passed=${result.passed}`) + } + }) + }) + + afterEach(() => { + vi.restoreAllMocks() + TestFramework.instances.clear() + }) + + it('reports a timed-out test from mocha\'s `fail`, and drops its late afterTest', async () => { + const test = makeTest('times out') + const uuid = await start(test) + + reporterFail(test) + await framework.settleTestFinishes() + expect(finishes).toEqual([`times out ${uuid} passed=false`]) + + // the body finished late and succeeded: wdio's afterTest says passed + await afterTest(test, passed) + expect(finishes).toEqual([`times out ${uuid} passed=false`]) + }) + + it('reports a normal failure from afterTest, and drops the `fail` that follows it', async () => { + const test = makeTest('fails') + const uuid = await start(test) + + await afterTest(test, { ...failed, error: new Error('expected 1 to equal 2') }) + reporterFail(test) + await framework.settleTestFinishes() + + expect(finishes).toEqual([`fails ${uuid} passed=false`]) + }) + + it('closes a late afterTest against its own test run while the next test holds the slot', async () => { + const first = makeTest('times out') + const firstUuid = await start(first) + const next = makeTest('next test') + const nextUuid = await start(next) + + await afterTest(first, failed) + + expect(finishes).toEqual([`times out ${firstUuid} passed=false`]) + // the running test keeps its own test run + expect(TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID)).toBe(nextUuid) + }) + + it('without a reporter, keeps mocha\'s failure when the late afterTest says passed', async () => { + const test = makeTest('times out then succeeds') + const uuid = await start(test) + + Object.assign(test.ctx!.test as object, { state: 'failed', timedOut: true, duration: 10001 }) + await afterTest(test, passed) + + expect(finishes).toEqual([`times out then succeeds ${uuid} passed=false`]) + }) + + it('without a reporter, settle finishes a test mocha already failed, from its runnable', async () => { + const timedOut = makeTest('times out unreported') + const timedOutUuid = await start(timedOut) + Object.assign(timedOut.ctx!.test as object, { state: 'failed', timedOut: true, duration: 10001 }) + const running = makeTest('still running') + await start(running) + const loadResult = vi.spyOn(framework, 'loadTestResult') + + await framework.settleTestFinishes() + + expect(finishes).toEqual([`times out unreported ${timedOutUuid} passed=false`]) + expect(loadResult).toHaveBeenCalledWith(expect.anything(), expect.objectContaining({ + result: expect.objectContaining({ error: new Error('Timeout of 10000ms exceeded.') }) + })) + }) + + it('keeps each retried attempt on its own test run', async () => { + const attempt0 = makeTest('flaky', { _currentRetry: 0 }) + const uuid0 = await start(attempt0) + const attempt1 = makeTest('flaky', { _currentRetry: 1 }) + const uuid1 = await start(attempt1) + + // attempt 0's late afterTest, then attempt 1 times out too + await afterTest(attempt0, failed) + reporterFail(makeTest('flaky', { _currentRetry: 1 })) + await framework.settleTestFinishes() + + expect(finishes).toEqual([`flaky ${uuid0} passed=false`, `flaky ${uuid1} passed=false`]) + }) + + it('drops a `fail` for a test that never started (a hook), and still reports afterTest for one it never saw', async () => { + await start(makeTest('runs')) + + reporterFail(makeTest('"before each" hook for runs')) + await framework.settleTestFinishes() + expect(finishes).toEqual([]) + + await afterTest(makeTest('unseen'), passed) + expect(finishes).toHaveLength(1) + }) +}) diff --git a/packages/browserstack-service/tests/reporter.onTestFail.test.ts b/packages/browserstack-service/tests/reporter.onTestFail.test.ts index 376d1a84..9238d90a 100644 --- a/packages/browserstack-service/tests/reporter.onTestFail.test.ts +++ b/packages/browserstack-service/tests/reporter.onTestFail.test.ts @@ -1,20 +1,18 @@ import path from 'node:path' -import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import { describe, expect, it, vi, afterEach } from 'vitest' import TestReporter from '../src/reporter.js' import { BrowserstackCLI } from '../src/cli/index.js' -import * as earlyTestFinish from '../src/cli/earlyTestFinish.js' +import WdioMochaTestFramework from '../src/cli/frameworks/wdioMochaTestFramework.js' +import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' +import { HookState } from '../src/cli/states/hookState.js' import * as bstackLogger from '../src/bstackLogger.js' vi.mock('@wdio/reporter', () => import(path.join(process.cwd(), '__mocks__', '@wdio/reporter'))) vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) -vi.mock('../src/cli/earlyTestFinish.js', async (importOriginal) => ({ - ...(await importOriginal()), - finishCliTestOnFailure: vi.fn().mockReturnValue(true) -})) vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) -describe('reporter onTestFail — hands mocha\'s failure to the CLI finish (SDK-7843)', () => { +describe('reporter onTestFail — sends mocha\'s failure through the CLI test events (SDK-7843)', () => { const timeout = new Error('Timeout of 300000ms exceeded. The execution in the test took too long.') const testStats = { title: 'should navigate via bottom nav', parent: 'Smoke: Home Navigation', error: timeout, _duration: 300004, retries: 0 } @@ -23,50 +21,55 @@ describe('reporter onTestFail — hands mocha\'s failure to the CLI finish (SDK- ;(reporter as unknown as { _config: unknown })._config = { framework } return reporter } - - beforeEach(() => { - vi.mocked(earlyTestFinish.finishCliTestOnFailure).mockClear() - }) + const mockCli = (isRunning: boolean) => { + const trackEvent = vi.fn().mockResolvedValue(undefined) + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => isRunning, getTestFramework: () => ({ trackEvent }) } as never) + return trackEvent + } afterEach(() => { vi.restoreAllMocks() }) - it('reports a mocha failure on the CLI flow under the same identity the service registered', () => { - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true } as never) + it('sends LOG_REPORT/POST then TEST/POST with mocha\'s result, under the test\'s identity', async () => { + const trackEvent = mockCli(true) - makeReporter('mocha').onTestFail(testStats as never) + await makeReporter('mocha').onTestFail(testStats as never) - expect(earlyTestFinish.finishCliTestOnFailure).toHaveBeenCalledWith( - 'Smoke: Home Navigation - should navigate via bottom nav', - expect.objectContaining({ passed: false, error: timeout, duration: 300004, status: 'failed', exception: timeout.message }) - ) + const result = expect.objectContaining({ passed: false, error: timeout, duration: 300004, status: 'failed', exception: timeout.message }) + expect(trackEvent.mock.calls.map(([state, hook]) => `${String(state)}/${String(hook)}`)).toEqual([ + `${TestFrameworkState.LOG_REPORT}/${HookState.POST}`, + `${TestFrameworkState.TEST}/${HookState.POST}` + ]) + for (const [, , args] of trackEvent.mock.calls) { + expect(args).toEqual(expect.objectContaining({ result, fromMochaFail: true })) + expect(WdioMochaTestFramework.attemptKey(args.test)).toBe('Smoke: Home Navigation - should navigate via bottom nav') + } }) - it('does nothing on the classic flow, which sets the session status from after(result)', () => { - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => false } as never) + it('names a retried attempt the way the service\'s afterTest does', async () => { + const trackEvent = mockCli(true) - makeReporter('mocha').onTestFail(testStats as never) + await makeReporter('mocha').onTestFail({ ...testStats, retries: 1 } as never) - expect(earlyTestFinish.finishCliTestOnFailure).not.toHaveBeenCalled() + expect(WdioMochaTestFramework.attemptKey(trackEvent.mock.calls[0][2].test)).toBe('Smoke: Home Navigation - should navigate via bottom nav (retry 1)') + expect(WdioMochaTestFramework.attemptKey({ title: testStats.title, parent: testStats.parent, _currentRetry: 1 } as never)) + .toBe('Smoke: Home Navigation - should navigate via bottom nav (retry 1)') }) - it('does nothing for other frameworks, whose afterTest is not run after after()', () => { - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true } as never) + it('does nothing on the classic flow, which sets the session status from after(result)', async () => { + const trackEvent = mockCli(false) - makeReporter('cucumber').onTestFail(testStats as never) + await makeReporter('mocha').onTestFail(testStats as never) - expect(earlyTestFinish.finishCliTestOnFailure).not.toHaveBeenCalled() + expect(trackEvent).not.toHaveBeenCalled() }) - it('reports a retried attempt under that attempt\'s key', () => { - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true } as never) + it('does nothing for other frameworks, whose afterTest is not run after after()', async () => { + const trackEvent = mockCli(true) - makeReporter('mocha').onTestFail({ ...testStats, retries: 1 } as never) + await makeReporter('cucumber').onTestFail(testStats as never) - expect(earlyTestFinish.finishCliTestOnFailure).toHaveBeenCalledWith( - 'Smoke: Home Navigation - should navigate via bottom nav (retry 1)', - expect.objectContaining({ passed: false }) - ) + expect(trackEvent).not.toHaveBeenCalled() }) }) diff --git a/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts b/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts index 828cc0e3..84dea060 100644 --- a/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts +++ b/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts @@ -77,7 +77,6 @@ describe('service.after() — skip drain must precede the deferred-finish flush _hookFailReasons: [], _insightsHandler: undefined, _percyHandler: undefined, - _cliTestUuids: new Map(), saveWorkerData: vi.fn() } } diff --git a/packages/browserstack-service/tests/service.test.ts b/packages/browserstack-service/tests/service.test.ts index aa32efbc..83d003f8 100644 --- a/packages/browserstack-service/tests/service.test.ts +++ b/packages/browserstack-service/tests/service.test.ts @@ -13,6 +13,7 @@ import AutomationFramework from '../src/cli/frameworks/automationFramework.js' import WdioCucumberTestFramework from '../src/cli/frameworks/wdioCucumberTestFramework.js' import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' +import TestFramework from '../src/cli/frameworks/testFramework.js' import { AutomationFrameworkConstants } from '../src/cli/frameworks/constants/automationFrameworkConstants.js' import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' @@ -2652,157 +2653,43 @@ describe('_isAppAutomate honors skipAppOverride', () => { }) }) -describe('afterTest bail skip cascade (SDK-7063)', () => { +describe('beforeTest passes mocha\'s bail to the CLI framework (SDK-7063)', () => { + // the cascade itself runs in WdioMochaTestFramework (tests/cli/wdioMochaTestFramework.bailCascade.test.ts) let getInstanceSpy: ReturnType - // reportSkippedTest de-dupes on `${parent} - ${title}` in a module-scope Set that outlives - // each test, so every case here needs its own titles. - const buildTree = (tag: string) => { - const root: any = { title: '', tests: [], suites: [], parent: undefined } - const suiteA: any = { title: `${tag} Suite A`, tests: [], suites: [], parent: root } - const suiteB: any = { title: `${tag} Suite B`, tests: [], suites: [], parent: root } - root.suites.push(suiteA, suiteB) - - const ran: any = { title: `${tag} A1`, state: 'passed', parent: suiteA, file: '/spec/a.js' } - const failing: any = { title: `${tag} A2`, state: 'failed', parent: suiteA, file: '/spec/a.js' } - const dropped: any = { title: `${tag} A3`, parent: suiteA, file: '/spec/a.js' } - suiteA.tests.push(ran, failing, dropped) - // sibling top-level describe — only reachable because the cascade walks up to root - suiteB.tests.push({ title: `${tag} B1`, parent: suiteB, file: '/spec/a.js' }) - - failing.ctx = { test: { parent: suiteA } } - return { failing, root } - } - const makeService = (config: Record) => new BrowserstackService( { testObservability: false } as any, [] as any, { user: 'foo', key: 'bar', ...config } as any ) - const runAfterTest = async (svc: BrowserstackService, failing: any, results: Record) => { + const bailSent = async (config: Record) => { const trackEvent = vi.fn().mockResolvedValue(undefined) getInstanceSpy = vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true, getTestFramework: () => ({ trackEvent }) } as any) - await svc.afterTest(failing, undefined as never, results as any) - return trackEvent + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as any) + vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid' as any) + await makeService(config).beforeTest({ title: 'test', parent: 'suite' } as any) + const [, , args] = trackEvent.mock.calls.find(([state, hook]: any[]) => state === TestFrameworkState.TEST && hook === HookState.PRE)! + return args.bail } - // WHICH tests got reported, not just how many events fired — a cascade that swept the wrong - // tests still produces the same call count. Pairs with the count assertions, which catch the - // opposite failure (a test emitted twice). - const skippedTitles = (trackEvent: ReturnType) => [...new Set( - trackEvent.mock.calls - .filter(([, , payload]: any[]) => payload?.result?.skipped === true) - .map(([, , payload]: any[]) => payload.test.title as string) - )].sort() - afterEach(() => { getInstanceSpy?.mockRestore() + vi.mocked(TestFramework.getTrackedInstance).mockRestore() + vi.mocked(TestFramework.getState).mockRestore() }) - it('reports un-run tests across sibling describes when mocha bail is on', async () => { - const { failing } = buildTree('bail1') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - - // 2 events close the failing test (LOG_REPORT/POST + TEST/POST), then 4 per skipped test. - // A3 (same describe) and B1 (SIBLING describe) => 2 skipped => 8. - expect(trackEvent).toHaveBeenCalledTimes(2 + 8) - // exactly the un-run tests: A1 already passed and A2 is the failure being reported, - // so sweeping either of them in would be a defect the count alone cannot see - expect(skippedTitles(trackEvent)).toEqual(['bail1 A3', 'bail1 B1']) + it('sends bail when mocha bail is on', async () => { + expect(await bailSent({ framework: 'mocha', mochaOpts: { bail: true } })).toBe(true) }) - it('does not cascade when only wdio-level bail is set', async () => { + it('does not send bail when only wdio-level bail is set', async () => { // wdio's `bail` never halts a spec, so those tests still run — reporting them - // as skipped here would double-report them. - const { failing } = buildTree('bail2') - const svc = makeService({ framework: 'mocha', bail: 1 }) - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade while a wdio spec-file retry is still queued', async () => { - const { failing } = buildTree('bail3') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 2 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade while a MOCHA-level retry is still queued', async () => { - // wdio's `results.retries` only tracks spec-file retries — @wdio/mocha-framework never - // feeds mochaOpts.retries into it, so it reads {0,0} here and cannot be relied on. - // Without reading mocha's own runnable state the cascade fires on attempt 1 and reports - // tests as skipped that the retry then actually runs. - const { failing } = buildTree('bail5') - failing.ctx.test.currentRetry = () => 0 - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true, retries: 1 } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 0 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('cascades once the final mocha retry has been used', async () => { - const { failing } = buildTree('bail6') - failing.ctx.test.currentRetry = () => 1 - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true, retries: 1 } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 0 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2 + 8) - expect(skippedTitles(trackEvent)).toEqual(['bail6 A3', 'bail6 B1']) - }) - - it('does not cascade when the test passed', async () => { - const { failing } = buildTree('bail4') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: true }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade when the test was itself skipped', async () => { - // a skipped test does not abort the spec, and the pre-existing skip paths already - // report it — cascading here would double-report the rest of the suite - const { failing } = buildTree('bail7') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: false, skipped: true }) - - // A2 is the test being reported and its own result is legitimately `skipped`; what must - // NOT appear is A3/B1, which the cascade would have added. - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual(['bail7 A2']) - }) - - it('never throws out of afterTest when mocha state is hostile', async () => { - // afterTest is awaited by wdio; anything escaping this cascade would surface as a - // framework-level error in the user's run - const { failing } = buildTree('bail8') - failing.ctx.test.currentRetry = () => { throw new Error('mocha exploded') } - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - expect(skippedTitles(trackEvent)).toEqual([]) + // as skipped would double-report them. + expect(await bailSent({ framework: 'mocha', bail: 1 })).toBe(false) }) }) diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts index abd665d0..789182a2 100644 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -8,29 +8,21 @@ import TestFramework from '../src/cli/frameworks/testFramework.js' import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' -import { awaitCliTestFinishesOnFailure, cliTestAttemptKey, finishCliTestOnFailure, resetCliTestFinishers } from '../src/cli/earlyTestFinish.js' import * as bstackLogger from '../src/bstackLogger.js' vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) /** - * SDK-7843 — with a mocha timeout, mocha fails the test (and tells reporters) while its body and - * wdio's afterTest are still pending; with `bail`, wdio then runs after() before that afterTest. - * These drive the service hooks in exactly that order. + * SDK-7843 — with a mocha timeout, mocha fails the test (the reporter sends its finish) while its + * body and wdio's afterTest are still pending; with `bail`, wdio then runs after() before that + * afterTest. after() must let that finish land before the flush and before EXECUTE/POST, where + * AutomateModule marks the session status. */ -describe('service — a timed-out mocha test is finished when mocha fails it (SDK-7843)', () => { +describe('service after() — settles test finishes before the session status is marked (SDK-7843)', () => { let events: string[] - let testTrackEvent: ReturnType - let flush: ReturnType - // the single tracked-instance slot the CLI reads the test uuid from - let slotUuid: string | undefined - let minted: number - - const makeTest = (title: string, extra: Record = {}) => - ({ title, parent: 'Suite', ctx: { test: {} }, ...extra }) as unknown as Frameworks.Test - const timedOutTest = makeTest('times out') - const failed = { passed: false, error: new Error('Timeout of 300000ms exceeded.'), duration: 300000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult + let settle: ReturnType + let trackEvent: ReturnType const makeService = () => new BrowserstackService( { testObservability: false } as never, @@ -39,202 +31,51 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD ) beforeEach(() => { - resetCliTestFinishers() events = [] - slotUuid = undefined - minted = 0 - // gRPC sends take real time; an instant mock would hide after() not waiting for the finish - testTrackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown, args: { result?: Frameworks.TestResult, test?: Frameworks.Test }) => { - if (state === TestFrameworkState.INIT_TEST) { - slotUuid = `uuid-${++minted}` - return - } - // the CLI reads the uuid when the event is handled, before the send - const uuid = slotUuid + // the reporter's finish is still being sent when after() starts + settle = vi.fn().mockImplementation(async () => { await new Promise((resolve) => setTimeout(resolve, 30)) - const result = args?.result ? ` ${args.result.skipped ? 'skipped' : `passed=${args.result.passed}`}` : '' - events.push(`${String(state)}/${String(hook)}${result}${state === TestFrameworkState.TEST && hook === HookState.POST ? ` ${args.test?.title} ${uuid}` : ''}`) + events.push('settleTestFinishes') }) - flush = vi.fn().mockImplementation(async () => { - events.push('flushPendingTestFinishEvent') + trackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + events.push(`${String(state)}/${String(hook)}`) }) vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true, - getTestFramework: () => ({ trackEvent: testTrackEvent }), + getTestFramework: () => ({ trackEvent, settleTestFinishes: settle }), getAutomationFramework: () => ({ trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { events.push(`${String(state)}/${String(hook)}`) }) }), - modules: { TestHubModule: { flushPendingTestFinishEvent: flush } } + modules: { TestHubModule: { flushPendingTestFinishEvent: vi.fn().mockImplementation(async () => { events.push('flushPendingTestFinishEvent') }) } } } as never) vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as never) - vi.spyOn(TestFramework, 'getState').mockImplementation(() => slotUuid as never) - vi.spyOn(TestFramework, 'setState').mockImplementation((_instance: unknown, _key: unknown, value: unknown) => { - slotUuid = value as string - }) + vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid-1' as never) }) afterEach(() => { vi.restoreAllMocks() }) - const testPosts = () => events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`)) - - it('reports the failure, then marks the session, then ignores the late afterTest', async () => { - const service = makeService() - await service.beforeTest(timedOutTest) - events.length = 0 - - // mocha's `fail` reaches the reporter first... - expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) - // ...then wdio runs after() before the timed-out test's afterTest - await service.after(1) - // ...and only then the late afterTest - await service.afterTest(timedOutTest, undefined as never, { ...failed }) + it('settles before the deferred-finish flush and before EXECUTE/POST', async () => { + await makeService().after(1) - const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out uuid-1`) - const flushAt = events.indexOf('flushPendingTestFinishEvent') - const sessionStatusAt = events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`) - expect(testPost).toBeGreaterThanOrEqual(0) - // the failure is recorded before the deferred-finish flush and before EXECUTE/POST, - // which is where AutomateModule marks the session status - expect(testPost).toBeLessThan(flushAt) - expect(flushAt).toBeLessThan(sessionStatusAt) - // reported once: the late afterTest added no second LOG_REPORT/TEST POST - expect(testPosts()).toHaveLength(1) - expect(events.filter((e) => e.startsWith(`${TestFrameworkState.LOG_REPORT}/${HookState.POST}`))).toHaveLength(1) + expect(events).toEqual(['settleTestFinishes', 'flushPendingTestFinishEvent', `${AutomationFrameworkState.EXECUTE}/${HookState.POST}`]) }) - it('without a reporter, after() still finishes a test mocha failed, from mocha\'s runnable', async () => { + it('leaves the tracked test run alone in afterTest; the CLI framework picks the test\'s own', async () => { + const setState = vi.spyOn(TestFramework, 'setState') const service = makeService() - const runnable = { state: undefined as string | undefined, timedOut: false, timeout: () => 10000, duration: 0 } - const test = makeTest('times out unreported', { ctx: { test: runnable } }) - await service.beforeTest(test) - events.length = 0 + const test = { title: 'times out', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test - // mocha's timeout: Runner#fail sets the state; no reporter hears the `fail` - Object.assign(runnable, { state: 'failed', timedOut: true, duration: 10001 }) - await service.after(1) - await service.afterTest(test, undefined as never, { ...failed }) - - const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out unreported uuid-1`) - expect(testPost).toBeGreaterThanOrEqual(0) - expect(testPost).toBeLessThan(events.indexOf('flushPendingTestFinishEvent')) - expect(testPost).toBeLessThan(events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`)) - expect(testPosts()).toHaveLength(1) - }) - - it('runs the bail cascade from the reporter path, before the flush', async () => { - const service = makeService() - const root: { title: string, tests: unknown[], suites: unknown[], parent?: unknown } = { title: '', tests: [], suites: [] } - const suite = { title: 'Suite', parent: root, tests: [] as unknown[], suites: [] } - root.suites.push(suite) - suite.tests.push({ title: 'never reached', parent: suite, state: undefined, file: '/spec.js', body: '' }) - const test = makeTest('times out with bail', { ctx: { test: { parent: suite } } }) await service.beforeTest(test) - events.length = 0 - - expect(finishCliTestOnFailure('Suite - times out with bail', failed)).toBe(true) - await service.after(1) + await service.afterTest(test, undefined as never, { passed: false, error: new Error('Timeout'), duration: 1 } as Frameworks.TestResult) - const failedAt = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out with bail uuid-1`) - const skippedAt = events.findIndex((e) => e.includes('skipped never reached')) - const flushAt = events.indexOf('flushPendingTestFinishEvent') - expect(failedAt).toBeGreaterThanOrEqual(0) - expect(skippedAt).toBeGreaterThan(failedAt) - expect(skippedAt).toBeLessThan(flushAt) - }) - - it('closes the timed-out test with its own uuid even when the next test took the slot meanwhile', async () => { - const service = makeService() - const next = makeTest('next test') - await service.beforeTest(timedOutTest) - events.length = 0 - - // the reporter starts the finish; mocha (no bail) moves on to the next test during its LOG_REPORT send - expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(true) - await service.beforeTest(next) - await awaitCliTestFinishesOnFailure() - - expect(testPosts()).toEqual([`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out uuid-1`]) - // and the slot is handed back to the test now running - expect(slotUuid).toBe('uuid-2') - }) - - it('lets a retried attempt\'s late afterTest close that attempt, not the next one', async () => { - const service = makeService() - const attempt0 = makeTest('flaky', { _currentRetry: 0 }) - const attempt1 = makeTest('flaky', { _currentRetry: 1 }) - await service.beforeTest(attempt0) - // attempt 0 timed out and is retried (mocha emits `retry`, not `fail`); attempt 1 starts - await service.beforeTest(attempt1) - events.length = 0 - - // attempt 0's late afterTest - await service.afterTest(attempt0, undefined as never, { ...failed }) - // attempt 1 times out too: the reporter can still report it - expect(finishCliTestOnFailure(cliTestAttemptKey('Suite - flaky', 1), failed)).toBe(true) - await service.after(1) - - expect(testPosts()).toEqual([ - `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky uuid-1`, - `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky uuid-2` + expect(setState).not.toHaveBeenCalled() + expect(events.filter((e) => e.startsWith(TestFrameworkState.TEST))).toEqual([ + `${TestFrameworkState.TEST}/${HookState.PRE}`, + `${TestFrameworkState.TEST}/${HookState.POST}` ]) }) - - it('still reports a normal failure from afterTest, and the reporter then does nothing', async () => { - const service = makeService() - await service.beforeTest(timedOutTest) - events.length = 0 - - await service.afterTest(timedOutTest, undefined as never, { ...failed }) - expect(finishCliTestOnFailure('Suite - times out', failed)).toBe(false) - - expect(testPosts()).toHaveLength(1) - }) - - it('reports afterTest for a test it never saw start, as before', async () => { - const service = makeService() - - await service.afterTest(makeTest('unseen'), undefined as never, { passed: true } as Frameworks.TestResult) - - expect(testPosts()).toHaveLength(1) - }) - - it('without a reporter, a timed-out test whose body finishes late is still reported failed', async () => { - const service = makeService() - const runnable = { state: undefined as string | undefined, timedOut: false, timeout: () => 10000, duration: 0 } - const test = makeTest('times out then succeeds', { ctx: { test: runnable } }) - await service.beforeTest(test) - events.length = 0 - - // mocha times it out (no reporter hears it); the body then succeeds, so wdio's late - // afterTest says passed — before after() runs - Object.assign(runnable, { state: 'failed', timedOut: true, duration: 10001 }) - await service.afterTest(test, undefined as never, { passed: true } as Frameworks.TestResult) - await service.after(1) - - expect(testPosts()).toEqual([`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out then succeeds uuid-1`]) - }) - - it('runs the bail cascade from the runnable it captured, not the hook mocha moved on to', async () => { - const service = makeService() - const root: { title: string, tests: unknown[], suites: unknown[] } = { title: '', tests: [], suites: [] } - const suite = { title: 'Suite', parent: root, tests: [] as unknown[], suites: [] } - root.suites.push(suite) - suite.tests.push({ title: 'dropped by bail', parent: suite, state: undefined, file: '/spec.js', body: '' }) - // final attempt of a test under `retries: 1` - const ctx = { test: { parent: suite, currentRetry: () => 1, retries: () => 1 } as unknown } - const test = makeTest('times out on last attempt', { ctx, _currentRetry: 1 }) - await service.beforeTest(test) - events.length = 0 - - // mocha fails it and moves on to an afterEach hook, which inherits the suite's retries - ctx.test = { parent: suite, currentRetry: () => 0, retries: () => 1 } - expect(finishCliTestOnFailure(cliTestAttemptKey('Suite - times out on last attempt', 1), failed)).toBe(true) - await service.after(1) - - expect(events.some((e) => e.includes('skipped dropped by bail'))).toBe(true) - }) }) From f51407ea05917ab7d78bf84e8886b9e51ef0b162 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Fri, 9 Oct 2026 13:06:08 +0530 Subject: [PATCH 8/9] fix(cli): report each mocha test once by its own attempt, not by its name (SDK-7843) A finished attempt's key went into `finishedAttempts` and was never cleared. The key is `${parent} - ${title}` with only the immediate parent, so a later test with the same key in a worker (e.g. login > valid > works and signup > valid > works) had every finish dropped: it stayed In Progress in Test Reporting and its failure never reached the session status. Two same-key attempts open at once (a timed-out test's late afterTest) also overwrote each other's entry. Track finished per attempt. Resolve wdio's afterTest by the test's body (`fn`, on both the beforeTest and afterTest copies of the mocha test) plus retry, and the reporter's `fail`, which has only title and parent, by the latest attempt with that key, resolved before any await so it is the test mocha just failed. Pin the resolved attempt to the event's `test` object so the same source's TEST/POST cannot land on a later same-named test. `file::fullTitle` (review suggestion) cannot key both sides: wdio's hook copy `{ ...context.test }` drops mocha's prototype `fullTitle()`, and the reporter's TestStats has no `file`. Co-Authored-By: Claude Opus 5.5 --- .../cli/frameworks/wdioMochaTestFramework.ts | 77 +++++++++++++++---- ...dioMochaTestFramework.timedOutTest.test.ts | 46 +++++++++++ 2 files changed, 109 insertions(+), 14 deletions(-) diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index b745f725..a3234efe 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -59,6 +59,8 @@ interface TestAttempt { bail?: boolean /** Who is reporting this attempt's finish: wdio's afterTest, or the reporter's `fail`. */ finishingFrom?: 'afterTest' | 'fail' + /** Its TEST/POST has been reported. */ + finished?: boolean } /** The failure mocha recorded on a runnable (it keeps no error object on it). */ @@ -83,8 +85,20 @@ export default class WdioMochaTestFramework extends TestFramework { * slot, or not at all before the session status is marked. Each attempt keeps the instance it * started on, so its finish is reported against its own test run, once. */ - private openAttempts = new Map() - private finishedAttempts = new Set() + private openAttempts = new Set() + /** + * The latest attempt started under each `attemptKey`. The key holds only the immediate parent's + * title, so two tests in a worker can share it; the later one's TEST/PRE replaces the entry. + */ + private latestAttemptByKey = new Map() + /** + * Attempts by the test's body. wdio hands beforeTest and afterTest separate copies of the mocha + * test (`{ ...context.test }`), but both carry its `fn`, so afterTest finds its own attempt even + * when another test with the same key has started since. + */ + private attemptsByFn = new WeakMap>() + /** The attempt a source's LOG_REPORT/POST resolved; its TEST/POST passes the same `test` object. */ + private resolvedFinishes = new WeakMap() private pendingFinishes = new Set>() /** One attempt of a test: mocha retries a test as a new runnable with `_currentRetry` + 1. */ @@ -94,6 +108,11 @@ export default class WdioMochaTestFramework extends TestFramework { return retry ? `${identifier} (retry ${retry})` : identifier } + private static testBody(test: Frameworks.Test): object | undefined { + const fn = (test as { fn?: unknown }).fn + return typeof fn === 'function' ? fn : undefined + } + /** * Constructor for the TestFramework * @param {Array} testFrameworks - List of Test frameworks @@ -126,6 +145,9 @@ export default class WdioMochaTestFramework extends TestFramework { private async trackTestEvent(testFrameworkState: State, hookState: State, args: Record) { logger.info(`trackEvent: testFrameworkState=${testFrameworkState} hookState=${hookState}`) + // before any await: the reporter's `fail` must resolve to the attempt mocha just failed, + // before mocha starts the next test (it defers that with setImmediate) + const attempt = this.resolveTestAttempt(testFrameworkState, hookState, args) await super.trackEvent(testFrameworkState, hookState, args) // Console output from wdio's `before` hook (after the service has patched console) @@ -137,7 +159,6 @@ export default class WdioMochaTestFramework extends TestFramework { return } - const attempt = this.resolveTestAttempt(testFrameworkState, hookState, args) if (attempt === null) { return } @@ -272,13 +293,39 @@ export default class WdioMochaTestFramework extends TestFramework { /** TEST/PRE: this attempt's finish is owed from here on, against this instance. */ private openTestAttempt(instance: TestFrameworkInstance, args: Record) { const test = args.test as Frameworks.Test - this.openAttempts.set(WdioMochaTestFramework.attemptKey(test), { + const attempt: TestAttempt = { instance, test, suiteTitle: args.suiteTitle, runnable: test.ctx?.test as MochaRunnable | undefined, bail: args.bail === true - }) + } + this.openAttempts.add(attempt) + this.latestAttemptByKey.set(WdioMochaTestFramework.attemptKey(test), attempt) + const body = WdioMochaTestFramework.testBody(test) + if (body) { + const byRetry = this.attemptsByFn.get(body) ?? new Map() + byRetry.set((test as { _currentRetry?: number })._currentRetry ?? 0, attempt) + this.attemptsByFn.set(body, byRetry) + } + } + + /** + * The attempt a finish belongs to. wdio's afterTest carries the test's body, which identifies + * it exactly. The reporter's `fail` has only the title and parent: it is resolved (before any + * await, see trackTestEvent) to the latest attempt with that key, which is the one mocha just + * failed, and pinned so the same source's TEST/POST cannot land on a later same-named test. + */ + private findTestAttempt(test: Frameworks.Test): TestAttempt | undefined { + const resolved = this.resolvedFinishes.get(test) + if (resolved) { + return resolved + } + const body = WdioMochaTestFramework.testBody(test) + if (body) { + return this.attemptsByFn.get(body)?.get((test as { _currentRetry?: number })._currentRetry ?? 0) + } + return this.latestAttemptByKey.get(WdioMochaTestFramework.attemptKey(test)) } /** @@ -292,18 +339,19 @@ export default class WdioMochaTestFramework extends TestFramework { if (!isFinish || !args.test) { return undefined } - const key = WdioMochaTestFramework.attemptKey(args.test as Frameworks.Test) + const test = args.test as Frameworks.Test const source = args.fromMochaFail ? 'fail' : 'afterTest' - const attempt = this.openAttempts.get(key) - if (this.finishedAttempts.has(key) || (attempt?.finishingFrom && attempt.finishingFrom !== source)) { - logger.debug(`trackEvent: '${key}' was already reported, dropping ${testFrameworkState} ${hookState} from ${source}`) - return null - } + const attempt = this.findTestAttempt(test) if (!attempt) { // the reporter's `fail` for a hook, or for a test that never started return source === 'fail' ? null : undefined } + if (attempt.finished || (attempt.finishingFrom && attempt.finishingFrom !== source)) { + logger.debug(`trackEvent: '${WdioMochaTestFramework.attemptKey(test)}' was already reported, dropping ${testFrameworkState} ${hookState} from ${source}`) + return null + } attempt.finishingFrom = source + this.resolvedFinishes.set(test, attempt) args.suiteTitle ??= attempt.suiteTitle // a timed-out test whose body finished late: wdio's result says only whether the body // threw, not that mocha already failed it @@ -311,8 +359,8 @@ export default class WdioMochaTestFramework extends TestFramework { args.result = failureFromRunnable(attempt.runnable) } if (testFrameworkState === TestFrameworkState.TEST) { - this.openAttempts.delete(key) - this.finishedAttempts.add(key) + attempt.finished = true + this.openAttempts.delete(attempt) } return attempt } @@ -323,9 +371,10 @@ export default class WdioMochaTestFramework extends TestFramework { * Accessibility and Percy are all off), then wait for every finish the reporter started. */ async settleTestFinishes(): Promise { - for (const attempt of [...this.openAttempts.values()]) { + for (const attempt of [...this.openAttempts]) { if (attempt.runnable?.state === 'failed' && !attempt.finishingFrom) { const result = failureFromRunnable(attempt.runnable) + this.resolvedFinishes.set(attempt.test, attempt) await this.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: attempt.test, result, fromMochaFail: true }) await this.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: attempt.test, result, suiteTitle: attempt.suiteTitle, fromMochaFail: true }) } diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts index 932ce0ae..3c675377 100644 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts @@ -146,6 +146,52 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its expect(finishes).toEqual([`flaky ${uuid0} passed=false`, `flaky ${uuid1} passed=false`]) }) + // `attemptKey` holds only the immediate parent's title, so these share `valid - works`: + // describe('login', () => describe('valid', () => it('works'))) and the same under 'signup' + it('reports a later test that shares an earlier finished test\'s key', async () => { + const first = makeTest('works', { parent: 'valid' }) + const firstUuid = await start(first) + await afterTest(first, passed) + const second = makeTest('works', { parent: 'valid' }) + const secondUuid = await start(second) + await afterTest(second, failed) + + expect(finishes).toEqual([`works ${firstUuid} passed=true`, `works ${secondUuid} passed=false`]) + }) + + it('closes a late afterTest by the test\'s body when a same-named test has started since', async () => { + // wdio hands beforeTest and afterTest separate copies of the mocha test; both carry its fn + const first = makeTest('works', { parent: 'valid', fn: () => {} }) + const firstUuid = await start(first) + reporterFail(makeTest('works', { parent: 'valid' })) + await framework.settleTestFinishes() + const second = makeTest('works', { parent: 'valid', fn: () => {} }) + const secondUuid = await start(second) + + // the first test's body finishes late (and succeeds) while the second test is running; the + // second then fails on its own + await afterTest({ ...first } as Frameworks.Test, passed) + await afterTest({ ...second } as Frameworks.Test, failed) + + expect(finishes).toEqual([`works ${firstUuid} passed=false`, `works ${secondUuid} passed=false`]) + }) + + it('keeps the reporter\'s TEST/POST on the test its LOG_REPORT resolved, if a same-named test starts in between', async () => { + const first = makeTest('works', { parent: 'valid', fn: () => {} }) + const firstUuid = await start(first) + const failed1 = makeTest('works', { parent: 'valid' }) + // mocha's `fail`: LOG_REPORT resolves now; TEST/POST is sent after it, by when mocha may + // have started the next test + const logReport = framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failed1, result: failed, fromMochaFail: true }) + const second = makeTest('works', { parent: 'valid', fn: () => {} }) + const secondUuid = await start(second) + await logReport + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failed1, result: failed, fromMochaFail: true }) + await afterTest({ ...second } as Frameworks.Test, passed) + + expect(finishes).toEqual([`works ${firstUuid} passed=false`, `works ${secondUuid} passed=true`]) + }) + it('drops a `fail` for a test that never started (a hook), and still reports afterTest for one it never saw', async () => { await start(makeTest('runs')) From 2d7bba79299d24e893877ec18254aec3c1b46cb4 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Fri, 9 Oct 2026 14:28:14 +0530 Subject: [PATCH 9/9] fix(cli): run the bail cascade of a reporter-reported failure from settle (SDK-7843) wdio does not await the reporter's `fail`, and mocha still runs the failed test's after-hooks after it. Running the bail cascade inside that finish let its immediate skip reports claim the tracked slot while those hooks ran, so their events could attach to a skipped test. Record the cascade on that path and run it from settleTestFinishes(), which after() awaits before the flush and EXECUTE/POST. The afterTest path still cascades inline. Co-Authored-By: Claude Opus 5.5 --- .../cli/frameworks/wdioMochaTestFramework.ts | 22 +++++++++++++++---- .../src/cli/skipReporter.ts | 6 +++-- ...wdioMochaTestFramework.bailCascade.test.ts | 21 ++++++++++++++++++ 3 files changed, 43 insertions(+), 6 deletions(-) diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index a3234efe..dd2c39d8 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -100,6 +100,8 @@ export default class WdioMochaTestFramework extends TestFramework { /** The attempt a source's LOG_REPORT/POST resolved; its TEST/POST passes the same `test` object. */ private resolvedFinishes = new WeakMap() private pendingFinishes = new Set>() + /** Bail cascades of failures the reporter's `fail` reported; settleTestFinishes() runs them. */ + private owedBailCascades: Array<{ attempt: TestAttempt, result: Frameworks.TestResult }> = [] /** One attempt of a test: mocha retries a test as a new runnable with `_currentRetry` + 1. */ static attemptKey(test: Frameworks.Test): string { @@ -229,7 +231,13 @@ export default class WdioMochaTestFramework extends TestFramework { args.instance = instance await this.runHooks(instance, testFrameworkState, hookState, args) if (attempt && testFrameworkState === TestFrameworkState.TEST) { - await this.reportBailSkippedTests(attempt, args.result as Frameworks.TestResult) + if (args.fromMochaFail) { + // wdio does not await the reporter's `fail`, and mocha still runs the failed test's + // after-hooks: the cascade's skip reports would claim the tracked slot under them + this.owedBailCascades.push({ attempt, result: args.result as Frameworks.TestResult }) + } else { + await this.reportBailSkippedTests(attempt, args.result as Frameworks.TestResult) + } } } @@ -264,8 +272,10 @@ export default class WdioMochaTestFramework extends TestFramework { * it is handed to one mocha instance. Cascading across them is still correct: bail aborts that * whole runner, so those tests do not run either. * - * Runs as part of the failed test's finish, so it lands before the session status is marked - * and the last test finish is flushed, also when that finish came from mocha's `fail` (SDK-7843). + * Runs as part of the failed test's finish when that comes from afterTest, which wdio awaits. + * When it comes from the reporter's `fail`, which wdio does not await, settleTestFinishes() + * runs it instead: bail has already aborted the spec, and that still lands before the session + * status is marked and the last test finish is flushed (SDK-7843). */ private async reportBailSkippedTests(attempt: TestAttempt, results: Frameworks.TestResult | undefined) { if (!attempt.bail || !results || results.passed || results.skipped) { @@ -368,7 +378,8 @@ export default class WdioMochaTestFramework extends TestFramework { /** * Before the session status is marked and the last test finish is flushed: finish every attempt * mocha already failed that nothing reported (no reporter is registered when Test Reporting, - * Accessibility and Percy are all off), then wait for every finish the reporter started. + * Accessibility and Percy are all off), then wait for every finish the reporter started, then + * run the bail cascades those finishes owe. */ async settleTestFinishes(): Promise { for (const attempt of [...this.openAttempts]) { @@ -382,6 +393,9 @@ export default class WdioMochaTestFramework extends TestFramework { while (this.pendingFinishes.size > 0) { await Promise.all([...this.pendingFinishes]) } + for (const { attempt, result } of this.owedBailCascades.splice(0)) { + await this.reportBailSkippedTests(attempt, result) + } } /** diff --git a/packages/browserstack-service/src/cli/skipReporter.ts b/packages/browserstack-service/src/cli/skipReporter.ts index 4fff79d5..76cb2bec 100644 --- a/packages/browserstack-service/src/cli/skipReporter.ts +++ b/packages/browserstack-service/src/cli/skipReporter.ts @@ -128,7 +128,8 @@ export function reportSkippedTest( const queued: QueuedSkip = { framework, test, result, suiteTitle } // SDK-7493: only the DETACHED caller needs deferring. `immediate` is for callers wdio - // awaits — the hook cascade (afterHook) and the bail cascade (afterTest). Those never had + // awaits — the hook cascade (afterHook) and the bail cascade (afterTest; when the reporter's + // `fail` reported the failure, from service.after() instead, SDK-7843). Those never had // the interleave, because wdio holds the lifecycle open until they resolve, so nothing else // can claim the tracked slot underneath them. Deferring those too would be a behaviour // change for no benefit: their skips would move to end-of-run and their reports would no @@ -158,7 +159,8 @@ export function reportSkippedTest( * suite — report each state-undefined test as skipped, recursing into nested describes. * * Reports IMMEDIATELY (SDK-7493): every caller of this — the failed-hook cascade in - * `afterHook` and the bail cascade in `afterTest` — is awaited by wdio, so these reports + * `afterHook` and the bail cascade in `afterTest` (or in `after()`, for a failure the reporter's + * `fail` reported, SDK-7843) — is awaited by wdio, so these reports * cannot interleave with a live test the way the un-awaited `onTestSkip` path could. They * belong to the hook/test being reported, so they must not slide to end-of-run. */ diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts index 2d89ce19..2db8f605 100644 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts @@ -6,6 +6,7 @@ import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramew import TestFramework from '../../src/cli/frameworks/testFramework.js' import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' import { HookState } from '../../src/cli/states/hookState.js' +import { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.js' import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) @@ -133,10 +134,30 @@ describe('mocha bail skip cascade (SDK-7063), run by the CLI framework with the await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.settleTestFinishes() expect(skippedTitles()).toEqual(['bail9 A3', 'bail9 B1']) }) + it('runs the cascade for a failure reported by mocha\'s `fail` from settle, not under the test\'s after-hooks (SDK-7843)', async () => { + const { failing } = buildTree('bail10') + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + const failedUuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) + trackEvent.mockClear() + + // the reporter's `fail`, which wdio does not await; mocha then runs the test's afterEach + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.AFTER_EACH, HookState.PRE, { test: failing }) + + expect(skippedTitles()).toEqual([]) + expect(TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID)).toBe(failedUuid) + + await framework.settleTestFinishes() + expect(skippedTitles()).toEqual(['bail10 A3', 'bail10 B1']) + }) + it('does not cascade when the test passed', async () => { const { failing } = buildTree('bail4') await runTest(failing, { passed: true })