diff --git a/.changeset/pr-272.md b/.changeset/pr-272.md new file mode 100644 index 00000000..415d660b --- /dev/null +++ b/.changeset/pr-272.md @@ -0,0 +1,6 @@ +--- +"@wdio/browserstack-service": patch +--- + +- Fixed mocha tests that fail by exceeding their timeout being marked "passed" on the Automate / App Automate dashboard, and their builds ending as "timeout" in Test Reporting about an hour after the run. Such tests are now reported as failed, with the timeout error as the reason. +- Removed the `resolveInstance: unable to resolve/create instance ... LOG POST` error printed when a wdio `before` hook writes to the console. diff --git a/packages/browserstack-service/src/cli/frameworks/testFramework.ts b/packages/browserstack-service/src/cli/frameworks/testFramework.ts index f291505c..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,21 @@ 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). + * @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 8a885982..ff04c728 100644 --- a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts @@ -12,6 +12,7 @@ import { BStackLogger as logger } from '../cliLogger.js' import type { Frameworks } from '@wdio/types' import { getMochaTestHierarchy, getTestTags, getUniqueIdentifier, isUndefined, removeAnsiColors } from '../../util.js' import { TEST_ANALYTICS_ID } from '../../constants.js' +import { reportSuiteSkipped } from '../skipReporter.js' /** * File-path pair sent with every test/hook event. @@ -31,10 +32,95 @@ const resolveTestFilePaths = (filename: string | undefined) => ({ : undefined, }) +/** mocha's live runnable of a test attempt; mocha sets `state` before it emits `fail`. */ +interface MochaRunnable { + state?: string + timedOut?: boolean + duration?: number + timeout?: () => number + currentRetry?: () => number + retries?: () => number + parent?: MochaSuite +} + +interface MochaSuite { + parent?: MochaSuite + tests?: unknown[] + suites?: unknown[] +} + +/** A mocha test attempt that has started (TEST/PRE) and not finished yet (SDK-7843). */ +interface TestAttempt { + instance: TestFrameworkInstance + test: Frameworks.Test + suiteTitle?: unknown + runnable?: MochaRunnable + /** mocha's `bail`: a failure drops every test the spec has not reached yet. */ + bail?: boolean + /** Who is reporting this attempt's finish: wdio's afterTest, or the reporter's `fail`. */ + finishingFrom?: 'afterTest' | 'fail' + /** Its TEST/POST has been reported. */ + finished?: boolean +} + +/** 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 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, 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>() + /** The attempt a source's LOG_REPORT/POST resolved; its TEST/POST passes the same `test` object. */ + private resolvedFinishes = new WeakMap() + /** Bail cascades owed by failures reported after mocha moved on; settleTestFinishes() runs them. */ + private owedBailCascades: Array<{ attempt: TestAttempt, result: Frameworks.TestResult }> = [] + /** settleTestFinishes() has run its cascades; anything later cascades inline. */ + private settled = false + + /** 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 + } + + 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 + } + /** * Constructor for the TestFramework * @param {Array} testFrameworks - List of Test frameworks @@ -53,13 +139,35 @@ export default class WdioMochaTestFramework extends TestFramework { */ async trackEvent(testFrameworkState: State, hookState: State, args: Record = {}) { logger.info(`trackEvent: testFrameworkState=${testFrameworkState} hookState=${hookState}`) + const attempt = this.resolveTestAttempt(testFrameworkState, hookState, args) await super.trackEvent(testFrameworkState, hookState, args) - const instance = this.resolveInstance(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 + } + + if (attempt === null) { + return + } + let instance: TestFrameworkInstance | null + if (attempt) { + instance = attempt.instance + this.updateInstanceState(instance, testFrameworkState, hookState) + } else { + instance = this.resolveInstance(testFrameworkState, hookState, args) + } if (instance === null) { logger.error(`trackEvent: instance not found for testFrameworkState=${testFrameworkState} hookState=${hookState}`) return } + if (testFrameworkState === TestFrameworkState.TEST && hookState === HookState.PRE && args.test) { + this.openTestAttempt(instance, args) + } try { // matchHookRegex expects the short state name (e.g. AFTER_EACH); `toString()` yields @@ -112,6 +220,203 @@ export default class WdioMochaTestFramework extends TestFramework { } args.instance = instance await this.runHooks(instance, testFrameworkState, hookState, args) + if (attempt && testFrameworkState === TestFrameworkState.TEST) { + if (!this.settled && (args.fromMochaFail || this.mochaFailed(attempt))) { + // mocha has moved on: it runs the failed test's after-hooks after the reporter's + // `fail` (which wdio does not await), and a timed-out test's afterTest arrives later + // still. The cascade's skip reports would claim the tracked slot under those hooks + this.owedBailCascades.push({ attempt, result: args.result as Frameworks.TestResult }) + } else { + await this.reportBailSkippedTests(attempt, args.result as Frameworks.TestResult) + } + } + } + + /** + * Whether this failure will be retried, in which case mocha has not dropped anything yet and + * the tests after it are still going to run. + * + * `results.retries` only tracks wdio's spec-file retries — `@wdio/utils` builds it as + * `{ attempts: 0, limit: repeatTest }` and `@wdio/mocha-framework` never feeds `mochaOpts.retries` + * into it, so under mocha-level retries it stays `{0, 0}` and tells us nothing. Read mocha's own + * runnable state for that case, otherwise the cascade fires on the first attempt and reports + * tests as skipped that the retry then actually runs. The runnable is the one captured at + * TEST/PRE: once mocha fails a timed-out test it moves on, and the suite's shared + * `ctx.test` then points at a hook, which inherits the suite's `retries` (SDK-7843). + */ + private hasRetryPending(runnable: MochaRunnable | undefined, results: Frameworks.TestResult): boolean { + if (typeof runnable?.currentRetry === 'function' && typeof runnable.retries === 'function') { + if (runnable.currentRetry() < runnable.retries()) { + return true + } + } + return Boolean(results.retries && results.retries.attempts < results.retries.limit) + } + + /** + * mocha's `bail` aborts the run on the first failure, so every test the spec had not reached + * yet is dropped without emitting any event and never appears on the dashboard. Report them + * as skipped — same cascade the failed-hook path uses, from the spec's root suite so sibling + * describes are covered too (bail kills the whole spec, not just the failing describe). + * + * The root can span more than one file when specs are grouped — `MochaAdapter` adds every spec + * it is handed to one mocha instance. Cascading across them is still correct: bail aborts that + * whole runner, so those tests do not run either. + * + * Runs as part of the failed test's finish when that comes from afterTest while mocha waits + * for it. When mocha has already moved on (the reporter's `fail`, or a timed-out test's late + * afterTest), settleTestFinishes() runs it instead: bail has already aborted the spec, and that + * still lands before the session status is marked and the last test finish is flushed + * (SDK-7843). + */ + private async reportBailSkippedTests(attempt: TestAttempt, results: Frameworks.TestResult | undefined) { + if (!attempt.bail || !results || results.passed || results.skipped) { + return + } + try { + // inside the boundary: hasRetryPending reaches into mocha's own runnable, which this + // SDK does not own + if (this.hasRetryPending(attempt.runnable, results)) { + return + } + let suite = attempt.runnable?.parent + if (!suite) { + return + } + while (suite.parent) { + suite = suite.parent + } + await reportSuiteSkipped(this, suite) + } catch (err) { + logger.debug(`Failed reporting bail-skipped tests: ${err}`) + } + } + + /** TEST/PRE: this attempt's finish is owed from here on, against this instance. */ + private openTestAttempt(instance: TestFrameworkInstance, args: Record) { + const test = args.test as Frameworks.Test + const attempt: TestAttempt = { + instance, + test, + suiteTitle: args.suiteTitle, + runnable: test.ctx?.test as MochaRunnable | undefined, + bail: args.bail === true + } + this.openAttempts.add(attempt) + this.latestAttemptByKey.set(WdioMochaTestFramework.attemptKey(test), attempt) + const body = WdioMochaTestFramework.testBody(test) + if (body) { + const byKey = this.attemptsByFn.get(body) ?? new Map() + byKey.set(WdioMochaTestFramework.attemptKey(test), attempt) + this.attemptsByFn.set(body, byKey) + } + } + + /** + * 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 + * 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 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) + } + + /** + * 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 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) + if (resolved) { + return resolved + } + const body = WdioMochaTestFramework.testBody(test) + if (body) { + return this.attemptsByFn.get(body)?.get(WdioMochaTestFramework.attemptKey(test)) + } + return this.latestAttemptByKey.get(WdioMochaTestFramework.attemptKey(test)) + } + + /** + * 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 test = args.test as Frameworks.Test + const source = args.fromMochaFail ? 'fail' : 'afterTest' + const attempt = this.findTestAttempt(test) + if (!attempt) { + // the reporter's `fail` for a hook, or for a test that never started + return source === 'fail' ? null : undefined + } + if (attempt.finished || (attempt.finishingFrom && attempt.finishingFrom !== source)) { + logger.debug(`trackEvent: '${WdioMochaTestFramework.attemptKey(test)}' was already reported, dropping ${testFrameworkState} ${hookState} from ${source}`) + return null + } + attempt.finishingFrom = source + this.resolvedFinishes.set(test, attempt) + args.suiteTitle ??= attempt.suiteTitle + // a timed-out test whose body finished late: wdio's result says only whether the body + // threw, not that mocha already failed it + if (attempt.runnable && this.mochaFailed(attempt) && (args.result as Frameworks.TestResult | undefined)?.passed) { + args.result = failureFromRunnable(attempt.runnable) + } + if (testFrameworkState === TestFrameworkState.TEST) { + attempt.finished = true + this.openAttempts.delete(attempt) + } + return attempt + } + + /** + * 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 run the bail cascades owed. Runs after + * drainSkipReports(), which waits for the finishes the reporter queued. + */ + async settleTestFinishes(): Promise { + for (const attempt of [...this.openAttempts]) { + 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 }) + await this.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: attempt.test, result, suiteTitle: attempt.suiteTitle, fromMochaFail: true }) + } + } + while (this.owedBailCascades.length > 0) { + const { attempt, result } = this.owedBailCascades.shift()! + await this.reportBailSkippedTests(attempt, result) + } + this.settled = true } /** diff --git a/packages/browserstack-service/src/cli/skipReporter.ts b/packages/browserstack-service/src/cli/skipReporter.ts index 4fff79d5..b76ef1e7 100644 --- a/packages/browserstack-service/src/cli/skipReporter.ts +++ b/packages/browserstack-service/src/cli/skipReporter.ts @@ -87,6 +87,18 @@ async function emitSkipReport({ framework, test, result, suiteTitle }: QueuedSki } } +/** + * 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. service.after() waits for the chain + * through drainSkipReports(). 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 +} + export function markTestStarted(identifier: string) { startedTests.add(identifier) } @@ -128,16 +140,14 @@ export function reportSkippedTest( const queued: QueuedSkip = { framework, test, result, suiteTitle } // SDK-7493: only the DETACHED caller needs deferring. `immediate` is for callers wdio - // awaits — the hook cascade (afterHook) and the bail cascade (afterTest). Those never had + // awaits — the hook cascade (afterHook) and the bail cascade (afterTest; when the failure was + // reported after mocha moved on, from service.after() instead, SDK-7843). Those never had // the interleave, because wdio holds the lifecycle open until they resolve, so nothing else // can claim the tracked slot underneath them. Deferring those too would be a behaviour // change for no benefit: their skips would move to end-of-run and their reports would no // longer be part of the hook/test they belong to. if (options?.immediate) { - reportChain = reportChain.then(() => emitSkipReport(queued)).catch((err: unknown) => { - BStackLogger.debug(`Failed reporting skipped test '${identifier}': ${err}`) - }) - return reportChain + return enqueueReport(() => emitSkipReport(queued), `skipped test '${identifier}'`) } // The un-awaited `onTestSkip` path: queue it — see the QueuedSkip docs above. Emitting here @@ -158,7 +168,8 @@ export function reportSkippedTest( * suite — report each state-undefined test as skipped, recursing into nested describes. * * Reports IMMEDIATELY (SDK-7493): every caller of this — the failed-hook cascade in - * `afterHook` and the bail cascade in `afterTest` — is awaited by wdio, so these reports + * `afterHook` and the bail cascade in `afterTest` (or in `after()`, for a failure reported after + * mocha moved on, SDK-7843) — is awaited by wdio, so these reports * cannot interleave with a live test the way the un-awaited `onTestSkip` path could. They * belong to the hook/test being reported, so they must not slide to end-of-run. */ diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index 68d77738..1ec9c580 100644 --- a/packages/browserstack-service/src/reporter.ts +++ b/packages/browserstack-service/src/reporter.ts @@ -4,7 +4,9 @@ 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' import { v4 as uuidv4 } from 'uuid' @@ -149,6 +151,42 @@ 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, 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. + */ + async onTestFail(testStats: TestStats) { + if (this._config?.framework !== 'mocha' || !BrowserstackCLI.getInstance().isRunning()) { + return + } + const framework = BrowserstackCLI.getInstance().getTestFramework() + if (!framework) { + return + } + // `retries` is this test's retry count so far, i.e. the attempt mocha just failed + 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' + } + // 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) { if (!this.needToSendData('test', 'end')) { return diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index 3c4af0db..3a1c76d7 100644 --- a/packages/browserstack-service/src/service.ts +++ b/packages/browserstack-service/src/service.ts @@ -70,20 +70,6 @@ export default class BrowserstackService implements Services.ServiceInstance { private _specsRan: boolean = false private _observability private _currentTest?: Frameworks.Test | ITestCaseHookParameter - /** - * CLI/gRPC path: map of test identity -> the test_uuid minted for it at - * INIT_TEST/PRE. The CLI mints a fresh uuid into a SINGLE mutable per-worker tracked instance - * (`trackWdioMochaInstance` overwrites `TestFramework.instances[ctxId]` wholesale on every - * INIT_TEST), and the gRPC test-finish reads the uuid from that single slot. When a test hangs - * past the mocha timeout, the NEXT test's INIT_TEST overwrites the slot before the hung test's - * afterTest POST fires, so the POST would carry the wrong (next) test's uuid and the binary - * would close the wrong test_run — orphaning the hung one. We snapshot each test's uuid here, - * keyed by the same identity the legacy `_tests` map uses, and at afterTest we restore the - * finishing test's minted uuid onto the tracked instance before the POST so it closes the - * correct test_run. The finishing identity is `originalTest` (already snapshotted pre-await by - * the testFnWrapper, so it is the timed-out runnable's own identity, not the next test's). - */ - private _cliTestUuids: Map = new Map() private _insightsHandler?: InsightsHandler private _accessibility private _accessibilityHandler?: AccessibilityHandler @@ -620,17 +606,11 @@ export default class BrowserstackService implements Services.ServiceInstance { if (BrowserstackCLI.getInstance().isRunning()) { await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) const uuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) - // snapshot this test's freshly-minted uuid keyed by its identity, so a later - // afterTest can restore it even after a subsequent INIT_TEST has overwritten the single - // mutable tracked-instance slot. Keyed exactly like the legacy `_tests` map. - if (this._config.framework === 'mocha' && uuid) { - this._cliTestUuids.set(getUniqueIdentifier(test, this._config.framework), uuid as string) - } // this test reports its own finish (incl. runtime `this.skip()`), so the // skip reporter must never re-report it from onTestSkip markTestStarted(getUniqueIdentifier(test, this._config.framework)) this._insightsHandler?.setTestData(test, uuid) - await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) + await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle, bail: this._mochaBail }) return } @@ -657,27 +637,12 @@ export default class BrowserstackService implements Services.ServiceInstance { } if (BrowserstackCLI.getInstance().isRunning()) { - // the CLI test-finish reads test_uuid from the single mutable per-worker - // tracked instance, which a later INIT_TEST may have overwritten with the NEXT test's - // uuid. `test` is `originalTest` — already the correct (timed-out) identity, snapshotted - // pre-await by the testFnWrapper — so restore THAT test's minted uuid onto the tracked - // instance so the POST carries it and the binary closes the correct test_run. Without - // this, the finish would carry the next test's uuid and orphan the finishing one. - if (this._config.framework === 'mocha') { - const identifier = getUniqueIdentifier(test, this._config.framework) - const resolvedUuid = this._cliTestUuids.get(identifier) - if (resolvedUuid) { - const trackedInstance = TestFramework.getTrackedInstance() - if (trackedInstance) { - TestFramework.setState(trackedInstance, TestFrameworkConstants.KEY_TEST_UUID, resolvedUuid) - } - // Clean up so the per-worker map does not grow across the run. - this._cliTestUuids.delete(identifier) - } - } + // `test` is `originalTest`, the timed-out runnable's own identity; the CLI framework + // reports the finish against the instance that test started on, even when a later + // test has taken the tracked-instance slot, drops it if mocha's `fail` already + // reported it, and runs the bail cascade (SDK-7843) await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result: results }) await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result: results, suiteTitle: this._suiteTitle }) - await this.reportBailSkippedTests(test, results) return } @@ -686,60 +651,6 @@ export default class BrowserstackService implements Services.ServiceInstance { await this._percyHandler?.afterTest() } - /** - * Whether this failure will be retried, in which case mocha has not dropped anything yet and - * the tests after it are still going to run. - * - * `results.retries` only tracks wdio's spec-file retries — `@wdio/utils` builds it as - * `{ attempts: 0, limit: repeatTest }` and `@wdio/mocha-framework` never feeds `mochaOpts.retries` - * into it, so under mocha-level retries it stays `{0, 0}` and tells us nothing. Read mocha's own - * runnable state for that case, otherwise the cascade fires on the first attempt and reports - * tests as skipped that the retry then actually runs. - */ - private hasRetryPending(test: Frameworks.Test, results: Frameworks.TestResult): boolean { - const mochaTest = test.ctx?.test as { currentRetry?: () => number, retries?: () => number } | undefined - if (typeof mochaTest?.currentRetry === 'function' && typeof mochaTest.retries === 'function') { - if (mochaTest.currentRetry() < mochaTest.retries()) { - return true - } - } - return Boolean(results.retries && results.retries.attempts < results.retries.limit) - } - - /** - * mocha's `bail` aborts the run on the first failure, so every test the spec had not reached - * yet is dropped without emitting any event and never appears on the dashboard. Report them - * as skipped — same cascade the failed-hook path uses, from the spec's root suite so sibling - * describes are covered too (bail kills the whole spec, not just the failing describe). - * - * The root can span more than one file when specs are grouped — `MochaAdapter` adds every spec - * it is handed to one mocha instance. Cascading across them is still correct: bail aborts that - * whole runner, so those tests do not run either. - */ - private async reportBailSkippedTests(test: Frameworks.Test, results: Frameworks.TestResult) { - if (!this._mochaBail || results.passed || results.skipped) { - return - } - try { - // inside the boundary: hasRetryPending reaches into mocha's own runnable, which this - // SDK does not own - if (this.hasRetryPending(test, results)) { - return - } - const framework = BrowserstackCLI.getInstance().getTestFramework() - let suite = test.ctx?.test?.parent - if (!framework || !suite) { - return - } - while (suite.parent) { - suite = suite.parent - } - await reportSuiteSkipped(framework, suite) - } catch (err) { - BStackLogger.debug(`Failed reporting bail-skipped tests: ${err}`) - } - } - @PerformanceTester.Measure(PERFORMANCE_SDK_EVENTS.EVENTS.SDK_HOOK, { hookType: 'after' }) async after (result: number) { try { @@ -768,6 +679,15 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (skipDrainErr) { BStackLogger.debug(`Exception draining skip reports in after(): ${util.format(skipDrainErr)}`) } + // SDK-7843: the drain above also waits for a timed-out test's finish, which the + // reporter's `fail` queues on the same chain. Then finish a failed test nothing + // reported (no reporter registered) and run owed bail cascades, before the flush + // below and before EXECUTE/POST, where the session status is marked + try { + await BrowserstackCLI.getInstance().getTestFramework()?.settleTestFinishes() + } catch (settleErr) { + BStackLogger.debug(`Exception settling test finishes in after(): ${util.format(settleErr)}`) + } // Flush a test-finish event deferred past the after-each hook window — the last // test of the worker has no next-test boundary to trigger the flush. Must run // before worker teardown so the event isn't dropped. @@ -854,12 +774,6 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (sweepErr) { BStackLogger.debug('Exception in sweepUnfinished during after(): ' + util.format(sweepErr)) } - // The sweep closes the _tests entries, but the CLI uuid snapshots (_cliTestUuids) are - // only drained in afterTest — the callback that never fires for a test the sweep just - // handled (e.g. one that timed out). Clear them here at per-worker teardown so stale - // snapshots cannot leak across the worker. Safe to clear: this runs after the sweep and - // no further afterTest will consume them in this worker. - this._cliTestUuids.clear() // Track Listener cleanup PerformanceTester.start(EVENTS.SDK_LISTENER_WORKER_END) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.filePath.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.filePath.test.ts deleted file mode 100644 index 6f89454d..00000000 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.filePath.test.ts +++ /dev/null @@ -1,78 +0,0 @@ -import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' -import path from 'node:path' -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 { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.js' - -vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) - -// Deliberately NOT under process.cwd(), so an absolute value and a cwd-relative -// value cannot coincide and mask a regression. -const SPEC = '/Users/someone/projects/arenaclub/test/specs/smoke/homePage.test.ts' - -describe('SDK-7233 — test_file_path must be the absolute spec path', () => { - beforeEach(() => { - vi.spyOn(TestFramework, 'getState').mockReturnValue('WebdriverIO-mocha') - vi.spyOn(util, 'getUniqueIdentifier').mockReturnValue('Verify the homepage elements') - vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) - }) - - afterEach(() => { - vi.restoreAllMocks() - }) - - // NB: not a default parameter — passing `undefined` explicitly must stay undefined. - const getTestData = (...args: [file?: string | undefined]) => - getTestDataWith(args.length ? args[0] : SPEC) - - const getTestDataWith = (file: string | undefined) => - // @ts-expect-error — partial TestFrameworkInstance / Frameworks.Test are enough here - WdioMochaTestFramework.prototype.getTestData.call(WdioMochaTestFramework.prototype, {}, { - file, - title: 'Verify the homepage elements', - body: 'async () => {}', - }) - - it('sends the absolute path, so the binary can re-base it itself', async () => { - // Previously this field was gated on a git root being resolvable; the - // customer's project had none ("Unable to find a Git directory"), so it - // went out as `undefined`, threw inside the binary, and dropped every - // TestRunStarted/TestRunFinished event. - const data = await getTestData() - - expect(data[TestFrameworkConstants.KEY_TEST_FILE_PATH]).toBe(SPEC) - expect(path.isAbsolute(data[TestFrameworkConstants.KEY_TEST_FILE_PATH] as string)).toBe(true) - }) - - it('does not consult git metadata for the file path at all', async () => { - // Re-basing is the binary's job (it holds pathProject and - // versionControlInfo.root). The emitter must not pre-relativise, and no - // longer pays for a git lookup per test. - const git = vi.spyOn(util, 'getGitMetaData') - - await getTestData() - - expect(git).not.toHaveBeenCalled() - }) - - it('keeps test_location cwd-relative and distinct from test_file_path', async () => { - const data = await getTestData() - - expect(data[TestFrameworkConstants.KEY_TEST_LOCATION]).toBe(path.relative(process.cwd(), SPEC)) - expect(data[TestFrameworkConstants.KEY_TEST_LOCATION]).not.toBe( - data[TestFrameworkConstants.KEY_TEST_FILE_PATH], - ) - }) - - it('leaves both fields undefined when the spec filename is unknown', async () => { - // Documented residual hole: a construct with no `test.file` still yields - // undefined. Not reachable for normal Mocha specs, which always carry one. - const data = await getTestData(undefined) - - expect(data[TestFrameworkConstants.KEY_TEST_FILE_PATH]).toBeUndefined() - expect(data[TestFrameworkConstants.KEY_TEST_LOCATION]).toBeUndefined() - }) -}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.logKind.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.logKind.test.ts deleted file mode 100644 index 3053e898..00000000 --- a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.logKind.test.ts +++ /dev/null @@ -1,69 +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 { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.js' -import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' -import { HookState } from '../../src/cli/states/hookState.js' - -vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) - -describe('SDK-4177 — loadLogEntries must not relabel a log that carries its own kind', () => { - let entries: unknown[] - let instance: any - - beforeEach(() => { - entries = [] - instance = { - getCurrentTestState: () => TestFrameworkState.TEST, - updateMultipleEntries: vi.fn(), - } - vi.spyOn(TestFramework, 'getState').mockReturnValue(entries) - vi.spyOn(WdioMochaTestFramework, 'lastActiveHook').mockReturnValue(null) - }) - - afterEach(() => { - vi.restoreAllMocks() - }) - - const load = (logEntry: Record) => { - WdioMochaTestFramework.prototype.loadLogEntries.call( - WdioMochaTestFramework.prototype, - instance, - TestFrameworkState.LOG, - HookState.POST, - logEntry - ) - return entries[0] as Record - } - - it('keeps TEST_SCREENSHOT, which the kind was previously hardcoded over', () => { - // Hardcoding KIND_LOG here meant a screenshot reached Observability labelled as a - // console log, so no screenshots manifest was ever built for the test run. - const record = load({ - kind: TestFrameworkConstants.KIND_SCREENSHOT, - message: 'aBase64Screenshot', - timestamp: '2020-01-01T00:00:00.000Z', - }) - - expect(record.kind).toBe('TEST_SCREENSHOT') - expect(record.message).toEqual(Buffer.from('aBase64Screenshot')) - }) - - it('still labels a console log TEST_LOG', () => { - const record = load({ - kind: TestFrameworkConstants.KIND_LOG, - message: 'hello', - level: 'info', - timestamp: '2020-01-01T00:00:00.000Z', - }) - - expect(record.kind).toBe('TEST_LOG') - expect(record.level).toBe('info') - }) - - it('falls back to TEST_LOG for an entry with no kind', () => { - expect(load({ message: 'hello', timestamp: '2020-01-01T00:00:00.000Z' }).kind).toBe('TEST_LOG') - }) -}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.test.ts new file mode 100644 index 00000000..608cdf2b --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.test.ts @@ -0,0 +1,629 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import path from 'node:path' +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 { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.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 type TestFrameworkInstance from '../../src/cli/instances/testFrameworkInstance.js' +import { drainSkipReports, enqueueReport } from '../../src/cli/skipReporter.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +// Deliberately NOT under process.cwd(), so an absolute value and a cwd-relative +// value cannot coincide and mask a regression. +const SPEC = '/Users/someone/projects/arenaclub/test/specs/smoke/homePage.test.ts' + +describe('SDK-7233 — test_file_path must be the absolute spec path', () => { + beforeEach(() => { + vi.spyOn(TestFramework, 'getState').mockReturnValue('WebdriverIO-mocha') + vi.spyOn(util, 'getUniqueIdentifier').mockReturnValue('Verify the homepage elements') + vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + // NB: not a default parameter — passing `undefined` explicitly must stay undefined. + const getTestData = (...args: [file?: string | undefined]) => + getTestDataWith(args.length ? args[0] : SPEC) + + const getTestDataWith = (file: string | undefined) => + // @ts-expect-error — partial TestFrameworkInstance / Frameworks.Test are enough here + WdioMochaTestFramework.prototype.getTestData.call(WdioMochaTestFramework.prototype, {}, { + file, + title: 'Verify the homepage elements', + body: 'async () => {}', + }) + + it('sends the absolute path, so the binary can re-base it itself', async () => { + // Previously this field was gated on a git root being resolvable; the + // customer's project had none ("Unable to find a Git directory"), so it + // went out as `undefined`, threw inside the binary, and dropped every + // TestRunStarted/TestRunFinished event. + const data = await getTestData() + + expect(data[TestFrameworkConstants.KEY_TEST_FILE_PATH]).toBe(SPEC) + expect(path.isAbsolute(data[TestFrameworkConstants.KEY_TEST_FILE_PATH] as string)).toBe(true) + }) + + it('does not consult git metadata for the file path at all', async () => { + // Re-basing is the binary's job (it holds pathProject and + // versionControlInfo.root). The emitter must not pre-relativise, and no + // longer pays for a git lookup per test. + const git = vi.spyOn(util, 'getGitMetaData') + + await getTestData() + + expect(git).not.toHaveBeenCalled() + }) + + it('keeps test_location cwd-relative and distinct from test_file_path', async () => { + const data = await getTestData() + + expect(data[TestFrameworkConstants.KEY_TEST_LOCATION]).toBe(path.relative(process.cwd(), SPEC)) + expect(data[TestFrameworkConstants.KEY_TEST_LOCATION]).not.toBe( + data[TestFrameworkConstants.KEY_TEST_FILE_PATH], + ) + }) + + it('leaves both fields undefined when the spec filename is unknown', async () => { + // Documented residual hole: a construct with no `test.file` still yields + // undefined. Not reachable for normal Mocha specs, which always carry one. + const data = await getTestData(undefined) + + expect(data[TestFrameworkConstants.KEY_TEST_FILE_PATH]).toBeUndefined() + expect(data[TestFrameworkConstants.KEY_TEST_LOCATION]).toBeUndefined() + }) +}) + +describe('SDK-4177 — loadLogEntries must not relabel a log that carries its own kind', () => { + let entries: unknown[] + let instance: any + + beforeEach(() => { + entries = [] + instance = { + getCurrentTestState: () => TestFrameworkState.TEST, + updateMultipleEntries: vi.fn(), + } + vi.spyOn(TestFramework, 'getState').mockReturnValue(entries) + vi.spyOn(WdioMochaTestFramework, 'lastActiveHook').mockReturnValue(null) + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + const load = (logEntry: Record) => { + WdioMochaTestFramework.prototype.loadLogEntries.call( + WdioMochaTestFramework.prototype, + instance, + TestFrameworkState.LOG, + HookState.POST, + logEntry + ) + return entries[0] as Record + } + + it('keeps TEST_SCREENSHOT, which the kind was previously hardcoded over', () => { + // Hardcoding KIND_LOG here meant a screenshot reached Observability labelled as a + // console log, so no screenshots manifest was ever built for the test run. + const record = load({ + kind: TestFrameworkConstants.KIND_SCREENSHOT, + message: 'aBase64Screenshot', + timestamp: '2020-01-01T00:00:00.000Z', + }) + + expect(record.kind).toBe('TEST_SCREENSHOT') + expect(record.message).toEqual(Buffer.from('aBase64Screenshot')) + }) + + it('still labels a console log TEST_LOG', () => { + const record = load({ + kind: TestFrameworkConstants.KIND_LOG, + message: 'hello', + level: 'info', + timestamp: '2020-01-01T00:00:00.000Z', + }) + + expect(record.kind).toBe('TEST_LOG') + expect(record.level).toBe('info') + }) + + it('falls back to TEST_LOG for an entry with no kind', () => { + expect(load({ message: 'hello', timestamp: '2020-01-01T00:00:00.000Z' }).kind).toBe('TEST_LOG') + }) +}) + +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')) + }) +}) + +describe('mocha bail skip cascade (SDK-7063), run by the CLI framework with the test\'s finish', () => { + let framework: WdioMochaTestFramework + let trackEvent: ReturnType + + // reportSkippedTest de-dupes on `${parent} - ${title}` in a module-scope Set that outlives + // each test, so every case here needs its own titles. + const buildTree = (tag: string) => { + const root: any = { title: '', tests: [], suites: [], parent: undefined } + const suiteA: any = { title: `${tag} Suite A`, tests: [], suites: [], parent: root } + const suiteB: any = { title: `${tag} Suite B`, tests: [], suites: [], parent: root } + root.suites.push(suiteA, suiteB) + + const ran: any = { title: `${tag} A1`, state: 'passed', parent: suiteA, file: '/spec/a.js' } + const failing: any = { title: `${tag} A2`, state: 'failed', parent: suiteA, file: '/spec/a.js' } + const dropped: any = { title: `${tag} A3`, parent: suiteA, file: '/spec/a.js' } + suiteA.tests.push(ran, failing, dropped) + // sibling top-level describe — only reachable because the cascade walks up to root + suiteB.tests.push({ title: `${tag} B1`, parent: suiteB, file: '/spec/a.js' }) + + failing.ctx = { test: { parent: suiteA } } + return { failing, root } + } + + /** beforeTest's events, then afterTest's, as the service sends them. */ + const runTest = async (failing: any, results: Record, bail = true) => { + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail }) + trackEvent.mockClear() + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: results }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: results, suiteTitle: 'suite' }) + } + + // WHICH tests got reported, not just how many events fired — a cascade that swept the wrong + // tests still produces the same call count. Pairs with the count assertions, which catch the + // opposite failure (a test emitted twice). + const skippedTitles = () => [...new Set( + trackEvent.mock.calls + .filter(([, , payload]: any[]) => payload?.result?.skipped === true) + .map(([, , payload]: any[]) => payload.test.title as string) + )].sort() + + beforeEach(() => { + TestFramework.instances.clear() + framework = new WdioMochaTestFramework(['WebdriverIO-mocha'], { 'WebdriverIO-mocha': '9' }, 'bin-session-id') + vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) + vi.spyOn(util, 'getTestTags').mockReturnValue([]) + for (const level of ['info', 'debug', 'error'] as const) { + vi.spyOn(cliLogger, level).mockImplementation(() => {}) + } + vi.spyOn(framework, 'runHooks').mockResolvedValue(undefined) + trackEvent = vi.spyOn(framework, 'trackEvent') + }) + + afterEach(() => { + vi.restoreAllMocks() + TestFramework.instances.clear() + }) + + it('reports un-run tests across sibling describes when mocha bail is on', async () => { + const { failing } = buildTree('bail1') + await runTest(failing, { passed: false }) + + // 2 events close the failing test (LOG_REPORT/POST + TEST/POST), then 4 per skipped test. + // A3 (same describe) and B1 (SIBLING describe) => 2 skipped => 8. + expect(trackEvent).toHaveBeenCalledTimes(2 + 8) + // exactly the un-run tests: A1 already passed and A2 is the failure being reported, + // so sweeping either of them in would be a defect the count alone cannot see + expect(skippedTitles()).toEqual(['bail1 A3', 'bail1 B1']) + }) + + it('does not cascade without mocha bail', async () => { + const { failing } = buildTree('bail2') + await runTest(failing, { passed: false }, false) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade while a wdio spec-file retry is still queued', async () => { + const { failing } = buildTree('bail3') + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 2 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade while a MOCHA-level retry is still queued', async () => { + // wdio's `results.retries` only tracks spec-file retries — @wdio/mocha-framework never + // feeds mochaOpts.retries into it, so it reads {0,0} here and cannot be relied on. + // Without reading mocha's own runnable state the cascade fires on attempt 1 and reports + // tests as skipped that the retry then actually runs. + const { failing } = buildTree('bail5') + failing.ctx.test.currentRetry = () => 0 + failing.ctx.test.retries = () => 1 + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 0 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('cascades once the final mocha retry has been used', async () => { + const { failing } = buildTree('bail6') + failing.ctx.test.currentRetry = () => 1 + failing.ctx.test.retries = () => 1 + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 0 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2 + 8) + expect(skippedTitles()).toEqual(['bail6 A3', 'bail6 B1']) + }) + + it('cascades from the runnable the test started on, not the hook mocha moved on to (SDK-7843)', async () => { + // the final attempt under `retries: 1` times out; mocha moves on to an afterEach hook, + // which inherits the suite's retries, before the finish is reported + const { failing } = buildTree('bail9') + failing.ctx.test.currentRetry = () => 1 + failing.ctx.test.retries = () => 1 + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + failing.ctx.test = { parent: failing.parent, currentRetry: () => 0, retries: () => 1 } + trackEvent.mockClear() + + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.settleTestFinishes() + + expect(skippedTitles()).toEqual(['bail9 A3', 'bail9 B1']) + }) + + it('runs the cascade for a failure reported by mocha\'s `fail` from settle, not under the test\'s after-hooks (SDK-7843)', async () => { + const { failing } = buildTree('bail10') + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + const failedUuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) + trackEvent.mockClear() + + // the reporter's `fail`, which wdio does not await; mocha then runs the test's afterEach + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.AFTER_EACH, HookState.PRE, { test: failing }) + + expect(skippedTitles()).toEqual([]) + expect(TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID)).toBe(failedUuid) + + await framework.settleTestFinishes() + expect(skippedTitles()).toEqual(['bail10 A3', 'bail10 B1']) + }) + + it('runs the cascade from settle for a timed-out test\'s late afterTest, with no reporter (SDK-7843)', async () => { + const { failing } = buildTree('bail11') + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + const failedUuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) + // mocha timed the test out and moved on to its afterEach; wdio's afterTest arrives late + Object.assign(failing.ctx.test, { state: 'failed', timedOut: true }) + trackEvent.mockClear() + + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false } }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, suiteTitle: 'suite' }) + await framework.trackEvent(TestFrameworkState.AFTER_EACH, HookState.PRE, { test: failing }) + + expect(skippedTitles()).toEqual([]) + expect(TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID)).toBe(failedUuid) + + await framework.settleTestFinishes() + expect(skippedTitles()).toEqual(['bail11 A3', 'bail11 B1']) + }) + + it('does not cascade when the test passed', async () => { + const { failing } = buildTree('bail4') + await runTest(failing, { passed: true }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade when the test was itself skipped', async () => { + // a skipped test does not abort the spec, and the pre-existing skip paths already + // report it — cascading here would double-report the rest of the suite + const { failing } = buildTree('bail7') + await runTest(failing, { passed: false, skipped: true }) + + // A2 is the test being reported and its own result is legitimately `skipped`; what must + // NOT appear is A3/B1, which the cascade would have added. + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual(['bail7 A2']) + }) + + it('never throws out of the finish when mocha state is hostile', async () => { + // afterTest is awaited by wdio; anything escaping this cascade would surface as a + // framework-level error in the user's run + const { failing } = buildTree('bail8') + failing.ctx.test.currentRetry = () => { throw new Error('mocha exploded') } + failing.ctx.test.retries = () => 1 + + await runTest(failing, { passed: false }) + expect(skippedTitles()).toEqual([]) + }) +}) + +/** + * 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 does in `fail`: pin the test, then queue its finish; wdio does not await it. */ + const reporterFail = (test: Frameworks.Test, result = failed) => { + 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(() => { + 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 settle() + 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 settle() + + 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 settle() + + 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 settle() + + 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 settle() + + 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`]) + }) + + 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 () => { + 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 settle() + 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 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`: 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 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) + + 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')) + + reporterFail(makeTest('"before each" hook for runs')) + await settle() + expect(finishes).toEqual([]) + + await afterTest(makeTest('unseen'), passed) + expect(finishes).toHaveLength(1) + }) +}) diff --git a/packages/browserstack-service/tests/reporter.test.ts b/packages/browserstack-service/tests/reporter.test.ts index da59c2c2..acb53ed5 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' const log = logger('test') @@ -355,3 +360,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.afterSkipOrdering.test.ts b/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts deleted file mode 100644 index 828cc0e3..00000000 --- a/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts +++ /dev/null @@ -1,103 +0,0 @@ -import path from 'node:path' - -import { describe, expect, it, vi, beforeEach } from 'vitest' - -import BrowserstackService from '../src/service.js' -import { drainSkipReports } from '../src/cli/skipReporter.js' -import { BrowserstackCLI } from '../src/cli/index.js' - -vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) - -vi.mock('../src/cli/skipReporter.js', () => ({ - drainSkipReports: vi.fn().mockResolvedValue(undefined), - markTestStarted: vi.fn(), - reportSuiteSkipped: vi.fn().mockResolvedValue(undefined), - reportSkippedTest: vi.fn().mockResolvedValue(undefined), - resolveSpecFile: vi.fn() -})) - -vi.mock('../src/testOps/listener.js', () => ({ - default: { getInstance: () => ({ onWorkerEnd: vi.fn().mockResolvedValue(undefined) }) } -})) - -vi.mock('../src/data-store.js', () => ({ saveWorkerData: vi.fn() })) - -vi.mock('../src/instrumentation/performance/performance-tester.js', () => ({ - default: { - start: vi.fn(), - end: vi.fn(), - startMonitoring: vi.fn(), - stopAndGenerate: vi.fn().mockResolvedValue(undefined), - calculateTimes: vi.fn(), - measureWrapper: vi.fn().mockImplementation((_name: string, fn: Function) => fn), - Measure: vi.fn().mockImplementation(() => (_t: any, _k: string, d: PropertyDescriptor) => d) - } -})) - -const flushPendingTestFinishEvent = vi.fn().mockResolvedValue(undefined) - -vi.mock('../src/cli/index.js', () => ({ - BrowserstackCLI: { - getInstance: vi.fn() - } -})) - -/** - * SDK-7493 — `service.after()` must drain the skip-report chain BEFORE flushing the - * deferred test-finish. - * - * wdio does not await `onTestSkip`, so skip reports are still in flight when `after()` - * starts, and each one ENDS by emitting mocha TEST/POST — which TestHubModule stashes in - * its single-slot `pendingTestFinish` instead of sending. Flushing first therefore flushes - * an empty slot and strands the stash that lands moments later; with `describe.skip()` - * there is no next test to flush it either, so the test stays "in progress" until Test - * Hub's ~60-min idle reap stamps the whole build `timeout`. - * - * This asserts the ORDER, which is the whole fix — both calls being present is not enough. - */ -describe('service.after() — skip drain must precede the deferred-finish flush (SDK-7493)', () => { - beforeEach(() => { - vi.clearAllMocks() - vi.mocked(BrowserstackCLI.getInstance).mockReturnValue({ - isRunning: () => true, - modules: { TestHubModule: { flushPendingTestFinishEvent } }, - getAutomationFramework: () => ({ trackEvent: vi.fn().mockResolvedValue(undefined) }) - } as never) - }) - - function fakeService() { - return { - _options: { setSessionStatus: false, setSessionName: false, preferScenarioName: false }, - _scenariosRanCount: 0, - _lastScenarioName: undefined, - _fullTitle: 'suite - test', - _specsRan: true, - _failReasons: [], - _pureTestFailReasons: [], - _hookFailReasons: [], - _insightsHandler: undefined, - _percyHandler: undefined, - _cliTestUuids: new Map(), - saveWorkerData: vi.fn() - } - } - - it('drains queued skip reports before flushing the deferred test finish', async () => { - await BrowserstackService.prototype.after.call(fakeService() as never, 0) - - expect(drainSkipReports).toHaveBeenCalledTimes(1) - expect(flushPendingTestFinishEvent).toHaveBeenCalledTimes(1) - - const drainOrder = vi.mocked(drainSkipReports).mock.invocationCallOrder[0] - const flushOrder = flushPendingTestFinishEvent.mock.invocationCallOrder[0] - expect(drainOrder).toBeLessThan(flushOrder) - }) - - it('still flushes when the skip drain rejects — a drain failure must not strand the finish', async () => { - vi.mocked(drainSkipReports).mockRejectedValueOnce(new Error('skip chain blew up')) - - await BrowserstackService.prototype.after.call(fakeService() as never, 0) - - expect(flushPendingTestFinishEvent).toHaveBeenCalledTimes(1) - }) -}) diff --git a/packages/browserstack-service/tests/service.test.ts b/packages/browserstack-service/tests/service.test.ts index 291a2c39..4f5040b2 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 logger from '@wdio/logger' import BrowserstackService from '../src/service.js' @@ -9,10 +10,12 @@ import InsightsHandler from '../src/insights-handler.js' import { BrowserstackCLI } from '../src/cli/index.js' import AccessibilityModule from '../src/cli/modules/accessibilityModule.js' import * as bstackLogger from '../src/bstackLogger.js' +import * as skipReporter from '../src/cli/skipReporter.js' import AutomationFramework from '../src/cli/frameworks/automationFramework.js' import WdioCucumberTestFramework from '../src/cli/frameworks/wdioCucumberTestFramework.js' import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' +import TestFramework from '../src/cli/frameworks/testFramework.js' import { AutomationFrameworkConstants } from '../src/cli/frameworks/constants/automationFrameworkConstants.js' import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' @@ -58,6 +61,7 @@ vi.mock('../src/instrumentation/performance/performance-tester.js', () => ({ start: vi.fn(), end: vi.fn(), startMonitoring: vi.fn(), + stopAndGenerate: vi.fn().mockResolvedValue(undefined), measureWrapper: vi.fn().mockImplementation((_name: string, fn: Function) => fn), Measure: vi.fn().mockImplementation(() => (_target: any, _propertyKey: string, descriptor: PropertyDescriptor) => descriptor), browser: undefined, @@ -2672,157 +2676,43 @@ describe('_isAppAutomate honors skipAppOverride', () => { }) }) -describe('afterTest bail skip cascade (SDK-7063)', () => { +describe('beforeTest passes mocha\'s bail to the CLI framework (SDK-7063)', () => { + // the cascade itself runs in WdioMochaTestFramework (tests/cli/wdioMochaTestFramework.bailCascade.test.ts) let getInstanceSpy: ReturnType - // reportSkippedTest de-dupes on `${parent} - ${title}` in a module-scope Set that outlives - // each test, so every case here needs its own titles. - const buildTree = (tag: string) => { - const root: any = { title: '', tests: [], suites: [], parent: undefined } - const suiteA: any = { title: `${tag} Suite A`, tests: [], suites: [], parent: root } - const suiteB: any = { title: `${tag} Suite B`, tests: [], suites: [], parent: root } - root.suites.push(suiteA, suiteB) - - const ran: any = { title: `${tag} A1`, state: 'passed', parent: suiteA, file: '/spec/a.js' } - const failing: any = { title: `${tag} A2`, state: 'failed', parent: suiteA, file: '/spec/a.js' } - const dropped: any = { title: `${tag} A3`, parent: suiteA, file: '/spec/a.js' } - suiteA.tests.push(ran, failing, dropped) - // sibling top-level describe — only reachable because the cascade walks up to root - suiteB.tests.push({ title: `${tag} B1`, parent: suiteB, file: '/spec/a.js' }) - - failing.ctx = { test: { parent: suiteA } } - return { failing, root } - } - const makeService = (config: Record) => new BrowserstackService( { testObservability: false } as any, [] as any, { user: 'foo', key: 'bar', ...config } as any ) - const runAfterTest = async (svc: BrowserstackService, failing: any, results: Record) => { + const bailSent = async (config: Record) => { const trackEvent = vi.fn().mockResolvedValue(undefined) getInstanceSpy = vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true, getTestFramework: () => ({ trackEvent }) } as any) - await svc.afterTest(failing, undefined as never, results as any) - return trackEvent + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as any) + vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid' as any) + await makeService(config).beforeTest({ title: 'test', parent: 'suite' } as any) + const [, , args] = trackEvent.mock.calls.find(([state, hook]: any[]) => state === TestFrameworkState.TEST && hook === HookState.PRE)! + return args.bail } - // WHICH tests got reported, not just how many events fired — a cascade that swept the wrong - // tests still produces the same call count. Pairs with the count assertions, which catch the - // opposite failure (a test emitted twice). - const skippedTitles = (trackEvent: ReturnType) => [...new Set( - trackEvent.mock.calls - .filter(([, , payload]: any[]) => payload?.result?.skipped === true) - .map(([, , payload]: any[]) => payload.test.title as string) - )].sort() - afterEach(() => { getInstanceSpy?.mockRestore() + vi.mocked(TestFramework.getTrackedInstance).mockRestore() + vi.mocked(TestFramework.getState).mockRestore() }) - it('reports un-run tests across sibling describes when mocha bail is on', async () => { - const { failing } = buildTree('bail1') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - - // 2 events close the failing test (LOG_REPORT/POST + TEST/POST), then 4 per skipped test. - // A3 (same describe) and B1 (SIBLING describe) => 2 skipped => 8. - expect(trackEvent).toHaveBeenCalledTimes(2 + 8) - // exactly the un-run tests: A1 already passed and A2 is the failure being reported, - // so sweeping either of them in would be a defect the count alone cannot see - expect(skippedTitles(trackEvent)).toEqual(['bail1 A3', 'bail1 B1']) + it('sends bail when mocha bail is on', async () => { + expect(await bailSent({ framework: 'mocha', mochaOpts: { bail: true } })).toBe(true) }) - it('does not cascade when only wdio-level bail is set', async () => { + it('does not send bail when only wdio-level bail is set', async () => { // wdio's `bail` never halts a spec, so those tests still run — reporting them - // as skipped here would double-report them. - const { failing } = buildTree('bail2') - const svc = makeService({ framework: 'mocha', bail: 1 }) - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade while a wdio spec-file retry is still queued', async () => { - const { failing } = buildTree('bail3') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 2 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade while a MOCHA-level retry is still queued', async () => { - // wdio's `results.retries` only tracks spec-file retries — @wdio/mocha-framework never - // feeds mochaOpts.retries into it, so it reads {0,0} here and cannot be relied on. - // Without reading mocha's own runnable state the cascade fires on attempt 1 and reports - // tests as skipped that the retry then actually runs. - const { failing } = buildTree('bail5') - failing.ctx.test.currentRetry = () => 0 - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true, retries: 1 } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 0 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('cascades once the final mocha retry has been used', async () => { - const { failing } = buildTree('bail6') - failing.ctx.test.currentRetry = () => 1 - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true, retries: 1 } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 0 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2 + 8) - expect(skippedTitles(trackEvent)).toEqual(['bail6 A3', 'bail6 B1']) - }) - - it('does not cascade when the test passed', async () => { - const { failing } = buildTree('bail4') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: true }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade when the test was itself skipped', async () => { - // a skipped test does not abort the spec, and the pre-existing skip paths already - // report it — cascading here would double-report the rest of the suite - const { failing } = buildTree('bail7') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: false, skipped: true }) - - // A2 is the test being reported and its own result is legitimately `skipped`; what must - // NOT appear is A3/B1, which the cascade would have added. - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual(['bail7 A2']) - }) - - it('never throws out of afterTest when mocha state is hostile', async () => { - // afterTest is awaited by wdio; anything escaping this cascade would surface as a - // framework-level error in the user's run - const { failing } = buildTree('bail8') - failing.ctx.test.currentRetry = () => { throw new Error('mocha exploded') } - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - expect(skippedTitles(trackEvent)).toEqual([]) + // as skipped would double-report them. + expect(await bailSent({ framework: 'mocha', bail: 1 })).toBe(false) }) }) @@ -3146,3 +3036,153 @@ describe('_cucumberTestResult failure reason adjacent', () => { expect(result.error?.message).toBe('Unknown Error') }) }) + +/** + * SDK-7843 — with a mocha timeout, mocha fails the test (the reporter sends its finish) while its + * body and wdio's afterTest are still pending; with `bail`, wdio then runs after() before that + * afterTest. after() must let that finish land before the flush and before EXECUTE/POST, where + * AutomateModule marks the session status. + */ +describe('service 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 }> + // the `after` suite above replaces BrowserstackService.prototype.after in its beforeEach; this + // runs at collection, before any hook, so it keeps the real one + const realAfter = BrowserstackService.prototype.after + + 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)}`) + }) + }), + modules: { TestHubModule: { flushPendingTestFinishEvent: vi.fn().mockImplementation(async () => { events.push('flushPendingTestFinishEvent') }) } } + } 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 the deferred-finish flush and before EXECUTE/POST', async () => { + await realAfter.call(makeService(), 1) + + expect(events).toEqual(['settleTestFinishes', 'flushPendingTestFinishEvent', `${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}` + ]) + }) +}) + +/** + * SDK-7493 — `service.after()` must drain the skip-report chain BEFORE flushing the + * deferred test-finish. + * + * wdio does not await `onTestSkip`, so skip reports are still in flight when `after()` + * starts, and each one ENDS by emitting mocha TEST/POST — which TestHubModule stashes in + * its single-slot `pendingTestFinish` instead of sending. Flushing first therefore flushes + * an empty slot and strands the stash that lands moments later; with `describe.skip()` + * there is no next test to flush it either, so the test stays "in progress" until Test + * Hub's ~60-min idle reap stamps the whole build `timeout`. + * + * This asserts the ORDER, which is the whole fix — both calls being present is not enough. + */ +describe('service.after() — skip drain must precede the deferred-finish flush (SDK-7493)', () => { + // the `after` suite above replaces BrowserstackService.prototype.after; keep the real one + const realAfter = BrowserstackService.prototype.after + const flushPendingTestFinishEvent = vi.fn().mockResolvedValue(undefined) + let spies: Array<{ mockRestore: () => void }> + let drainSkipReports: ReturnType + + beforeEach(() => { + flushPendingTestFinishEvent.mockClear() + drainSkipReports = vi.spyOn(skipReporter, 'drainSkipReports').mockResolvedValue(undefined) + spies = [ + drainSkipReports, + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ + isRunning: () => true, + modules: { TestHubModule: { flushPendingTestFinishEvent } }, + getAutomationFramework: () => ({ trackEvent: vi.fn().mockResolvedValue(undefined) }) + } as never) + ] + }) + + afterEach(() => { + spies.forEach((spy) => spy.mockRestore()) + }) + + function fakeService() { + return { + _options: { setSessionStatus: false, setSessionName: false, preferScenarioName: false }, + _scenariosRanCount: 0, + _lastScenarioName: undefined, + _fullTitle: 'suite - test', + _specsRan: true, + _failReasons: [], + _pureTestFailReasons: [], + _hookFailReasons: [], + _insightsHandler: undefined, + _percyHandler: undefined, + saveWorkerData: vi.fn() + } + } + + it('drains queued skip reports before flushing the deferred test finish', async () => { + await realAfter.call(fakeService() as never, 0) + + expect(drainSkipReports).toHaveBeenCalledTimes(1) + expect(flushPendingTestFinishEvent).toHaveBeenCalledTimes(1) + + const drainOrder = drainSkipReports.mock.invocationCallOrder[0] + const flushOrder = flushPendingTestFinishEvent.mock.invocationCallOrder[0] + expect(drainOrder).toBeLessThan(flushOrder) + }) + + it('still flushes when the skip drain rejects — a drain failure must not strand the finish', async () => { + drainSkipReports.mockRejectedValueOnce(new Error('skip chain blew up')) + + await realAfter.call(fakeService() as never, 0) + + expect(flushPendingTestFinishEvent).toHaveBeenCalledTimes(1) + }) +})