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..4266ed79 100644 --- a/packages/browserstack-service/src/cli/frameworks/testFramework.ts +++ b/packages/browserstack-service/src/cli/frameworks/testFramework.ts @@ -84,6 +84,13 @@ export default class TestFramework { logger.info(`trackEvent: testFrameworkState=${testFrameworkState}; hookState=${hookState}; args=${args}`) } + /** + * Wait for test finishes that are still being reported. A module calls this before it reads the + * final results of the run (session status, the last deferred test finish). + * @returns {Promise} + */ + async settleTestFinishes(): Promise {} + /** * run test hooks * @param {TestFrameworkInstance} instance diff --git a/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts b/packages/browserstack-service/src/cli/frameworks/wdioMochaTestFramework.ts index 8a885982..dd2c39d8 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,89 @@ 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. wdio hands beforeTest and afterTest separate copies of the mocha + * test (`{ ...context.test }`), but both carry its `fn`, so afterTest finds its own attempt even + * when another test with the same key has started since. + */ + private attemptsByFn = new WeakMap>() + /** The attempt a source's LOG_REPORT/POST resolved; its TEST/POST passes the same `test` object. */ + private resolvedFinishes = new WeakMap() + private pendingFinishes = new Set>() + /** Bail cascades of failures the reporter's `fail` reported; settleTestFinishes() runs them. */ + private owedBailCascades: Array<{ attempt: TestAttempt, result: Frameworks.TestResult }> = [] + + /** One attempt of a test: mocha retries a test as a new runnable with `_currentRetry` + 1. */ + static attemptKey(test: Frameworks.Test): string { + const retry = (test as { _currentRetry?: number })._currentRetry + const identifier = getUniqueIdentifier(test, 'mocha') + return retry ? `${identifier} (retry ${retry})` : identifier + } + + private static testBody(test: Frameworks.Test): object | undefined { + const fn = (test as { fn?: unknown }).fn + return typeof fn === 'function' ? fn : undefined + } + /** * Constructor for the TestFramework * @param {Array} testFrameworks - List of Test frameworks @@ -52,14 +132,52 @@ export default class WdioMochaTestFramework extends TestFramework { * @param {*} args */ async trackEvent(testFrameworkState: State, hookState: State, args: Record = {}) { + if (args.fromMochaFail) { + // the reporter's `fail` (SDK-7843): wdio does not await reporter callbacks, so keep the + // send visible to settleTestFinishes() + const work = this.trackTestEvent(testFrameworkState, hookState, args).catch((err: unknown) => { + logger.debug(`trackEvent: reporting a failed test failed: ${err}`) + }) + this.pendingFinishes.add(work) + work.finally(() => this.pendingFinishes.delete(work)) + return work + } + await this.trackTestEvent(testFrameworkState, hookState, args) + } + + private async trackTestEvent(testFrameworkState: State, hookState: State, args: Record) { logger.info(`trackEvent: testFrameworkState=${testFrameworkState} hookState=${hookState}`) + // before any await: the reporter's `fail` must resolve to the attempt mocha just failed, + // before mocha starts the next test (it defers that with setImmediate) + const attempt = this.resolveTestAttempt(testFrameworkState, hookState, args) await super.trackEvent(testFrameworkState, hookState, args) - 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 +230,172 @@ export default class WdioMochaTestFramework extends TestFramework { } args.instance = instance await this.runHooks(instance, testFrameworkState, hookState, args) + if (attempt && testFrameworkState === TestFrameworkState.TEST) { + if (args.fromMochaFail) { + // wdio does not await the reporter's `fail`, and mocha still runs the failed test's + // after-hooks: the cascade's skip reports would claim the tracked slot under them + this.owedBailCascades.push({ attempt, result: args.result as Frameworks.TestResult }) + } else { + await this.reportBailSkippedTests(attempt, args.result as Frameworks.TestResult) + } + } + } + + /** + * 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, which wdio awaits. + * When it comes from the reporter's `fail`, which wdio does not await, settleTestFinishes() + * runs it instead: bail has already aborted the spec, and that still lands before the session + * status is marked and the last test finish is flushed (SDK-7843). + */ + private async reportBailSkippedTests(attempt: TestAttempt, results: Frameworks.TestResult | undefined) { + if (!attempt.bail || !results || results.passed || results.skipped) { + 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 byRetry = this.attemptsByFn.get(body) ?? new Map() + byRetry.set((test as { _currentRetry?: number })._currentRetry ?? 0, attempt) + this.attemptsByFn.set(body, byRetry) + } + } + + /** + * The attempt a finish belongs to. wdio's afterTest carries the test's body, which identifies + * it exactly. The reporter's `fail` has only the title and parent: it is resolved (before any + * await, see trackTestEvent) to the latest attempt with that key, which is the one mocha just + * failed, and pinned so the same source's TEST/POST cannot land on a later same-named test. + */ + private findTestAttempt(test: Frameworks.Test): TestAttempt | undefined { + const resolved = this.resolvedFinishes.get(test) + if (resolved) { + return resolved + } + const body = WdioMochaTestFramework.testBody(test) + if (body) { + return this.attemptsByFn.get(body)?.get((test as { _currentRetry?: number })._currentRetry ?? 0) + } + return this.latestAttemptByKey.get(WdioMochaTestFramework.attemptKey(test)) + } + + /** + * 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?.state === 'failed' && (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 that nothing reported (no reporter is registered when Test Reporting, + * Accessibility and Percy are all off), then wait for every finish the reporter started, then + * run the bail cascades those finishes owe. + */ + async settleTestFinishes(): Promise { + for (const attempt of [...this.openAttempts]) { + if (attempt.runnable?.state === 'failed' && !attempt.finishingFrom) { + const result = failureFromRunnable(attempt.runnable) + this.resolvedFinishes.set(attempt.test, attempt) + await this.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: attempt.test, result, fromMochaFail: true }) + await this.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: attempt.test, result, suiteTitle: attempt.suiteTitle, fromMochaFail: true }) + } + } + while (this.pendingFinishes.size > 0) { + await Promise.all([...this.pendingFinishes]) + } + for (const { attempt, result } of this.owedBailCascades.splice(0)) { + await this.reportBailSkippedTests(attempt, result) + } } /** diff --git a/packages/browserstack-service/src/cli/skipReporter.ts b/packages/browserstack-service/src/cli/skipReporter.ts index 4fff79d5..76cb2bec 100644 --- a/packages/browserstack-service/src/cli/skipReporter.ts +++ b/packages/browserstack-service/src/cli/skipReporter.ts @@ -128,7 +128,8 @@ export function reportSkippedTest( const queued: QueuedSkip = { framework, test, result, suiteTitle } // SDK-7493: only the DETACHED caller needs deferring. `immediate` is for callers wdio - // awaits — the hook cascade (afterHook) and the bail cascade (afterTest). Those never had + // awaits — the hook cascade (afterHook) and the bail cascade (afterTest; when the reporter's + // `fail` reported the failure, from service.after() instead, SDK-7843). Those never had // the interleave, because wdio holds the lifecycle open until they resolve, so nothing else // can claim the tracked slot underneath them. Deferring those too would be a behaviour // change for no benefit: their skips would move to end-of-run and their reports would no @@ -158,7 +159,8 @@ export function reportSkippedTest( * suite — report each state-undefined test as skipped, recursing into nested describes. * * Reports IMMEDIATELY (SDK-7493): every caller of this — the failed-hook cascade in - * `afterHook` and the bail cascade in `afterTest` — is awaited by wdio, so these reports + * `afterHook` and the bail cascade in `afterTest` (or in `after()`, for a failure the reporter's + * `fail` reported, SDK-7843) — is awaited by wdio, so these reports * cannot interleave with a live test the way the un-awaited `onTestSkip` path could. They * belong to the hook/test being reported, so they must not slide to end-of-run. */ diff --git a/packages/browserstack-service/src/reporter.ts b/packages/browserstack-service/src/reporter.ts index 68d77738..b2b7234c 100644 --- a/packages/browserstack-service/src/reporter.ts +++ b/packages/browserstack-service/src/reporter.ts @@ -5,6 +5,8 @@ import WDIOReporter from '@wdio/reporter' import type { Options, Frameworks } from '@wdio/types' import { BrowserstackCLI } from './cli/index.js' import { reportSkippedTest, resolveSpecFile } from './cli/skipReporter.js' +import { 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,37 @@ 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' + } + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, fromMochaFail: true }) + } + async onTestEnd(testStats: TestStats) { if (!this.needToSendData('test', 'end')) { return diff --git a/packages/browserstack-service/src/service.ts b/packages/browserstack-service/src/service.ts index 8854e15c..0349751a 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 @@ -616,17 +602,11 @@ export default class BrowserstackService implements Services.ServiceInstance { if (BrowserstackCLI.getInstance().isRunning()) { await BrowserstackCLI.getInstance().getTestFramework()!.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) const uuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) - // snapshot this test's freshly-minted uuid keyed by its identity, so a later - // afterTest can restore it even after a subsequent INIT_TEST has overwritten the single - // mutable tracked-instance slot. Keyed 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 } @@ -653,27 +633,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 } @@ -682,60 +647,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 { @@ -764,6 +675,14 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (skipDrainErr) { BStackLogger.debug(`Exception draining skip reports in after(): ${util.format(skipDrainErr)}`) } + // SDK-7843: a test that timed out is reported when mocha failed it, and that report + // can still be in flight; settle it before the flush below and before EXECUTE/POST, + // where the session status is marked from the results recorded so far + try { + await BrowserstackCLI.getInstance().getTestFramework()?.settleTestFinishes() + } catch (settleErr) { + BStackLogger.debug(`Exception settling test finishes in after(): ${util.format(settleErr)}`) + } // Flush a test-finish event deferred past the after-each hook window — the last // test of the worker has no next-test boundary to trigger the flush. Must run // before worker teardown so the event isn't dropped. @@ -850,12 +769,6 @@ export default class BrowserstackService implements Services.ServiceInstance { } catch (sweepErr) { BStackLogger.debug('Exception in sweepUnfinished during after(): ' + util.format(sweepErr)) } - // The sweep closes the _tests entries, but the CLI uuid snapshots (_cliTestUuids) are - // only drained in afterTest — the callback that never fires for a test the sweep just - // handled (e.g. one that timed out). Clear them here at per-worker teardown so stale - // snapshots cannot leak across the worker. Safe to clear: this runs after the sweep and - // no further afterTest will consume them in this worker. - this._cliTestUuids.clear() // Track Listener cleanup PerformanceTester.start(EVENTS.SDK_LISTENER_WORKER_END) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts new file mode 100644 index 00000000..2db8f605 --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.bailCascade.test.ts @@ -0,0 +1,191 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import * as bstackLogger from '../../src/bstackLogger.js' +import * as util from '../../src/util.js' + +import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramework.js' +import TestFramework from '../../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.js' +import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +describe('mocha bail skip cascade (SDK-7063), run by the CLI framework with the test\'s finish', () => { + let framework: WdioMochaTestFramework + let trackEvent: ReturnType + + // reportSkippedTest de-dupes on `${parent} - ${title}` in a module-scope Set that outlives + // each test, so every case here needs its own titles. + const buildTree = (tag: string) => { + const root: any = { title: '', tests: [], suites: [], parent: undefined } + const suiteA: any = { title: `${tag} Suite A`, tests: [], suites: [], parent: root } + const suiteB: any = { title: `${tag} Suite B`, tests: [], suites: [], parent: root } + root.suites.push(suiteA, suiteB) + + const ran: any = { title: `${tag} A1`, state: 'passed', parent: suiteA, file: '/spec/a.js' } + const failing: any = { title: `${tag} A2`, state: 'failed', parent: suiteA, file: '/spec/a.js' } + const dropped: any = { title: `${tag} A3`, parent: suiteA, file: '/spec/a.js' } + suiteA.tests.push(ran, failing, dropped) + // sibling top-level describe — only reachable because the cascade walks up to root + suiteB.tests.push({ title: `${tag} B1`, parent: suiteB, file: '/spec/a.js' }) + + failing.ctx = { test: { parent: suiteA } } + return { failing, root } + } + + /** beforeTest's events, then afterTest's, as the service sends them. */ + const runTest = async (failing: any, results: Record, bail = true) => { + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail }) + trackEvent.mockClear() + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: results }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: results, suiteTitle: 'suite' }) + } + + // WHICH tests got reported, not just how many events fired — a cascade that swept the wrong + // tests still produces the same call count. Pairs with the count assertions, which catch the + // opposite failure (a test emitted twice). + const skippedTitles = () => [...new Set( + trackEvent.mock.calls + .filter(([, , payload]: any[]) => payload?.result?.skipped === true) + .map(([, , payload]: any[]) => payload.test.title as string) + )].sort() + + beforeEach(() => { + TestFramework.instances.clear() + framework = new WdioMochaTestFramework(['WebdriverIO-mocha'], { 'WebdriverIO-mocha': '9' }, 'bin-session-id') + vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) + vi.spyOn(util, 'getTestTags').mockReturnValue([]) + for (const level of ['info', 'debug', 'error'] as const) { + vi.spyOn(cliLogger, level).mockImplementation(() => {}) + } + vi.spyOn(framework, 'runHooks').mockResolvedValue(undefined) + trackEvent = vi.spyOn(framework, 'trackEvent') + }) + + afterEach(() => { + vi.restoreAllMocks() + TestFramework.instances.clear() + }) + + it('reports un-run tests across sibling describes when mocha bail is on', async () => { + const { failing } = buildTree('bail1') + await runTest(failing, { passed: false }) + + // 2 events close the failing test (LOG_REPORT/POST + TEST/POST), then 4 per skipped test. + // A3 (same describe) and B1 (SIBLING describe) => 2 skipped => 8. + expect(trackEvent).toHaveBeenCalledTimes(2 + 8) + // exactly the un-run tests: A1 already passed and A2 is the failure being reported, + // so sweeping either of them in would be a defect the count alone cannot see + expect(skippedTitles()).toEqual(['bail1 A3', 'bail1 B1']) + }) + + it('does not cascade without mocha bail', async () => { + const { failing } = buildTree('bail2') + await runTest(failing, { passed: false }, false) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade while a wdio spec-file retry is still queued', async () => { + const { failing } = buildTree('bail3') + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 2 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade while a MOCHA-level retry is still queued', async () => { + // wdio's `results.retries` only tracks spec-file retries — @wdio/mocha-framework never + // feeds mochaOpts.retries into it, so it reads {0,0} here and cannot be relied on. + // Without reading mocha's own runnable state the cascade fires on attempt 1 and reports + // tests as skipped that the retry then actually runs. + const { failing } = buildTree('bail5') + failing.ctx.test.currentRetry = () => 0 + failing.ctx.test.retries = () => 1 + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 0 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('cascades once the final mocha retry has been used', async () => { + const { failing } = buildTree('bail6') + failing.ctx.test.currentRetry = () => 1 + failing.ctx.test.retries = () => 1 + await runTest(failing, { passed: false, retries: { attempts: 0, limit: 0 } }) + + expect(trackEvent).toHaveBeenCalledTimes(2 + 8) + expect(skippedTitles()).toEqual(['bail6 A3', 'bail6 B1']) + }) + + it('cascades from the runnable the test started on, not the hook mocha moved on to (SDK-7843)', async () => { + // the final attempt under `retries: 1` times out; mocha moves on to an afterEach hook, + // which inherits the suite's retries, before the finish is reported + const { failing } = buildTree('bail9') + failing.ctx.test.currentRetry = () => 1 + failing.ctx.test.retries = () => 1 + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + failing.ctx.test = { parent: failing.parent, currentRetry: () => 0, retries: () => 1 } + trackEvent.mockClear() + + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.settleTestFinishes() + + expect(skippedTitles()).toEqual(['bail9 A3', 'bail9 B1']) + }) + + it('runs the cascade for a failure reported by mocha\'s `fail` from settle, not under the test\'s after-hooks (SDK-7843)', async () => { + const { failing } = buildTree('bail10') + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: failing }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: failing, suiteTitle: 'suite', bail: true }) + const failedUuid = TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) + trackEvent.mockClear() + + // the reporter's `fail`, which wdio does not await; mocha then runs the test's afterEach + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failing, result: { passed: false }, fromMochaFail: true }) + await framework.trackEvent(TestFrameworkState.AFTER_EACH, HookState.PRE, { test: failing }) + + expect(skippedTitles()).toEqual([]) + expect(TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID)).toBe(failedUuid) + + await framework.settleTestFinishes() + expect(skippedTitles()).toEqual(['bail10 A3', 'bail10 B1']) + }) + + it('does not cascade when the test passed', async () => { + const { failing } = buildTree('bail4') + await runTest(failing, { passed: true }) + + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual([]) + }) + + it('does not cascade when the test was itself skipped', async () => { + // a skipped test does not abort the spec, and the pre-existing skip paths already + // report it — cascading here would double-report the rest of the suite + const { failing } = buildTree('bail7') + await runTest(failing, { passed: false, skipped: true }) + + // A2 is the test being reported and its own result is legitimately `skipped`; what must + // NOT appear is A3/B1, which the cascade would have added. + expect(trackEvent).toHaveBeenCalledTimes(2) + expect(skippedTitles()).toEqual(['bail7 A2']) + }) + + it('never throws out of the finish when mocha state is hostile', async () => { + // afterTest is awaited by wdio; anything escaping this cascade would surface as a + // framework-level error in the user's run + const { failing } = buildTree('bail8') + failing.ctx.test.currentRetry = () => { throw new Error('mocha exploded') } + failing.ctx.test.retries = () => 1 + + await runTest(failing, { passed: false }) + expect(skippedTitles()).toEqual([]) + }) +}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts new file mode 100644 index 00000000..1ee5a019 --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.preTestLog.test.ts @@ -0,0 +1,56 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import * as bstackLogger from '../../src/bstackLogger.js' + +import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramework.js' +import TestFramework from '../../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +describe('SDK-7843 — a log written before the first mocha hook is dropped quietly', () => { + let framework: WdioMochaTestFramework + let errorSpy: ReturnType + + beforeEach(() => { + framework = new WdioMochaTestFramework(['WebdriverIO', 'mocha'], {}, 'bin-session-id') + errorSpy = vi.spyOn(cliLogger, 'error').mockImplementation(() => {}) + vi.spyOn(cliLogger, 'info').mockImplementation(() => {}) + vi.spyOn(cliLogger, 'debug').mockImplementation(() => {}) + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + it('does not log an ERROR for console output from wdio\'s `before` hook', async () => { + // wdio's `before` runs before mocha's `before all`, so no instance is tracked yet. + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue(null as any) + const resolveSpy = vi.spyOn(framework, 'resolveInstance') + + await framework.trackEvent(TestFrameworkState.LOG, HookState.POST, { + logEntry: { kind: 'TEST_LOG', message: '[SelfHealer] Installed', level: 'info', timestamp: new Date().toISOString() } + }) + + expect(errorSpy).not.toHaveBeenCalled() + expect(resolveSpy).not.toHaveBeenCalled() + }) + + it('still resolves the instance for a log once a test or hook is tracked', async () => { + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as any) + const resolveSpy = vi.spyOn(framework, 'resolveInstance').mockReturnValue(null) + + await framework.trackEvent(TestFrameworkState.LOG, HookState.POST, { logEntry: {} }) + + expect(resolveSpy).toHaveBeenCalledOnce() + }) + + it('still reports a missing instance for non-log events', async () => { + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue(null as any) + + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, {}) + + expect(errorSpy).toHaveBeenCalledWith(expect.stringContaining('resolveInstance: unable to resolve/create instance')) + }) +}) diff --git a/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts new file mode 100644 index 00000000..3c675377 --- /dev/null +++ b/packages/browserstack-service/tests/cli/wdioMochaTestFramework.timedOutTest.test.ts @@ -0,0 +1,205 @@ +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import type { Frameworks } from '@wdio/types' +import * as bstackLogger from '../../src/bstackLogger.js' +import * as util from '../../src/util.js' + +import WdioMochaTestFramework from '../../src/cli/frameworks/wdioMochaTestFramework.js' +import TestFramework from '../../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import { TestFrameworkConstants } from '../../src/cli/frameworks/constants/testFrameworkConstants.js' +import type TestFrameworkInstance from '../../src/cli/instances/testFrameworkInstance.js' +import { BStackLogger as cliLogger } from '../../src/cli/cliLogger.js' + +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +/** + * SDK-7843 — when a mocha test hits its timeout, mocha fails it (the reporter's `fail`) while its + * body and wdio's afterTest are still pending, and moves on. These drive the real framework in + * that order and record what the product modules (TestHubModule, AutomateModule) would observe. + */ +describe('WdioMochaTestFramework — a test finish is reported once, against its own test run', () => { + let framework: WdioMochaTestFramework + let finishes: string[] + + const runnable = () => ({ state: undefined as string | undefined, timedOut: false, duration: 0, timeout: () => 10000 }) + const makeTest = (title: string, extra: Record = {}) => + ({ title, parent: 'Suite', file: '/spec.js', body: '', ctx: { test: runnable() }, ...extra }) as unknown as Frameworks.Test + const failed = { passed: false, error: new Error('Timeout of 10000ms exceeded.'), duration: 10001, retries: { attempts: 0, limit: 0 }, exception: '', status: 'failed' } as Frameworks.TestResult + const passed = { passed: true, duration: 40000, retries: { attempts: 0, limit: 0 }, exception: '', status: 'passed' } as Frameworks.TestResult + + const start = async (test: Frameworks.Test) => { + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle: 'Suite' }) + return TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID) as string + } + const afterTest = async (test: Frameworks.Test, result: Frameworks.TestResult) => { + await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, suiteTitle: 'Suite' }) + } + /** What the reporter sends from `fail`; wdio does not await it. */ + const reporterFail = (test: Frameworks.Test, result = failed) => { + void framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result, fromMochaFail: true }) + void framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, fromMochaFail: true }) + } + + beforeEach(() => { + TestFramework.instances.clear() + framework = new WdioMochaTestFramework(['WebdriverIO-mocha'], { 'WebdriverIO-mocha': '9' }, 'bin-session-id') + finishes = [] + vi.spyOn(util, 'getMochaTestHierarchy').mockReturnValue([]) + vi.spyOn(util, 'getTestTags').mockReturnValue([]) + for (const level of ['info', 'debug', 'error'] as const) { + vi.spyOn(cliLogger, level).mockImplementation(() => {}) + } + // record the TEST/POST each product module would observe, with the test run it closes; + // the modules' gRPC sends take real time, so an instant mock would hide a missing wait + vi.spyOn(framework, 'runHooks').mockImplementation(async (instance: TestFrameworkInstance, state: State, hook: State, args: unknown) => { + if (state === TestFrameworkState.TEST && hook === HookState.POST) { + const { test, result } = args as { test: Frameworks.Test, result: Frameworks.TestResult } + const uuid = TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_UUID) + await new Promise((resolve) => setTimeout(resolve, 20)) + finishes.push(`${test.title} ${uuid} passed=${result.passed}`) + } + }) + }) + + afterEach(() => { + vi.restoreAllMocks() + TestFramework.instances.clear() + }) + + it('reports a timed-out test from mocha\'s `fail`, and drops its late afterTest', async () => { + const test = makeTest('times out') + const uuid = await start(test) + + reporterFail(test) + await framework.settleTestFinishes() + expect(finishes).toEqual([`times out ${uuid} passed=false`]) + + // the body finished late and succeeded: wdio's afterTest says passed + await afterTest(test, passed) + expect(finishes).toEqual([`times out ${uuid} passed=false`]) + }) + + it('reports a normal failure from afterTest, and drops the `fail` that follows it', async () => { + const test = makeTest('fails') + const uuid = await start(test) + + await afterTest(test, { ...failed, error: new Error('expected 1 to equal 2') }) + reporterFail(test) + await framework.settleTestFinishes() + + expect(finishes).toEqual([`fails ${uuid} passed=false`]) + }) + + it('closes a late afterTest against its own test run while the next test holds the slot', async () => { + const first = makeTest('times out') + const firstUuid = await start(first) + const next = makeTest('next test') + const nextUuid = await start(next) + + await afterTest(first, failed) + + expect(finishes).toEqual([`times out ${firstUuid} passed=false`]) + // the running test keeps its own test run + expect(TestFramework.getState(TestFramework.getTrackedInstance(), TestFrameworkConstants.KEY_TEST_UUID)).toBe(nextUuid) + }) + + it('without a reporter, keeps mocha\'s failure when the late afterTest says passed', async () => { + const test = makeTest('times out then succeeds') + const uuid = await start(test) + + Object.assign(test.ctx!.test as object, { state: 'failed', timedOut: true, duration: 10001 }) + await afterTest(test, passed) + + expect(finishes).toEqual([`times out then succeeds ${uuid} passed=false`]) + }) + + it('without a reporter, settle finishes a test mocha already failed, from its runnable', async () => { + const timedOut = makeTest('times out unreported') + const timedOutUuid = await start(timedOut) + Object.assign(timedOut.ctx!.test as object, { state: 'failed', timedOut: true, duration: 10001 }) + const running = makeTest('still running') + await start(running) + const loadResult = vi.spyOn(framework, 'loadTestResult') + + await framework.settleTestFinishes() + + expect(finishes).toEqual([`times out unreported ${timedOutUuid} passed=false`]) + expect(loadResult).toHaveBeenCalledWith(expect.anything(), expect.objectContaining({ + result: expect.objectContaining({ error: new Error('Timeout of 10000ms exceeded.') }) + })) + }) + + it('keeps each retried attempt on its own test run', async () => { + const attempt0 = makeTest('flaky', { _currentRetry: 0 }) + const uuid0 = await start(attempt0) + const attempt1 = makeTest('flaky', { _currentRetry: 1 }) + const uuid1 = await start(attempt1) + + // attempt 0's late afterTest, then attempt 1 times out too + await afterTest(attempt0, failed) + reporterFail(makeTest('flaky', { _currentRetry: 1 })) + await framework.settleTestFinishes() + + expect(finishes).toEqual([`flaky ${uuid0} passed=false`, `flaky ${uuid1} passed=false`]) + }) + + // `attemptKey` holds only the immediate parent's title, so these share `valid - works`: + // describe('login', () => describe('valid', () => it('works'))) and the same under 'signup' + it('reports a later test that shares an earlier finished test\'s key', async () => { + const first = makeTest('works', { parent: 'valid' }) + const firstUuid = await start(first) + await afterTest(first, passed) + const second = makeTest('works', { parent: 'valid' }) + const secondUuid = await start(second) + await afterTest(second, failed) + + expect(finishes).toEqual([`works ${firstUuid} passed=true`, `works ${secondUuid} passed=false`]) + }) + + it('closes a late afterTest by the test\'s body when a same-named test has started since', async () => { + // wdio hands beforeTest and afterTest separate copies of the mocha test; both carry its fn + const first = makeTest('works', { parent: 'valid', fn: () => {} }) + const firstUuid = await start(first) + reporterFail(makeTest('works', { parent: 'valid' })) + await framework.settleTestFinishes() + const second = makeTest('works', { parent: 'valid', fn: () => {} }) + const secondUuid = await start(second) + + // the first test's body finishes late (and succeeds) while the second test is running; the + // second then fails on its own + await afterTest({ ...first } as Frameworks.Test, passed) + await afterTest({ ...second } as Frameworks.Test, failed) + + expect(finishes).toEqual([`works ${firstUuid} passed=false`, `works ${secondUuid} passed=false`]) + }) + + it('keeps the reporter\'s TEST/POST on the test its LOG_REPORT resolved, if a same-named test starts in between', async () => { + const first = makeTest('works', { parent: 'valid', fn: () => {} }) + const firstUuid = await start(first) + const failed1 = makeTest('works', { parent: 'valid' }) + // mocha's `fail`: LOG_REPORT resolves now; TEST/POST is sent after it, by when mocha may + // have started the next test + const logReport = framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test: failed1, result: failed, fromMochaFail: true }) + const second = makeTest('works', { parent: 'valid', fn: () => {} }) + const secondUuid = await start(second) + await logReport + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: failed1, result: failed, fromMochaFail: true }) + await afterTest({ ...second } as Frameworks.Test, passed) + + expect(finishes).toEqual([`works ${firstUuid} passed=false`, `works ${secondUuid} passed=true`]) + }) + + it('drops a `fail` for a test that never started (a hook), and still reports afterTest for one it never saw', async () => { + await start(makeTest('runs')) + + reporterFail(makeTest('"before each" hook for runs')) + await framework.settleTestFinishes() + expect(finishes).toEqual([]) + + await afterTest(makeTest('unseen'), passed) + expect(finishes).toHaveLength(1) + }) +}) diff --git a/packages/browserstack-service/tests/reporter.onTestFail.test.ts b/packages/browserstack-service/tests/reporter.onTestFail.test.ts new file mode 100644 index 00000000..9238d90a --- /dev/null +++ b/packages/browserstack-service/tests/reporter.onTestFail.test.ts @@ -0,0 +1,75 @@ +import path from 'node:path' +import { describe, expect, it, vi, afterEach } from 'vitest' + +import TestReporter from '../src/reporter.js' +import { BrowserstackCLI } from '../src/cli/index.js' +import WdioMochaTestFramework from '../src/cli/frameworks/wdioMochaTestFramework.js' +import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' +import { HookState } from '../src/cli/states/hookState.js' +import * as bstackLogger from '../src/bstackLogger.js' + +vi.mock('@wdio/reporter', () => import(path.join(process.cwd(), '__mocks__', '@wdio/reporter'))) +vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +describe('reporter onTestFail — sends mocha\'s failure through the CLI test events (SDK-7843)', () => { + const timeout = new Error('Timeout of 300000ms exceeded. The execution in the test took too long.') + const testStats = { title: 'should navigate via bottom nav', parent: 'Smoke: Home Navigation', error: timeout, _duration: 300004, retries: 0 } + + const makeReporter = (framework: string) => { + const reporter = new TestReporter({}) + ;(reporter as unknown as { _config: unknown })._config = { framework } + return reporter + } + const mockCli = (isRunning: boolean) => { + const trackEvent = vi.fn().mockResolvedValue(undefined) + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => isRunning, getTestFramework: () => ({ trackEvent }) } 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('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 index 828cc0e3..84dea060 100644 --- a/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts +++ b/packages/browserstack-service/tests/service.afterSkipOrdering.test.ts @@ -77,7 +77,6 @@ describe('service.after() — skip drain must precede the deferred-finish flush _hookFailReasons: [], _insightsHandler: undefined, _percyHandler: undefined, - _cliTestUuids: new Map(), saveWorkerData: vi.fn() } } diff --git a/packages/browserstack-service/tests/service.test.ts b/packages/browserstack-service/tests/service.test.ts index aa32efbc..83d003f8 100644 --- a/packages/browserstack-service/tests/service.test.ts +++ b/packages/browserstack-service/tests/service.test.ts @@ -13,6 +13,7 @@ import AutomationFramework from '../src/cli/frameworks/automationFramework.js' import WdioCucumberTestFramework from '../src/cli/frameworks/wdioCucumberTestFramework.js' import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' import { HookState } from '../src/cli/states/hookState.js' +import TestFramework from '../src/cli/frameworks/testFramework.js' import { AutomationFrameworkConstants } from '../src/cli/frameworks/constants/automationFrameworkConstants.js' import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' @@ -2652,157 +2653,43 @@ describe('_isAppAutomate honors skipAppOverride', () => { }) }) -describe('afterTest bail skip cascade (SDK-7063)', () => { +describe('beforeTest passes mocha\'s bail to the CLI framework (SDK-7063)', () => { + // the cascade itself runs in WdioMochaTestFramework (tests/cli/wdioMochaTestFramework.bailCascade.test.ts) let getInstanceSpy: ReturnType - // reportSkippedTest de-dupes on `${parent} - ${title}` in a module-scope Set that outlives - // each test, so every case here needs its own titles. - const buildTree = (tag: string) => { - const root: any = { title: '', tests: [], suites: [], parent: undefined } - const suiteA: any = { title: `${tag} Suite A`, tests: [], suites: [], parent: root } - const suiteB: any = { title: `${tag} Suite B`, tests: [], suites: [], parent: root } - root.suites.push(suiteA, suiteB) - - const ran: any = { title: `${tag} A1`, state: 'passed', parent: suiteA, file: '/spec/a.js' } - const failing: any = { title: `${tag} A2`, state: 'failed', parent: suiteA, file: '/spec/a.js' } - const dropped: any = { title: `${tag} A3`, parent: suiteA, file: '/spec/a.js' } - suiteA.tests.push(ran, failing, dropped) - // sibling top-level describe — only reachable because the cascade walks up to root - suiteB.tests.push({ title: `${tag} B1`, parent: suiteB, file: '/spec/a.js' }) - - failing.ctx = { test: { parent: suiteA } } - return { failing, root } - } - const makeService = (config: Record) => new BrowserstackService( { testObservability: false } as any, [] as any, { user: 'foo', key: 'bar', ...config } as any ) - const runAfterTest = async (svc: BrowserstackService, failing: any, results: Record) => { + const bailSent = async (config: Record) => { const trackEvent = vi.fn().mockResolvedValue(undefined) getInstanceSpy = vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ isRunning: () => true, getTestFramework: () => ({ trackEvent }) } as any) - await svc.afterTest(failing, undefined as never, results as any) - return trackEvent + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as any) + vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid' as any) + await makeService(config).beforeTest({ title: 'test', parent: 'suite' } as any) + const [, , args] = trackEvent.mock.calls.find(([state, hook]: any[]) => state === TestFrameworkState.TEST && hook === HookState.PRE)! + return args.bail } - // WHICH tests got reported, not just how many events fired — a cascade that swept the wrong - // tests still produces the same call count. Pairs with the count assertions, which catch the - // opposite failure (a test emitted twice). - const skippedTitles = (trackEvent: ReturnType) => [...new Set( - trackEvent.mock.calls - .filter(([, , payload]: any[]) => payload?.result?.skipped === true) - .map(([, , payload]: any[]) => payload.test.title as string) - )].sort() - afterEach(() => { getInstanceSpy?.mockRestore() + vi.mocked(TestFramework.getTrackedInstance).mockRestore() + vi.mocked(TestFramework.getState).mockRestore() }) - it('reports un-run tests across sibling describes when mocha bail is on', async () => { - const { failing } = buildTree('bail1') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - - // 2 events close the failing test (LOG_REPORT/POST + TEST/POST), then 4 per skipped test. - // A3 (same describe) and B1 (SIBLING describe) => 2 skipped => 8. - expect(trackEvent).toHaveBeenCalledTimes(2 + 8) - // exactly the un-run tests: A1 already passed and A2 is the failure being reported, - // so sweeping either of them in would be a defect the count alone cannot see - expect(skippedTitles(trackEvent)).toEqual(['bail1 A3', 'bail1 B1']) + it('sends bail when mocha bail is on', async () => { + expect(await bailSent({ framework: 'mocha', mochaOpts: { bail: true } })).toBe(true) }) - it('does not cascade when only wdio-level bail is set', async () => { + it('does not send bail when only wdio-level bail is set', async () => { // wdio's `bail` never halts a spec, so those tests still run — reporting them - // as skipped here would double-report them. - const { failing } = buildTree('bail2') - const svc = makeService({ framework: 'mocha', bail: 1 }) - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade while a wdio spec-file retry is still queued', async () => { - const { failing } = buildTree('bail3') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 2 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade while a MOCHA-level retry is still queued', async () => { - // wdio's `results.retries` only tracks spec-file retries — @wdio/mocha-framework never - // feeds mochaOpts.retries into it, so it reads {0,0} here and cannot be relied on. - // Without reading mocha's own runnable state the cascade fires on attempt 1 and reports - // tests as skipped that the retry then actually runs. - const { failing } = buildTree('bail5') - failing.ctx.test.currentRetry = () => 0 - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true, retries: 1 } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 0 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('cascades once the final mocha retry has been used', async () => { - const { failing } = buildTree('bail6') - failing.ctx.test.currentRetry = () => 1 - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true, retries: 1 } }) - const trackEvent = await runAfterTest(svc, failing, { - passed: false, - retries: { attempts: 0, limit: 0 } - }) - - expect(trackEvent).toHaveBeenCalledTimes(2 + 8) - expect(skippedTitles(trackEvent)).toEqual(['bail6 A3', 'bail6 B1']) - }) - - it('does not cascade when the test passed', async () => { - const { failing } = buildTree('bail4') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: true }) - - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual([]) - }) - - it('does not cascade when the test was itself skipped', async () => { - // a skipped test does not abort the spec, and the pre-existing skip paths already - // report it — cascading here would double-report the rest of the suite - const { failing } = buildTree('bail7') - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - const trackEvent = await runAfterTest(svc, failing, { passed: false, skipped: true }) - - // A2 is the test being reported and its own result is legitimately `skipped`; what must - // NOT appear is A3/B1, which the cascade would have added. - expect(trackEvent).toHaveBeenCalledTimes(2) - expect(skippedTitles(trackEvent)).toEqual(['bail7 A2']) - }) - - it('never throws out of afterTest when mocha state is hostile', async () => { - // afterTest is awaited by wdio; anything escaping this cascade would surface as a - // framework-level error in the user's run - const { failing } = buildTree('bail8') - failing.ctx.test.currentRetry = () => { throw new Error('mocha exploded') } - failing.ctx.test.retries = () => 1 - const svc = makeService({ framework: 'mocha', mochaOpts: { bail: true } }) - - const trackEvent = await runAfterTest(svc, failing, { passed: false }) - expect(skippedTitles(trackEvent)).toEqual([]) + // as skipped would double-report them. + expect(await bailSent({ framework: 'mocha', bail: 1 })).toBe(false) }) }) diff --git a/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts new file mode 100644 index 00000000..789182a2 --- /dev/null +++ b/packages/browserstack-service/tests/service.timedOutTestFinish.test.ts @@ -0,0 +1,81 @@ +import path from 'node:path' +import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest' +import type { Frameworks } from '@wdio/types' + +import BrowserstackService from '../src/service.js' +import { BrowserstackCLI } from '../src/cli/index.js' +import TestFramework from '../src/cli/frameworks/testFramework.js' +import { TestFrameworkState } from '../src/cli/states/testFrameworkState.js' +import { AutomationFrameworkState } from '../src/cli/states/automationFrameworkState.js' +import { HookState } from '../src/cli/states/hookState.js' +import * as bstackLogger from '../src/bstackLogger.js' + +vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) +vi.spyOn(bstackLogger.BStackLogger, 'logToFile').mockImplementation(() => {}) + +/** + * SDK-7843 — with a mocha timeout, mocha fails the test (the reporter sends its finish) while its + * body and wdio's afterTest are still pending; with `bail`, wdio then runs after() before that + * afterTest. after() must let that finish land before 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 + + const makeService = () => new BrowserstackService( + { testObservability: false } as never, + [] as never, + { user: 'foo', key: 'bar', framework: 'mocha', mochaOpts: { bail: true } } as never + ) + + beforeEach(() => { + events = [] + // the reporter's finish is still being sent when after() starts + settle = vi.fn().mockImplementation(async () => { + await new Promise((resolve) => setTimeout(resolve, 30)) + events.push('settleTestFinishes') + }) + trackEvent = vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + events.push(`${String(state)}/${String(hook)}`) + }) + vi.spyOn(BrowserstackCLI, 'getInstance').mockReturnValue({ + isRunning: () => true, + getTestFramework: () => ({ trackEvent, settleTestFinishes: settle }), + getAutomationFramework: () => ({ + trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + events.push(`${String(state)}/${String(hook)}`) + }) + }), + modules: { TestHubModule: { flushPendingTestFinishEvent: vi.fn().mockImplementation(async () => { events.push('flushPendingTestFinishEvent') }) } } + } as never) + vi.spyOn(TestFramework, 'getTrackedInstance').mockReturnValue({} as never) + vi.spyOn(TestFramework, 'getState').mockReturnValue('uuid-1' as never) + }) + + afterEach(() => { + vi.restoreAllMocks() + }) + + it('settles before the deferred-finish flush and before EXECUTE/POST', async () => { + await makeService().after(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') + 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(TestFrameworkState.TEST))).toEqual([ + `${TestFrameworkState.TEST}/${HookState.PRE}`, + `${TestFrameworkState.TEST}/${HookState.POST}` + ]) + }) +})