From d9774a2cf33d30b8a5529c87186c6088380540c2 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 11:25:06 +0530 Subject: [PATCH 01/12] fix(cli): record a timed-out mocha test's failure when mocha reports it (SDK-7843) v8 port of the main-line fix. When a mocha test hits its timeout, mocha fails it while the body and wdio's afterTest are still pending. With `bail`, or on the worker's last test, wdio runs after() first, so on the CLI flow AutomateModule.onAfterExecute marks the session `passed`: its results only come from afterTest. The classic flow reads after(result) and was correct. The service now registers a finisher per mocha test in beforeTest (cli/earlyTestFinish.ts). The reporter's onTestFail reports the failure through it when mocha fails the test. after() waits for those finishes before EXECUTE/POST, and the late afterTest stands down for a test that was already reported. v8 sends TEST/POST inline (no deferred finish), so its Test Reporting results were already right; this fixes the session status. 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 | 33 +++++- .../tests/cli/earlyTestFinish.test.ts | 71 ++++++++++++ .../tests/reporter.onTestFail.test.ts | 58 ++++++++++ .../tests/service.timedOutTestFinish.test.ts | 102 ++++++++++++++++++ 6 files changed, 360 insertions(+), 2 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 d9449827..41669a61 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' @@ -144,6 +145,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 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 9c89a4d4..ab9a005a 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -37,6 +37,7 @@ import { BrowserstackCLI } from './cli/index.js' import { TestFrameworkState } from './cli/states/testFrameworkState.js' import { HookState } from './cli/states/hookState.js' import { markTestStarted, reportSuiteSkipped } from './cli/skipReporter.js' +import { awaitCliTestFinishesOnFailure, claimCliTestFinish, registerCliTestFinisher } from './cli/earlyTestFinish.js' import { AutomationFrameworkState } from './cli/states/automationFrameworkState.js' import TestFramework from './cli/frameworks/testFramework.js' import { TestFrameworkConstants } from './cli/frameworks/constants/testFrameworkConstants.js' @@ -504,6 +505,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 @@ -526,8 +533,13 @@ export default class BrowserstackService implements Services.ServiceInstance { } if (BrowserstackCLI.getInstance().isRunning()) { - 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, suiteTite: this._suiteTitle }) + 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 this.finishCliTest(test, results) return } await this._accessibilityHandler?.afterTest(this._suiteTitle, test) @@ -535,12 +547,29 @@ export default class BrowserstackService implements Services.ServiceInstance { await this._percyHandler?.afterTest() } + /** + * Report a mocha test's finish on the CLI flow. 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) { + 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, suiteTite: this._suiteTitle }) + } + async after (result: number) { PerformanceTester.start(PERFORMANCE_SDK_EVENTS.HOOK_EVENTS.AFTER) PerformanceTester.start(PERFORMANCE_SDK_EVENTS.DRIVER_EVENT.QUIT) try { if (BrowserstackCLI.getInstance().isRunning()) { + // SDK-7843: a test that timed out was reported by the reporter when mocha failed it, + // which can still be in flight. EXECUTE/POST marks the session status from the + // results recorded so far, so wait for it first. + try { + await awaitCliTestFinishesOnFailure() + } catch (finishErr) { + BStackLogger.debug(`Exception awaiting failed-test finishes in after(): ${finishErr}`) + } await BrowserstackCLI.getInstance().getAutomationFramework()!.trackEvent(AutomationFrameworkState.EXECUTE, HookState.POST, {}) } const { preferScenarioName, setSessionName, setSessionStatus } = this._options 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..2f0b3227 --- /dev/null +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -0,0 +1,102 @@ +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 + + 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}` : ''}`) + }) + 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)}`) + }) + }) + } 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 sessionStatusAt = events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`) + expect(testPost).toBeGreaterThanOrEqual(0) + // the failure is recorded before EXECUTE/POST, which is where AutomateModule marks the + // session status + expect(testPost).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 ef24eba9905c866956f2a118bcd161cedf76e7c6 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:55:46 +0000 Subject: [PATCH 02/12] chore(changeset): auto-generate from PR template (patch) --- .changeset/pr-273.md | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 .changeset/pr-273.md diff --git a/.changeset/pr-273.md b/.changeset/pr-273.md new file mode 100644 index 00000000..953043df --- /dev/null +++ b/.changeset/pr-273.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. Such sessions are now marked failed, with the timeout error as the reason. From 12a43c514dab3ae430150559c0e66c1f5e4d6372 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 16:01:27 +0530 Subject: [PATCH 03/12] 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 #265. 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 b5706ee2..a4457a06 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -37,6 +37,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 f83d9be291dba1fa67e8f9f925ec02f87333be2c 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:31:54 +0000 Subject: [PATCH 04/12] chore(changeset): auto-generate from PR template (patch) --- .changeset/pr-273.md | 1 + 1 file changed, 1 insertion(+) diff --git a/.changeset/pr-273.md b/.changeset/pr-273.md index 953043df..73642b05 100644 --- a/.changeset/pr-273.md +++ b/.changeset/pr-273.md @@ -3,3 +3,4 @@ --- - Fixed mocha tests that fail by exceeding their timeout being marked "passed" on the Automate / App Automate dashboard. Such sessions are now marked 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 ab144e5b8776bdb14e166d21b026697cb8040d2a Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 18:20:46 +0530 Subject: [PATCH 05/12] 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 per retry attempt, so a retried attempt's late afterTest closes that attempt and not the next one. - Drop the try/catch around awaitCliTestFinishesOnFailure(); every finish catches its own error. - Tests: no reporter, retries. Same changes as #272. 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 | 33 ++++---- .../tests/cli/earlyTestFinish.test.ts | 46 +++++++++++ .../tests/reporter.onTestFail.test.ts | 16 +++- .../tests/service.timedOutTestFinish.test.ts | 48 +++++++++++- 6 files changed, 181 insertions(+), 43 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 41669a61..4b8b1fb2 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' @@ -157,7 +157,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 ab9a005a..4dc9d3ba 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -37,7 +37,7 @@ import { BrowserstackCLI } from './cli/index.js' import { TestFrameworkState } from './cli/states/testFrameworkState.js' import { HookState } from './cli/states/hookState.js' import { markTestStarted, reportSuiteSkipped } from './cli/skipReporter.js' -import { awaitCliTestFinishesOnFailure, claimCliTestFinish, registerCliTestFinisher } from './cli/earlyTestFinish.js' +import { awaitCliTestFinishesOnFailure, claimCliTestFinish, cliTestAttemptKey, registerCliTestFinisher } from './cli/earlyTestFinish.js' import { AutomationFrameworkState } from './cli/states/automationFrameworkState.js' import TestFramework from './cli/frameworks/testFramework.js' import { TestFrameworkConstants } from './cli/frameworks/constants/testFrameworkConstants.js' @@ -484,6 +484,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) { @@ -509,7 +512,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 }) @@ -533,10 +536,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) @@ -556,20 +559,22 @@ export default class BrowserstackService implements Services.ServiceInstance { await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTite: this._suiteTitle }) } + /** 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) + } + async after (result: number) { PerformanceTester.start(PERFORMANCE_SDK_EVENTS.HOOK_EVENTS.AFTER) PerformanceTester.start(PERFORMANCE_SDK_EVENTS.DRIVER_EVENT.QUIT) try { if (BrowserstackCLI.getInstance().isRunning()) { - // SDK-7843: a test that timed out was reported by the reporter when mocha failed it, - // which can still be in flight. EXECUTE/POST marks the session status from the - // results recorded so far, so wait for it first. - try { - await awaitCliTestFinishesOnFailure() - } catch (finishErr) { - BStackLogger.debug(`Exception awaiting failed-test finishes in after(): ${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. EXECUTE/POST marks the session status from the results recorded so far, so + // wait for it first. Every finish catches its own error, so this cannot reject. + await awaitCliTestFinishesOnFailure() await BrowserstackCLI.getInstance().getAutomationFramework()!.trackEvent(AutomationFrameworkState.EXECUTE, HookState.POST, {}) } const { preferScenarioName, setSessionName, setSessionStatus } = this._options 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 2f0b3227..67405a73 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'))) @@ -36,9 +36,10 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD 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 }) => { + testTrackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown, args: { result?: Frameworks.TestResult, test?: Frameworks.Test }) => { await new Promise((resolve) => setTimeout(resolve, 30)) - events.push(`${String(state)}/${String(hook)}${args?.result ? ` passed=${args.result.passed}` : ''}`) + const title = state === TestFrameworkState.TEST && hook === HookState.POST ? ` ${args.test?.title} #${(args.test as { _currentRetry?: number })._currentRetry ?? 0}` : '' + events.push(`${String(state)}/${String(hook)}${args?.result ? ` passed=${args.result.passed}` : ''}${title}`) }) vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true, @@ -70,7 +71,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 #0`) const sessionStatusAt = events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`) expect(testPost).toBeGreaterThanOrEqual(0) // the failure is recorded before EXECUTE/POST, which is where AutomateModule marks the @@ -99,4 +100,43 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${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 = { title: 'times out unreported', parent: 'Suite', ctx: { test: runnable } } as unknown as Frameworks.Test + 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 #0`) + expect(testPost).toBeGreaterThanOrEqual(0) + expect(testPost).toBeLessThan(events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`)) + expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + }) + + it('lets a retried attempt\'s late afterTest close that attempt, not the next one', async () => { + const service = makeService() + const attempt0 = { title: 'flaky', parent: 'Suite', ctx: { test: {} }, _currentRetry: 0 } as unknown as Frameworks.Test + const attempt1 = { title: 'flaky', parent: 'Suite', ctx: { test: {} }, _currentRetry: 1 } as unknown as Frameworks.Test + 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(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toEqual([ + `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky #0`, + `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky #1` + ]) + }) }) From 78102f02f74eb730ba1bea763f985184350bb2a4 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Wed, 7 Oct 2026 19:11:17 +0530 Subject: [PATCH 06/12] fix(cli): keep mocha's verdict for a late afterTest (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. Same change as #272. Co-Authored-By: Claude Opus 5.5 --- .../src/cli/earlyTestFinish.ts | 27 +++++++++++++------ .../tests/cli/earlyTestFinish.test.ts | 11 ++++++++ .../tests/service.timedOutTestFinish.test.ts | 18 +++++++++++++ 3 files changed, 48 insertions(+), 8 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/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 67405a73..289707b6 100644 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -139,4 +139,22 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky #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 = { title: 'times out then succeeds', parent: 'Suite', ctx: { test: runnable } } as unknown as Frameworks.Test + 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(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toEqual([ + `${TestFrameworkState.TEST}/${HookState.POST} passed=false times out then succeeds #0` + ]) + }) }) From ede6baaa6be0857c3f48cfdbb8c1f15e6073feef Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Thu, 8 Oct 2026 19:54:38 +0530 Subject: [PATCH 07/12] refactor(cli): route the timed-out test finish through trackEvent (SDK-7843) v8 port of the #272 review rework: service.ts / reporter.ts only feed the existing CLI events; product logic stays in the CLI layer. - reporter onTestFail sends LOG_REPORT/POST + TEST/POST through framework.trackEvent with mocha's result; AutomateModule already marks the session from a failed TEST/POST, it just arrived after after(). - WdioMochaTestFramework tracks each mocha test attempt from TEST/PRE and reports its finish once, against the instance it started on, keeping mocha's failure when a late afterTest says passed. - settleTestFinishes() (TestFramework, no-op by default); after() calls it before EXECUTE/POST. - 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 | 140 ++++++++++++++- packages/browserstack-service/src/reporter.ts | 25 ++- packages/browserstack-service/src/service.ts | 46 ++--- .../tests/cli/earlyTestFinish.test.ts | 128 -------------- ...dioMochaTestFramework.timedOutTest.test.ts | 159 ++++++++++++++++++ .../tests/reporter.onTestFail.test.ts | 69 ++++---- .../tests/service.timedOutTestFinish.test.ts | 132 +++------------ 9 files changed, 394 insertions(+), 430 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.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 a4457a06..b079dfba 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -13,10 +13,57 @@ import type { Frameworks } from '@wdio/types' import { getGitMetaData, getMochaTestHierarchy, getTestTags, getUniqueIdentifier, isUndefined, removeAnsiColors } from '../../util.js' import { TEST_ANALYTICS_ID } from '../../constants.js' +/** 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 +} + +/** 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 + /** 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 @@ -34,6 +81,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) @@ -46,11 +107,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 { // HOOK_REGEX is anchored (^BEFORE_|^AFTER_) — match the short state name; the @@ -97,6 +171,70 @@ export default class WdioMochaTestFramework extends TestFramework { await this.runHooks(instance, testFrameworkState, hookState, args) } + /** 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 + }) + } + + /** + * 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 + // 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, fromMochaFail: true }) + } + } + while (this.pendingFinishes.size > 0) { + await Promise.all([...this.pendingFinishes]) + } + } + /** * Resolve instance for the test framework * @param {TestFrameworkState} testFrameworkState diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index 4b8b1fb2..c4430379 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' @@ -148,24 +149,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 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 4dc9d3ba..5fe0128b 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -37,7 +37,6 @@ import { BrowserstackCLI } from './cli/index.js' import { TestFrameworkState } from './cli/states/testFrameworkState.js' import { HookState } from './cli/states/hookState.js' import { markTestStarted, reportSuiteSkipped } from './cli/skipReporter.js' -import { awaitCliTestFinishesOnFailure, claimCliTestFinish, cliTestAttemptKey, registerCliTestFinisher } from './cli/earlyTestFinish.js' import { AutomationFrameworkState } from './cli/states/automationFrameworkState.js' import TestFramework from './cli/frameworks/testFramework.js' import { TestFrameworkConstants } from './cli/frameworks/constants/testFrameworkConstants.js' @@ -484,9 +483,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) { @@ -508,12 +504,6 @@ 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(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 }) return @@ -536,13 +526,8 @@ 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) + 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, suiteTite: this._suiteTitle }) return } await this._accessibilityHandler?.afterTest(this._suiteTitle, test) @@ -550,31 +535,20 @@ export default class BrowserstackService implements Services.ServiceInstance { await this._percyHandler?.afterTest() } - /** - * Report a mocha test's finish on the CLI flow. 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) { - 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, suiteTite: this._suiteTitle }) - } - - /** 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) - } - async after (result: number) { PerformanceTester.start(PERFORMANCE_SDK_EVENTS.HOOK_EVENTS.AFTER) PerformanceTester.start(PERFORMANCE_SDK_EVENTS.DRIVER_EVENT.QUIT) try { if (BrowserstackCLI.getInstance().isRunning()) { - // 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. EXECUTE/POST marks the session status from the results recorded so far, so - // wait for it first. 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 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)}`) + } await BrowserstackCLI.getInstance().getAutomationFramework()!.trackEvent(AutomationFrameworkState.EXECUTE, HookState.POST, {}) } const { preferScenarioName, setSessionName, setSessionStatus } = this._options 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.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.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts index 289707b6..2c3f6f5a 100644 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -8,23 +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 { 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 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 - - 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 + let settle: ReturnType + let trackEvent: ReturnType const makeService = () => new BrowserstackService( { testObservability: false } as never, @@ -33,17 +31,18 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD ) 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, test?: Frameworks.Test }) => { + // the reporter's finish is still being sent when after() starts + settle = vi.fn().mockImplementation(async () => { await new Promise((resolve) => setTimeout(resolve, 30)) - const title = state === TestFrameworkState.TEST && hook === HookState.POST ? ` ${args.test?.title} #${(args.test as { _currentRetry?: number })._currentRetry ?? 0}` : '' - events.push(`${String(state)}/${String(hook)}${args?.result ? ` passed=${args.result.passed}` : ''}${title}`) + events.push('settleTestFinishes') + }) + 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)}`) @@ -51,110 +50,31 @@ describe('service — a timed-out mocha test is finished when mocha fails it (SD }) } 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').mockReturnValue('uuid-1' as never) }) 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 times out #0`) - const sessionStatusAt = events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`) - expect(testPost).toBeGreaterThanOrEqual(0) - // the failure is recorded before EXECUTE/POST, which is where AutomateModule marks the - // session status - expect(testPost).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) - }) - - 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 = { title: 'times out unreported', parent: 'Suite', ctx: { test: runnable } } as unknown as Frameworks.Test - 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 }) + it('settles before EXECUTE/POST', async () => { + await makeService().after(1) - const testPost = events.indexOf(`${TestFrameworkState.TEST}/${HookState.POST} passed=false times out unreported #0`) - expect(testPost).toBeGreaterThanOrEqual(0) - expect(testPost).toBeLessThan(events.indexOf(`${AutomationFrameworkState.EXECUTE}/${HookState.POST}`)) - expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toHaveLength(1) + expect(events).toEqual(['settleTestFinishes', `${AutomationFrameworkState.EXECUTE}/${HookState.POST}`]) }) - it('lets a retried attempt\'s late afterTest close that attempt, not the next one', 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 attempt0 = { title: 'flaky', parent: 'Suite', ctx: { test: {} }, _currentRetry: 0 } as unknown as Frameworks.Test - const attempt1 = { title: 'flaky', parent: 'Suite', ctx: { test: {} }, _currentRetry: 1 } as unknown as Frameworks.Test - 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 + const test = { title: 'times out', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test - // 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(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toEqual([ - `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky #0`, - `${TestFrameworkState.TEST}/${HookState.POST} passed=false flaky #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 = { title: 'times out then succeeds', parent: 'Suite', ctx: { test: runnable } } as unknown as Frameworks.Test 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) + await service.afterTest(test, undefined as never, { passed: false, error: new Error('Timeout'), duration: 1 } as Frameworks.TestResult) - expect(events.filter((e) => e.startsWith(`${TestFrameworkState.TEST}/${HookState.POST}`))).toEqual([ - `${TestFrameworkState.TEST}/${HookState.POST} passed=false times out then succeeds #0` + expect(setState).not.toHaveBeenCalled() + expect(events.filter((e) => e.startsWith(TestFrameworkState.TEST))).toEqual([ + `${TestFrameworkState.TEST}/${HookState.PRE}`, + `${TestFrameworkState.TEST}/${HookState.POST}` ]) }) }) From 359575a6c2b1bf73ec315e5d7bc9fc3641561bef Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Fri, 9 Oct 2026 13:06:11 +0530 Subject: [PATCH 08/12] 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 b079dfba..224870d1 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -29,6 +29,8 @@ interface TestAttempt { runnable?: MochaRunnable /** 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). */ @@ -53,8 +55,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. */ @@ -64,6 +78,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 @@ -96,6 +115,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) @@ -107,7 +129,6 @@ export default class WdioMochaTestFramework extends TestFramework { return } - const attempt = this.resolveTestAttempt(testFrameworkState, hookState, args) if (attempt === null) { return } @@ -174,12 +195,38 @@ 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 - }) + } + 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)) } /** @@ -193,26 +240,27 @@ 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) // 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) + attempt.finished = true + this.openAttempts.delete(attempt) } return attempt } @@ -223,9 +271,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, 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 7be93175fdd9170264bb1c517fc6a3cf158a2806 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Mon, 12 Oct 2026 13:11:29 +0530 Subject: [PATCH 09/12] fix(cli): treat a retried mocha attempt as failed when settling (SDK-7843) mocha retries a failed attempt by cloning it and emitting `retry`, not `fail`, so the attempt's runnable never gets state `failed`. A timed-out attempt that was retried was then neither finished by settleTestFinishes() nor kept failed when its late afterTest said passed. A later attempt of the same test having started means mocha failed this one; check that too. Co-Authored-By: Claude Opus 5.5 --- .../cli/frameworks/wdioMochaTestFramework.ts | 25 ++++++++++++++--- ...dioMochaTestFramework.timedOutTest.test.ts | 28 +++++++++++++++++++ .../tests/service.timedOutTestFinish.test.ts | 2 +- 3 files changed, 50 insertions(+), 5 deletions(-) diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index 224870d1..bc21994f 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -211,6 +211,22 @@ export default class WdioMochaTestFramework extends TestFramework { } } + /** + * Whether mocha already failed this attempt. A failure it retries is not marked: mocha clones + * the test, emits `retry` instead of `fail` and leaves the attempt's `state` unset. It only + * retries a failure, though, so a later attempt of the same test having started means this + * one failed. + */ + private mochaFailed(attempt: TestAttempt): boolean { + if (attempt.runnable?.state === 'failed') { + return true + } + const body = WdioMochaTestFramework.testBody(attempt.test) + const retries = body ? this.attemptsByFn.get(body) : undefined + const retry = (attempt.test as { _currentRetry?: number })._currentRetry ?? 0 + return Boolean(retries && [...retries.keys()].some((later) => later > retry)) + } + /** * 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 @@ -255,7 +271,7 @@ export default class WdioMochaTestFramework extends TestFramework { this.resolvedFinishes.set(test, attempt) // 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) { + if (attempt.runnable && this.mochaFailed(attempt) && (args.result as Frameworks.TestResult | undefined)?.passed) { args.result = failureFromRunnable(attempt.runnable) } if (testFrameworkState === TestFrameworkState.TEST) { @@ -267,12 +283,13 @@ 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. + * mocha already failed (or retried) 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]) { - if (attempt.runnable?.state === 'failed' && !attempt.finishingFrom) { + if (attempt.runnable && this.mochaFailed(attempt) && !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 }) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts index 3c675377..42a53e3e 100644 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts @@ -146,6 +146,34 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its expect(finishes).toEqual([`flaky ${uuid0} passed=false`, `flaky ${uuid1} passed=false`]) }) + // mocha retries a timed-out attempt without failing it: it emits `retry`, not `fail`, and + // leaves the attempt's runnable `state` unset + it('without a reporter, settle finishes a retried attempt whose body never returned', async () => { + const fn = () => {} + const attempt0 = makeTest('flaky', { fn, _currentRetry: 0 }) + const uuid0 = await start(attempt0) + Object.assign(attempt0.ctx!.test as object, { timedOut: true, duration: 10001 }) + const attempt1 = makeTest('flaky', { fn, _currentRetry: 1 }) + const uuid1 = await start(attempt1) + await afterTest({ ...attempt1 } as Frameworks.Test, passed) + + await framework.settleTestFinishes() + + expect(finishes).toEqual([`flaky ${uuid1} passed=true`, `flaky ${uuid0} passed=false`]) + }) + + it('keeps a retried attempt failed when its late afterTest says passed', async () => { + const fn = () => {} + const attempt0 = makeTest('flaky', { fn, _currentRetry: 0 }) + const uuid0 = await start(attempt0) + Object.assign(attempt0.ctx!.test as object, { timedOut: true, duration: 10001 }) + await start(makeTest('flaky', { fn, _currentRetry: 1 })) + + await afterTest({ ...attempt0 } as Frameworks.Test, passed) + + expect(finishes).toEqual([`flaky ${uuid0} 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 () => { diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts index 2c3f6f5a..7dacfce0 100644 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -72,7 +72,7 @@ describe('service after() — settles test finishes before the session status is await service.afterTest(test, undefined as never, { passed: false, error: new Error('Timeout'), duration: 1 } as Frameworks.TestResult) expect(setState).not.toHaveBeenCalled() - expect(events.filter((e) => e.startsWith(TestFrameworkState.TEST))).toEqual([ + expect(events.filter((e) => e.startsWith(String(TestFrameworkState.TEST)))).toEqual([ `${TestFrameworkState.TEST}/${HookState.PRE}`, `${TestFrameworkState.TEST}/${HookState.POST}` ]) From 683b5323a321afb23d39a5028c8a662e85cc622d Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Mon, 12 Oct 2026 14:25:49 +0530 Subject: [PATCH 10/12] fix(cli): key mocha attempts by body and name, not body and retry (SDK-7843) Tests can share one body (`it(name, sharedFn)`), so attempts keyed by the body and retry overwrote each other: a timed-out test's late afterTest resolved to the next test's attempt. Key them by body, then attemptKey. Co-Authored-By: Claude Opus 5.5 --- .../cli/frameworks/wdioMochaTestFramework.ts | 28 +++++++++++-------- ...dioMochaTestFramework.timedOutTest.test.ts | 15 ++++++++++ 2 files changed, 32 insertions(+), 11 deletions(-) diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index bc21994f..b8a50f76 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -62,11 +62,12 @@ export default class WdioMochaTestFramework extends TestFramework { */ 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. + * Attempts by the test's body, then by `attemptKey`. wdio hands beforeTest and afterTest + * separate copies of the mocha test (`{ ...context.test }`, with no reference to the runnable), + * but both carry its `fn`, so afterTest finds its own attempt even when another test with the + * same key has started since. Tests can share one body (`it(name, sharedFn)`), hence the key. */ - private attemptsByFn = new WeakMap>() + 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>() @@ -78,6 +79,10 @@ export default class WdioMochaTestFramework extends TestFramework { return retry ? `${identifier} (retry ${retry})` : identifier } + private static currentRetry(test: Frameworks.Test): number { + return (test as { _currentRetry?: number })._currentRetry ?? 0 + } + private static testBody(test: Frameworks.Test): object | undefined { const fn = (test as { fn?: unknown }).fn return typeof fn === 'function' ? fn : undefined @@ -205,9 +210,9 @@ export default class WdioMochaTestFramework extends TestFramework { 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) + const byKey = this.attemptsByFn.get(body) ?? new Map() + byKey.set(WdioMochaTestFramework.attemptKey(test), attempt) + this.attemptsByFn.set(body, byKey) } } @@ -222,9 +227,10 @@ export default class WdioMochaTestFramework extends TestFramework { return true } const body = WdioMochaTestFramework.testBody(attempt.test) - const retries = body ? this.attemptsByFn.get(body) : undefined - const retry = (attempt.test as { _currentRetry?: number })._currentRetry ?? 0 - return Boolean(retries && [...retries.keys()].some((later) => later > retry)) + const identifier = getUniqueIdentifier(attempt.test, 'mocha') + const retry = WdioMochaTestFramework.currentRetry(attempt.test) + return [...(body && this.attemptsByFn.get(body)?.values() || [])].some((other) => + getUniqueIdentifier(other.test, 'mocha') === identifier && WdioMochaTestFramework.currentRetry(other.test) > retry) } /** @@ -240,7 +246,7 @@ export default class WdioMochaTestFramework extends TestFramework { } const body = WdioMochaTestFramework.testBody(test) if (body) { - return this.attemptsByFn.get(body)?.get((test as { _currentRetry?: number })._currentRetry ?? 0) + return this.attemptsByFn.get(body)?.get(WdioMochaTestFramework.attemptKey(test)) } return this.latestAttemptByKey.get(WdioMochaTestFramework.attemptKey(test)) } diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts index 42a53e3e..32619bb8 100644 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts @@ -174,6 +174,21 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its expect(finishes).toEqual([`flaky ${uuid0} passed=false`]) }) + it('closes a late afterTest by its own test when tests share one body', async () => { + // for (const c of cases) it(c.name, sharedFn) + const fn = () => {} + const first = makeTest('case a', { fn }) + const firstUuid = await start(first) + Object.assign(first.ctx!.test as object, { state: 'failed', timedOut: true, duration: 10001 }) + const second = makeTest('case b', { fn }) + const secondUuid = await start(second) + + await afterTest({ ...first } as Frameworks.Test, passed) + await afterTest({ ...second } as Frameworks.Test, failed) + + expect(finishes).toEqual([`case a ${firstUuid} passed=false`, `case b ${secondUuid} 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 () => { From 788bc81a62865102abb58031165dede25378502c Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Mon, 12 Oct 2026 17:32:48 +0530 Subject: [PATCH 11/12] refactor(cli): queue the reporter's failed-test finish on the skip-report chain (SDK-7843) Reuse skipReporter's reportChain instead of a separate pendingFinishes set, and have after() wait for that chain (drainSkipReports) before settling. The reporter pins the failed test to its attempt synchronously in mocha's `fail` (pinFailedAttempt), then queues LOG_REPORT and TEST/POST through enqueueReport, so it cannot interleave with a skip report. settleTestFinishes() keeps the no-reporter fallback. Co-Authored-By: Claude Opus 5.5 --- .../src/cli/frameworks/testFramework.ts | 10 +++++ .../cli/frameworks/wdioMochaTestFramework.ts | 43 ++++++++---------- .../src/cli/skipReporter.ts | 24 +++++++--- packages/browserstack-service/src/reporter.ts | 11 +++-- packages/browserstack-service/src/service.ts | 14 ++++-- ...dioMochaTestFramework.timedOutTest.test.ts | 39 +++++++++------- .../tests/reporter.onTestFail.test.ts | 44 +++++++++++++++++-- 7 files changed, 130 insertions(+), 55 deletions(-) diff --git a/packages/browserstack-service/src/cli/frameworks/testFramework.ts b/packages/browserstack-service/src/cli/frameworks/testFramework.ts index 4266ed79..3e9404b2 100644 --- a/packages/browserstack-service/src/cli/frameworks/testFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/testFramework.ts @@ -1,3 +1,5 @@ +import type { Frameworks } from '@wdio/types' + import { CLIUtils } from '../cliUtils.js' import { eventDispatcher } from '../eventDispatcher.js' import { BStackLogger as logger } from '../cliLogger.js' @@ -84,6 +86,14 @@ export default class TestFramework { logger.info(`trackEvent: testFrameworkState=${testFrameworkState}; hookState=${hookState}; args=${args}`) } + /** + * Pin a test the reporter's `fail` is about to report to the test run it belongs to, before + * that report is queued. + * @param {Frameworks.Test} _test + */ + // eslint-disable-next-line @typescript-eslint/no-unused-vars + pinFailedAttempt(_test: Frameworks.Test): void {} + /** * 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). diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index b8a50f76..6a6abd8f 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -70,7 +70,6 @@ export default class WdioMochaTestFramework extends TestFramework { 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. */ static attemptKey(test: Frameworks.Test): string { @@ -105,23 +104,7 @@ 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}`) - // 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) @@ -216,6 +199,19 @@ export default class WdioMochaTestFramework extends TestFramework { } } + /** + * The reporter's `fail`, synchronously in mocha's `fail` event (SDK-7843): pin the failed test + * to the attempt mocha just failed, the latest with its key. The finish itself is queued (see + * skipReporter's enqueueReport) and may run after mocha has started the next test, which can + * share the key. + */ + pinFailedAttempt(test: Frameworks.Test) { + const attempt = this.findTestAttempt(test) + if (attempt) { + this.resolvedFinishes.set(test, attempt) + } + } + /** * Whether mocha already failed this attempt. A failure it retries is not marked: mocha clones * the test, emits `retry` instead of `fail` and leaves the attempt's `state` unset. It only @@ -235,9 +231,9 @@ export default class WdioMochaTestFramework extends TestFramework { /** * 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. + * it exactly. The reporter's `fail` has only the title and parent: it is pinned (see + * pinFailedAttempt) to the latest attempt with that key, which is the one mocha just failed, + * so its queued LOG_REPORT and TEST/POST cannot land on a later same-named test. */ private findTestAttempt(test: Frameworks.Test): TestAttempt | undefined { const resolved = this.resolvedFinishes.get(test) @@ -290,8 +286,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 (or retried) that nothing reported (no reporter is registered when Test - * Reporting, Accessibility and Percy are all off), then wait for every finish the reporter - * started. + * Reporting, Accessibility and Percy are all off). Runs after drainSkipReports(), which waits + * for the finishes the reporter queued. */ async settleTestFinishes(): Promise { for (const attempt of [...this.openAttempts]) { @@ -302,9 +298,6 @@ export default class WdioMochaTestFramework extends TestFramework { await this.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: attempt.test, result, fromMochaFail: true }) } } - while (this.pendingFinishes.size > 0) { - await Promise.all([...this.pendingFinishes]) - } } /** diff --git a/packages/browserstack-service/src/cli/skipReporter.ts b/packages/browserstack-service/src/cli/skipReporter.ts index 14bdc562..71a8fc96 100644 --- a/packages/browserstack-service/src/cli/skipReporter.ts +++ b/packages/browserstack-service/src/cli/skipReporter.ts @@ -32,6 +32,23 @@ const reportedSkips = new Set() // tracker's single mutable per-worker instance — serialize every report through one chain let reportChain: Promise = Promise.resolve() +/** + * Queue a report on the one chain every report wdio may not await goes through, so reports never + * interleave on the tracker's per-worker tracked-instance slot. Also used by the reporter's `fail` + * (SDK-7843). + */ +export function enqueueReport(work: () => Promise, what: string): Promise { + reportChain = reportChain.then(work).catch((err: unknown) => { + BStackLogger.debug(`Failed reporting ${what}: ${err}`) + }) + return reportChain +} + +/** Wait for every report queued so far; service.after() calls this before marking the session. */ +export function drainSkipReports(): Promise { + return reportChain +} + export function markTestStarted(identifier: string) { startedTests.add(identifier) } @@ -42,17 +59,14 @@ export function reportSkippedTest(framework: TestFramework, identifier: string, } reportedSkips.add(identifier) const result = { passed: false, skipped: true } as unknown as Frameworks.TestResult - reportChain = reportChain.then(async () => { + return enqueueReport(async () => { // LOG_REPORT/POST is what loads the result into the instance (loadTestResult is // gated on it, not on TEST/POST) — same sequence afterTest uses await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result }) await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, suiteTitle }) - }).catch((err: unknown) => { - BStackLogger.debug(`Failed reporting skipped test '${identifier}': ${err}`) - }) - return reportChain + }, `skipped test '${identifier}'`) } /** diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index c4430379..55cca7e7 100644 --- a/packages/browserstack-service/src/reporter.ts +++ b/packages/browserstack-service/src/reporter.ts @@ -4,7 +4,7 @@ import type { SuiteStats, TestStats, RunnerStats, HookStats } from '@wdio/report 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 { enqueueReport, reportSkippedTest, resolveSpecFile } from './cli/skipReporter.js' import { TestFrameworkState } from './cli/states/testFrameworkState.js' import { HookState } from './cli/states/hookState.js' import * as url from 'node:url' @@ -173,8 +173,13 @@ class _TestReporter extends WDIOReporter { 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 }) + // pin now, in mocha's `fail` event: the queued report can run after mocha starts the next test + framework.pinFailedAttempt(test) + // wdio does not await reporter callbacks: queue it on the skip-report chain, which after() drains + await enqueueReport(async () => { + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, fromMochaFail: true }) + }, `failed test '${stats.title}'`) } async onTestEnd(testStats: TestStats) { diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index 5fe0128b..50dc9ae5 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -36,7 +36,7 @@ import { EVENTS } from './instrumentation/performance/constants.js' import { BrowserstackCLI } from './cli/index.js' import { TestFrameworkState } from './cli/states/testFrameworkState.js' import { HookState } from './cli/states/hookState.js' -import { markTestStarted, reportSuiteSkipped } from './cli/skipReporter.js' +import { drainSkipReports, markTestStarted, reportSuiteSkipped } from './cli/skipReporter.js' import { AutomationFrameworkState } from './cli/states/automationFrameworkState.js' import TestFramework from './cli/frameworks/testFramework.js' import { TestFrameworkConstants } from './cli/frameworks/constants/testFrameworkConstants.js' @@ -541,9 +541,15 @@ export default class BrowserstackService implements Services.ServiceInstance { try { if (BrowserstackCLI.getInstance().isRunning()) { - // SDK-7843: a test that timed out is reported when mocha failed it, and that report - // can still be in flight; settle it before EXECUTE/POST, where the session status is - // marked from the results recorded so far + // SDK-7843: a test that timed out is reported when mocha failed it, and the reporter + // queues that report on the skip-report chain; wait for the chain, then finish a + // failed test nothing reported (no reporter registered), before EXECUTE/POST, where + // the session status is marked from the results recorded so far + try { + await drainSkipReports() + } catch (drainErr) { + BStackLogger.debug(`Exception draining reports in after(): ${util.format(drainErr)}`) + } try { await BrowserstackCLI.getInstance().getTestFramework()?.settleTestFinishes() } catch (settleErr) { diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts index 32619bb8..272b0b8b 100644 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts @@ -10,6 +10,7 @@ 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' +import { drainSkipReports, enqueueReport } from '../../src/cli/skipReporter.js' vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) @@ -37,10 +38,18 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its 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. */ + /** What the reporter does in `fail`: pin the test, then queue its finish; 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 }) + framework.pinFailedAttempt(test) + void enqueueReport(async () => { + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, fromMochaFail: true }) + }, test.title) + } + /** service.after(): drain the report chain, then settle. */ + const settle = async () => { + await drainSkipReports() + await framework.settleTestFinishes() } beforeEach(() => { @@ -74,7 +83,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its const uuid = await start(test) reporterFail(test) - await framework.settleTestFinishes() + await settle() expect(finishes).toEqual([`times out ${uuid} passed=false`]) // the body finished late and succeeded: wdio's afterTest says passed @@ -88,7 +97,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its await afterTest(test, { ...failed, error: new Error('expected 1 to equal 2') }) reporterFail(test) - await framework.settleTestFinishes() + await settle() expect(finishes).toEqual([`fails ${uuid} passed=false`]) }) @@ -124,7 +133,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its await start(running) const loadResult = vi.spyOn(framework, 'loadTestResult') - await framework.settleTestFinishes() + await settle() expect(finishes).toEqual([`times out unreported ${timedOutUuid} passed=false`]) expect(loadResult).toHaveBeenCalledWith(expect.anything(), expect.objectContaining({ @@ -141,7 +150,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its // attempt 0's late afterTest, then attempt 1 times out too await afterTest(attempt0, failed) reporterFail(makeTest('flaky', { _currentRetry: 1 })) - await framework.settleTestFinishes() + await settle() expect(finishes).toEqual([`flaky ${uuid0} passed=false`, `flaky ${uuid1} passed=false`]) }) @@ -157,7 +166,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its const uuid1 = await start(attempt1) await afterTest({ ...attempt1 } as Frameworks.Test, passed) - await framework.settleTestFinishes() + await settle() expect(finishes).toEqual([`flaky ${uuid1} passed=true`, `flaky ${uuid0} passed=false`]) }) @@ -207,7 +216,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its const first = makeTest('works', { parent: 'valid', fn: () => {} }) const firstUuid = await start(first) reporterFail(makeTest('works', { parent: 'valid' })) - await framework.settleTestFinishes() + await settle() const second = makeTest('works', { parent: 'valid', fn: () => {} }) const secondUuid = await start(second) @@ -219,16 +228,16 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its 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 () => { + it('keeps the reporter\'s queued finish on the test it pinned, 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 }) + // mocha's `fail`: the reporter pins the test now; its queued finish may run after mocha has + // started the next test + framework.pinFailedAttempt(failed1) const second = makeTest('works', { parent: 'valid', fn: () => {} }) const secondUuid = await start(second) - await logReport + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failed1, result: failed, fromMochaFail: true }) await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failed1, result: failed, fromMochaFail: true }) await afterTest({ ...second } as Frameworks.Test, passed) @@ -239,7 +248,7 @@ describe('WdioMochaTestFramework — a test finish is reported once, against its await start(makeTest('runs')) reporterFail(makeTest('"before each" hook for runs')) - await framework.settleTestFinishes() + await settle() expect(finishes).toEqual([]) await afterTest(makeTest('unseen'), passed) diff --git a/packages/browserstack-service/tests/reporter.onTestFail.test.ts b/packages/browserstack-service/tests/reporter.onTestFail.test.ts index 9238d90a..6784605b 100644 --- a/packages/browserstack-service/tests/reporter.onTestFail.test.ts +++ b/packages/browserstack-service/tests/reporter.onTestFail.test.ts @@ -7,6 +7,7 @@ import WdioMochaTestFramework from '../src/cli/frameworks/wdioMochaTestFramework import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' import * as bstackLogger from '../src/bstackLogger.js' +import { drainSkipReports, reportSkippedTest } from '../src/cli/skipReporter.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'))) @@ -21,9 +22,8 @@ describe('reporter onTestFail — sends mocha\'s failure through the CLI test ev ;(reporter as unknown as { _config: unknown })._config = { framework } return reporter } - const mockCli = (isRunning: boolean) => { - const trackEvent = vi.fn().mockResolvedValue(undefined) - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => isRunning, getTestFramework: () => ({ trackEvent }) } as never) + const mockCli = (isRunning: boolean, trackEvent = vi.fn().mockResolvedValue(undefined), pinFailedAttempt = vi.fn()) => { + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => isRunning, getTestFramework: () => ({ trackEvent, pinFailedAttempt }) } as never) return trackEvent } @@ -57,6 +57,44 @@ describe('reporter onTestFail — sends mocha\'s failure through the CLI test ev .toBe('Smoke: Home Navigation - should navigate via bottom nav (retry 1)') }) + it('pins the test before queueing its finish, and reports that same test object', async () => { + const order: string[] = [] + const pinFailedAttempt = vi.fn(() => { + order.push('pin') + }) + const trackEvent = mockCli(true, vi.fn(async (state: unknown) => { + order.push(String(state)) + }), pinFailedAttempt) + + await makeReporter('mocha').onTestFail(testStats as never) + + expect(order).toEqual(['pin', String(TestFrameworkState.LOG_REPORT), String(TestFrameworkState.TEST)]) + const pinned = pinFailedAttempt.mock.calls[0][0] + expect(trackEvent.mock.calls.map(([, , args]) => args.test)).toEqual([pinned, pinned]) + expect(trackEvent.mock.calls[0][2].test).toBe(pinned) + }) + + it('queues its finish on the skip-report chain, so a queued skip cannot interleave with it', async () => { + const events: string[] = [] + const trackEvent = vi.fn(async (state: unknown, hook: unknown, args: { test: { title: string } }) => { + events.push(`${args.test.title} ${String(state)}/${String(hook)} start`) + await new Promise((resolve) => setTimeout(resolve, 10)) + events.push(`${args.test.title} ${String(state)}/${String(hook)} end`) + }) + mockCli(true, trackEvent) + const framework = { trackEvent } as never + + // wdio does not await either: the fail, then mocha's skip of a later test + void makeReporter('mocha').onTestFail(testStats as never) + void reportSkippedTest(framework, 'Smoke - skipped later', { title: 'skipped later', parent: 'Smoke' } as never, 'Smoke') + await drainSkipReports() + + const failEnd = events.indexOf(`${testStats.title} ${TestFrameworkState.TEST}/${HookState.POST} end`) + const skipStart = events.indexOf(`skipped later ${TestFrameworkState.INIT_TEST}/${HookState.PRE} start`) + expect(failEnd).toBeGreaterThan(-1) + expect(skipStart).toBeGreaterThan(failEnd) + }) + it('does nothing on the classic flow, which sets the session status from after(result)', async () => { const trackEvent = mockCli(false) From c299adf5bc0d369b6e43e7324ce692035cf35282 Mon Sep 17 00:00:00 2001 From: Aakash Hotchandani Date: Mon, 12 Oct 2026 18:04:45 +0530 Subject: [PATCH 12/12] test: merge the split test files into one test file per source file (SDK-7843) Move the wdioMochaTestFramework, reporter and service tests this branch added (and the files they sat beside) into tests/cli/wdioMochaTestFramework.test.ts, tests/reporter.test.ts and tests/service.test.ts. No test is added or removed. In service.test.ts the moved after() cases use the real after() captured before the `after` suite replaces it, real timers for the cases that time a finish, and restore only their own spies. Co-Authored-By: Claude Opus 5.5 --- .../wdioMochaTestFramework.preTestLog.test.ts | 56 --------- ...test.ts => wdioMochaTestFramework.test.ts} | 53 +++++++- .../tests/reporter.onTestFail.test.ts | 113 ------------------ .../tests/reporter.test.ts | 104 ++++++++++++++++ .../tests/service.test.ts | 75 ++++++++++++ .../tests/service.timedOutTestFinish.test.ts | 80 ------------- 6 files changed, 228 insertions(+), 253 deletions(-) delete mode 100644 packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts rename packages/browserstack-service/tests/cli/{wdioMochaTestFramework.timedOutTest.test.ts => wdioMochaTestFramework.test.ts} (86%) delete mode 100644 packages/browserstack-service/tests/reporter.onTestFail.test.ts delete mode 100644 packages/browserstack-service/tests/service.timedOutTestFinish.test.ts diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts deleted file mode 100644 index 1ee5a019..00000000 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts +++ /dev/null @@ -1,56 +0,0 @@ -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')) - }) -}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.test.ts similarity index 86% rename from packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts rename to packages/browserstack-service/tests/cli/wdioMochaTestFramework.test.ts index 272b0b8b..a207957a 100644 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.test.ts @@ -1,19 +1,64 @@ 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 { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' +import type { Frameworks } from '@wdio/types' +import * as util from '../../src/util.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' import { drainSkipReports, enqueueReport } from '../../src/cli/skipReporter.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')) + }) +}) + /** * 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 diff --git a/packages/browserstack-service/tests/reporter.onTestFail.test.ts b/packages/browserstack-service/tests/reporter.onTestFail.test.ts deleted file mode 100644 index 6784605b..00000000 --- a/packages/browserstack-service/tests/reporter.onTestFail.test.ts +++ /dev/null @@ -1,113 +0,0 @@ -import path from 'node:path' -import { describe, expect, it, vi, afterEach } from 'vitest' - -import TestReporter from '../src/reporter.js' -import { BrowserstackCLI } from '../src/cli/index.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' -import { drainSkipReports, reportSkippedTest } from '../src/cli/skipReporter.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.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) - -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 } - - const makeReporter = (framework: string) => { - const reporter = new TestReporter({}) - ;(reporter as unknown as { _config: unknown })._config = { framework } - return reporter - } - const mockCli = (isRunning: boolean, trackEvent = vi.fn().mockResolvedValue(undefined), pinFailedAttempt = vi.fn()) => { - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => isRunning, getTestFramework: () => ({ trackEvent, pinFailedAttempt }) } as never) - return trackEvent - } - - afterEach(() => { - vi.restoreAllMocks() - }) - - it('sends LOG_REPORT/POST then TEST/POST with mocha\'s result, under the test\'s identity', async () => { - const trackEvent = mockCli(true) - - await makeReporter('mocha').onTestFail(testStats as never) - - 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('names a retried attempt the way the service\'s afterTest does', async () => { - const trackEvent = mockCli(true) - - await makeReporter('mocha').onTestFail({ ...testStats, retries: 1 } as never) - - 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('pins the test before queueing its finish, and reports that same test object', async () => { - const order: string[] = [] - const pinFailedAttempt = vi.fn(() => { - order.push('pin') - }) - const trackEvent = mockCli(true, vi.fn(async (state: unknown) => { - order.push(String(state)) - }), pinFailedAttempt) - - await makeReporter('mocha').onTestFail(testStats as never) - - expect(order).toEqual(['pin', String(TestFrameworkState.LOG_REPORT), String(TestFrameworkState.TEST)]) - const pinned = pinFailedAttempt.mock.calls[0][0] - expect(trackEvent.mock.calls.map(([, , args]) => args.test)).toEqual([pinned, pinned]) - expect(trackEvent.mock.calls[0][2].test).toBe(pinned) - }) - - it('queues its finish on the skip-report chain, so a queued skip cannot interleave with it', async () => { - const events: string[] = [] - const trackEvent = vi.fn(async (state: unknown, hook: unknown, args: { test: { title: string } }) => { - events.push(`${args.test.title} ${String(state)}/${String(hook)} start`) - await new Promise((resolve) => setTimeout(resolve, 10)) - events.push(`${args.test.title} ${String(state)}/${String(hook)} end`) - }) - mockCli(true, trackEvent) - const framework = { trackEvent } as never - - // wdio does not await either: the fail, then mocha's skip of a later test - void makeReporter('mocha').onTestFail(testStats as never) - void reportSkippedTest(framework, 'Smoke - skipped later', { title: 'skipped later', parent: 'Smoke' } as never, 'Smoke') - await drainSkipReports() - - const failEnd = events.indexOf(`${testStats.title} ${TestFrameworkState.TEST}/${HookState.POST} end`) - const skipStart = events.indexOf(`skipped later ${TestFrameworkState.INIT_TEST}/${HookState.PRE} start`) - expect(failEnd).toBeGreaterThan(-1) - expect(skipStart).toBeGreaterThan(failEnd) - }) - - it('does nothing on the classic flow, which sets the session status from after(result)', async () => { - const trackEvent = mockCli(false) - - await makeReporter('mocha').onTestFail(testStats as never) - - expect(trackEvent).not.toHaveBeenCalled() - }) - - it('does nothing for other frameworks, whose afterTest is not run after after()', async () => { - const trackEvent = mockCli(true) - - await makeReporter('cucumber').onTestFail(testStats as never) - - expect(trackEvent).not.toHaveBeenCalled() - }) -}) diff --git a/packages/browserstack-service/tests/reporter.test.ts b/packages/browserstack-service/tests/reporter.test.ts index 2b2a31c3..ed68e6a5 100644 --- a/packages/browserstack-service/tests/reporter.test.ts +++ b/packages/browserstack-service/tests/reporter.test.ts @@ -6,6 +6,11 @@ import type { StdLog } from '../src/index.js' import TestReporter from '../src/reporter.js' import * as utils from '../src/util.js' import * as bstackLogger from '../src/bstackLogger.js' +import { BrowserstackCLI } from '../src/cli/index.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 { drainSkipReports, reportSkippedTest } from '../src/cli/skipReporter.js' import TestMetadata from '../src/metadata.js' import { BROWSERSTACK_CENTRAL_USER } from '../src/constants.js' @@ -420,3 +425,102 @@ describe('test-reporter', () => { }) }) + +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 } + + const makeReporter = (framework: string) => { + const reporter = new TestReporter({}) + ;(reporter as unknown as { _config: unknown })._config = { framework } + return reporter + } + const mockCli = (isRunning: boolean, trackEvent = vi.fn().mockResolvedValue(undefined), pinFailedAttempt = vi.fn()) => { + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => isRunning, getTestFramework: () => ({ trackEvent, pinFailedAttempt }) } as never) + return trackEvent + } + + afterEach(() => { + vi.restoreAllMocks() + }) + + it('sends LOG_REPORT/POST then TEST/POST with mocha\'s result, under the test\'s identity', async () => { + const trackEvent = mockCli(true) + + await makeReporter('mocha').onTestFail(testStats as never) + + 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('names a retried attempt the way the service\'s afterTest does', async () => { + const trackEvent = mockCli(true) + + await makeReporter('mocha').onTestFail({ ...testStats, retries: 1 } as never) + + 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('pins the test before queueing its finish, and reports that same test object', async () => { + const order: string[] = [] + const pinFailedAttempt = vi.fn(() => { + order.push('pin') + }) + const trackEvent = mockCli(true, vi.fn(async (state: unknown) => { + order.push(String(state)) + }), pinFailedAttempt) + + await makeReporter('mocha').onTestFail(testStats as never) + + expect(order).toEqual(['pin', String(TestFrameworkState.LOG_REPORT), String(TestFrameworkState.TEST)]) + const pinned = pinFailedAttempt.mock.calls[0][0] + expect(trackEvent.mock.calls.map(([, , args]) => args.test)).toEqual([pinned, pinned]) + expect(trackEvent.mock.calls[0][2].test).toBe(pinned) + }) + + it('queues its finish on the skip-report chain, so a queued skip cannot interleave with it', async () => { + const events: string[] = [] + const trackEvent = vi.fn(async (state: unknown, hook: unknown, args: { test: { title: string } }) => { + events.push(`${args.test.title} ${String(state)}/${String(hook)} start`) + await new Promise((resolve) => setTimeout(resolve, 10)) + events.push(`${args.test.title} ${String(state)}/${String(hook)} end`) + }) + mockCli(true, trackEvent) + const framework = { trackEvent } as never + + // wdio does not await either: the fail, then mocha's skip of a later test + void makeReporter('mocha').onTestFail(testStats as never) + void reportSkippedTest(framework, 'Smoke - skipped later', { title: 'skipped later', parent: 'Smoke' } as never, 'Smoke') + await drainSkipReports() + + const failEnd = events.indexOf(`${testStats.title} ${TestFrameworkState.TEST}/${HookState.POST} end`) + const skipStart = events.indexOf(`skipped later ${TestFrameworkState.INIT_TEST}/${HookState.PRE} start`) + expect(failEnd).toBeGreaterThan(-1) + expect(skipStart).toBeGreaterThan(failEnd) + }) + + it('does nothing on the classic flow, which sets the session status from after(result)', async () => { + const trackEvent = mockCli(false) + + await makeReporter('mocha').onTestFail(testStats as never) + + expect(trackEvent).not.toHaveBeenCalled() + }) + + it('does nothing for other frameworks, whose afterTest is not run after after()', async () => { + const trackEvent = mockCli(true) + + await makeReporter('cucumber').onTestFail(testStats as never) + + expect(trackEvent).not.toHaveBeenCalled() + }) +}) diff --git a/packages/browserstack-service/tests/service.test.ts b/packages/browserstack-service/tests/service.test.ts index f25834aa..c32b603e 100644 --- a/packages/browserstack-service/tests/service.test.ts +++ b/packages/browserstack-service/tests/service.test.ts @@ -1,6 +1,7 @@ import path from 'node:path' import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import type { Frameworks } from '@wdio/types' import got from 'got' import logger from '@wdio/logger' @@ -13,6 +14,7 @@ import WdioCucumberTestFramework from '../src/cli/frameworks/wdioCucumberTestFra 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 { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' import { TestFrameworkConstants } from '../src/cli/frameworks/constants/testFrameworkConstants.js' const jasmineSuiteTitle = 'Jasmine__TopLevel__Suite' @@ -2144,3 +2146,76 @@ describe('cucumber CLI dispatch (binary flow)', () => { }) }) + +/** + * 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 EXECUTE/POST, where AutomateModule marks the + * session status. + */ +describe('service after() — settles test finishes before the session status is marked (SDK-7843)', () => { + let events: string[] + let settle: ReturnType + let trackEvent: ReturnType + // restored one by one: vi.restoreAllMocks() would also undo this file's module-wide logger spies + let spies: Array<{ mockRestore: () => void }> + + const makeService = () => new BrowserstackService( + { testObservability: false } as never, + [] as never, + { user: 'foo', key: 'bar', framework: 'mocha', mochaOpts: { bail: true } } as never + ) + + beforeEach(() => { + // this file fakes every timer; the finish below is timed with a real setTimeout + vi.useRealTimers() + events = [] + // the reporter's finish is still being sent when after() starts + settle = vi.fn().mockImplementation(async () => { + await new Promise((resolve) => setTimeout(resolve, 30)) + events.push('settleTestFinishes') + }) + trackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + events.push(`${String(state)}/${String(hook)}`) + }) + spies = [] + spies.push(vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ + isRunning: () => true, + getTestFramework: () => ({ trackEvent, settleTestFinishes: settle }), + getAutomationFramework: () => ({ + trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + events.push(`${String(state)}/${String(hook)}`) + }) + }) + } as never)) + spies.push(vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as never)) + spies.push(vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid-1' as never)) + }) + + afterEach(() => { + spies.forEach((spy) => spy.mockRestore()) + vi.useFakeTimers().setSystemTime(new Date('2020-01-01')) + }) + + it('settles before EXECUTE/POST', async () => { + await makeService().after(1) + + expect(events).toEqual(['settleTestFinishes', `${AutomationFrameworkState.EXECUTE}/${HookState.POST}`]) + }) + + it('leaves the tracked test run alone in afterTest; the CLI framework picks the test\'s own', async () => { + const setState = vi.spyOn(TestFramework, 'setState') + spies.push(setState) + const service = makeService() + const test = { title: 'times out', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test + + await service.beforeTest(test) + await service.afterTest(test, undefined as never, { passed: false, error: new Error('Timeout'), duration: 1 } as Frameworks.TestResult) + + expect(setState).not.toHaveBeenCalled() + expect(events.filter((e) => e.startsWith(String(TestFrameworkState.TEST)))).toEqual([ + `${TestFrameworkState.TEST}/${HookState.PRE}`, + `${TestFrameworkState.TEST}/${HookState.POST}` + ]) + }) +}) diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts deleted file mode 100644 index 7dacfce0..00000000 --- a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts +++ /dev/null @@ -1,80 +0,0 @@ -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 * 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 (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 EXECUTE/POST, where AutomateModule marks the - * session status. - */ -describe('service after() — settles test finishes before the session status is marked (SDK-7843)', () => { - let events: string[] - let settle: ReturnType - let trackEvent: ReturnType - - const makeService = () => new BrowserstackService( - { testObservability: false } as never, - [] as never, - { user: 'foo', key: 'bar', framework: 'mocha', mochaOpts: { bail: true } } as never - ) - - beforeEach(() => { - events = [] - // the reporter's finish is still being sent when after() starts - settle = vi.fn().mockImplementation(async () => { - await new Promise((resolve) => setTimeout(resolve, 30)) - events.push('settleTestFinishes') - }) - trackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { - events.push(`${String(state)}/${String(hook)}`) - }) - vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ - isRunning: () => true, - getTestFramework: () => ({ trackEvent, settleTestFinishes: settle }), - getAutomationFramework: () => ({ - trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { - events.push(`${String(state)}/${String(hook)}`) - }) - }) - } as never) - vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as never) - vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid-1' as never) - }) - - afterEach(() => { - vi.restoreAllMocks() - }) - - it('settles before EXECUTE/POST', async () => { - await makeService().after(1) - - expect(events).toEqual(['settleTestFinishes', `${AutomationFrameworkState.EXECUTE}/${HookState.POST}`]) - }) - - 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 test = { title: 'times out', parent: 'Suite', ctx: { test: {} } } as unknown as Frameworks.Test - - await service.beforeTest(test) - await service.afterTest(test, undefined as never, { passed: false, error: new Error('Timeout'), duration: 1 } as Frameworks.TestResult) - - expect(setState).not.toHaveBeenCalled() - expect(events.filter((e) => e.startsWith(String(TestFrameworkState.TEST)))).toEqual([ - `${TestFrameworkState.TEST}/${HookState.PRE}`, - `${TestFrameworkState.TEST}/${HookState.POST}` - ]) - }) -})