diff --git a/.changeset/pr-194.md b/.changeset/pr-194.md new file mode 100644 index 0000000..aa2973a --- /dev/null +++ b/.changeset/pr-194.md @@ -0,0 +1,5 @@ +--- +"@wdio/browserstack-service": patch +--- + +- Fixed a skipped test staying stuck on "In Progress" in Test Hub when it sits between two running tests — for example a `it.skip()` in the middle of a spec. Completes the fix shipped in 9.35.3, which only covered skips at the end of a spec. Skipped tests are now reported when the run finishes, so they appear grouped at the end of the build rather than in source order. diff --git a/packages/browserstack-service/src/cli/modules/testHubModule.ts b/packages/browserstack-service/src/cli/modules/testHubModule.ts index 859b6da..5026bda 100644 --- a/packages/browserstack-service/src/cli/modules/testHubModule.ts +++ b/packages/browserstack-service/src/cli/modules/testHubModule.ts @@ -38,8 +38,23 @@ export default class TestHubModule extends BaseModule { * slot with a fresh instance for the next test — so it stays valid across tests. * Flushed at the next test's first event (INIT_TEST / TEST PRE) or, for the worker's * last test, from service.after() via flushPendingTestFinishEvent(). + * + * SDK-7493: keyed by test uuid, NOT a single slot. wdio does not await `onTestSkip`, so a + * skip report runs detached and can interleave with a live test — its events land between + * the live test's own, on the same per-worker tracked-instance context. With one slot the + * second stash silently REPLACED the first (the old guard only flushed when the instance + * OBJECT differed, and an interleave can present the same object), so one test's + * TestRunFinished was never sent and TRA left it rendering "In Progress" until the ~60-min + * idle reap. A map cannot evict: every deferred finish is delivered, each under its own uuid. + * + * NOTE ON REDUNDANCY: SDK-7493's queue-and-drain (skipReporter) already stops a skip report + * running while a test is in flight, so on the normal path that collision can no longer be + * triggered and this map is not the primary fix. It is retained deliberately as + * defence-in-depth for a reporting path with a real incident history (SDK-7265, SDK-7493, + * ~60-min reaps): if any future caller reintroduces an interleave, the worst case degrades + * to a late send rather than a silently lost TestRunFinished. */ - private pendingTestFinish: { args: Record } | null = null + private pendingTestFinishes: Map, uuid: string }> = new Map() /** * Create a new TestHubModule @@ -84,7 +99,7 @@ export default class TestHubModule extends BaseModule { // A NEW test is starting (INIT_TEST minted a fresh instance) — the previous test's // after-each hook window is definitively over, so flush its deferred finish first // (payload build is synchronous, so gRPC send order is preserved). - if (this.pendingTestFinish && (testState === TestFrameworkState.INIT_TEST || (testState === TestFrameworkState.TEST && hookState === HookState.PRE))) { + if (this.pendingTestFinishes.size > 0 && (testState === TestFrameworkState.INIT_TEST || (testState === TestFrameworkState.TEST && hookState === HookState.PRE))) { this.flushPendingTestFinishEvent() } if (testState === TestFrameworkState.LOG) { @@ -119,13 +134,16 @@ export default class TestHubModule extends BaseModule { if (testState === TestFrameworkState.TEST && hookState === HookState.POST && frameworkName.toLowerCase().includes('mocha')) { // Defer the TestRunFinished send past the Mocha after-each hook window so // custom tags set in `afterEach` still make the payload (see field docs). - // If a previous finish is somehow still pending for a DIFFERENT test, flush - // it first; a re-stash for the same instance just replaces the stash. - if (this.pendingTestFinish && (this.pendingTestFinish.args.instance as TestFrameworkInstance) !== instance) { - this.flushPendingTestFinishEvent() - } - this.pendingTestFinish = { args } - this.logger.debug('onAllTestEvents: deferred TEST/POST send past the after-each hook window') + // SDK-7493: key the stash by the test's uuid, captured NOW. Two different tests + // can present the same tracked instance when a detached skip report interleaves + // with a live test, so keying on the instance object silently dropped one of the + // two finishes. Re-stashing the SAME uuid (e.g. the LOG_REPORT/POST recovery + // re-entry below) correctly replaces only that test's own entry. + const deferUuid = String( + TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_UUID) || instance.getRef() + ) + this.pendingTestFinishes.set(deferUuid, { args, uuid: deferUuid }) + this.logger.debug(`onAllTestEvents: deferred TEST/POST send past the after-each hook window (uuid=${deferUuid}, pending=${this.pendingTestFinishes.size})`) } else { this.sendTestFrameworkEvent(args) } @@ -140,34 +158,45 @@ export default class TestHubModule extends BaseModule { * next test's boundary and from service.after() at worker end. */ flushPendingTestFinishEvent(): Promise | undefined { - if (!this.pendingTestFinish) { + if (this.pendingTestFinishes.size === 0) { return undefined } - const { args } = this.pendingTestFinish - this.pendingTestFinish = null - this.logger.debug('flushPendingTestFinishEvent: sending deferred TEST/POST event') + // Drain every pending finish, not just the newest. Take and clear the whole batch up + // front so a concurrent stash (the detached skip chain) starts a fresh entry rather + // than being swallowed by this in-flight drain. + const batch = [...this.pendingTestFinishes.values()] + this.pendingTestFinishes.clear() + this.logger.debug(`flushPendingTestFinishEvent: sending ${batch.length} deferred TEST/POST event(s)`) + // SDK-7265: this is the only send of a mocha test's TestRunFinished, and the worker's last // test relies on this single flush from service.after(). A dropped send orphans the test → // Test Hub reaps it at its ~60-min idle timeout → the passing build is stamped `timeout`. - // Retry with backoff. `args` is captured locally and the shared slot is only cleared (never - // written back), so concurrent flushes can't clobber one another. + // Retry with backoff. Each entry is captured locally, so concurrent flushes can't clobber + // one another. const maxAttempts = 3 - const attempt = (n: number): Promise => - this.sendTestFrameworkEvent(args, { testFrameworkState: 'TEST', testHookState: 'POST' }).then((sent) => { - if (sent) { - return - } - this.logger.debug(`flushPendingTestFinishEvent: attempt ${n}/${maxAttempts} failed`) - if (n >= maxAttempts) { - this.logger.error('flushPendingTestFinishEvent: deferred TEST/POST send failed after all retries') - return - } - return new Promise((resolve) => setTimeout(resolve, 200 * n)).then(() => attempt(n + 1)) - }) - return attempt(1) + const sendOne = ({ args, uuid }: { args: Record, uuid: string }): Promise => { + // SDK-7493: pin the uuid captured at DEFER time. The payload is otherwise serialized + // from the instance's live data at send time, and an interleaved skip report can have + // rewritten the uuid on that instance since — which would close the wrong test_run and + // leave this one open forever. + const attempt = (n: number): Promise => + this.sendTestFrameworkEvent(args, { testFrameworkState: 'TEST', testHookState: 'POST', uuid }).then((sent) => { + if (sent) { + return + } + this.logger.debug(`flushPendingTestFinishEvent: uuid=${uuid} attempt ${n}/${maxAttempts} failed`) + if (n >= maxAttempts) { + this.logger.error(`flushPendingTestFinishEvent: deferred TEST/POST send failed after all retries (uuid=${uuid})`) + return + } + return new Promise((resolve) => setTimeout(resolve, 200 * n)).then(() => attempt(n + 1)) + }) + return attempt(1) + } + return Promise.all(batch.map(sendOne)).then(() => undefined) } - async sendTestFrameworkEvent(args: Record, stateOverride?: { testFrameworkState: string, testHookState: string }): Promise { + async sendTestFrameworkEvent(args: Record, stateOverride?: { testFrameworkState: string, testHookState: string, uuid?: string }): Promise { try { const testArgs = args as { test: Frameworks.Test, instance: TestFrameworkInstance } const instance = testArgs.instance as TestFrameworkInstance @@ -182,11 +211,24 @@ export default class TestHubModule extends BaseModule { this.logger.debug(`sendTestFrameworkEvent for testState: ${testFrameworkState} hookState: ${testHookState}`) const platformIndex = process.env.WDIO_WORKER_ID ? parseInt(process.env.WDIO_WORKER_ID.split('-')[0]) : 0 - const uuid = TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_UUID) || instance.getRef() + // SDK-7493: a deferred flush pins the uuid captured when the finish was stashed; + // reading it live here can pick up another test's uuid if an interleaved skip + // report rewrote it on this instance in the meantime. + const uuid = stateOverride?.uuid || TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_UUID) || instance.getRef() // Nested values such as test_hooks_started/test_hooks_finished are JS Maps, which // JSON.stringify would serialise to `{}` and strip the hook data. Convert any Map to // a plain object so the binary receives populated hook maps. - const eventJson = Buffer.from(JSON.stringify(Object.fromEntries(testData), (_key, value) => value instanceof Map ? Object.fromEntries(value) : value)) + // SDK-7493: the pinned uuid must go INSIDE event_json too, not just the top-level + // field. The binary routes a mocha test_run on the uuid it parses out of this blob — + // `webdriverio/index.js` does `const event = JSON.parse(eventJson)` and the mocha + // handler builds the test run with `uuid: event.test_uuid` — so a stale `test_uuid` + // here would close the wrong run and leave the deferred one open, which is the very + // failure the pin exists to prevent. Overriding a copy keeps the instance untouched. + const eventData = Object.fromEntries(testData) + if (stateOverride?.uuid) { + eventData[TestFrameworkConstants.KEY_TEST_UUID] = stateOverride.uuid + } + const eventJson = Buffer.from(JSON.stringify(eventData, (_key, value) => value instanceof Map ? Object.fromEntries(value) : value)) const executionContext = { hash: trackedContext.getId(), threadId: trackedContext.getThreadId().toString(), processId: trackedContext.getProcessId().toString() } const payload: Omit = { platformIndex, diff --git a/packages/browserstack-service/src/cli/skipReporter.ts b/packages/browserstack-service/src/cli/skipReporter.ts index 2a7bd0c..4fff79d 100644 --- a/packages/browserstack-service/src/cli/skipReporter.ts +++ b/packages/browserstack-service/src/cli/skipReporter.ts @@ -32,6 +32,61 @@ const reportedSkips = new Set() // tracker's single mutable per-worker instance — serialize every report through one chain let reportChain: Promise = Promise.resolve() +/** + * SDK-7493: skip reports are QUEUED here and only emitted from drainSkipReports(), never at + * the moment onTestSkip fires. + * + * wdio does not await onTestSkip, so emitting inline let a skip's events interleave with a + * live test's. Both share one per-worker tracked-instance slot, so the skip's INIT_TEST + * repointed that slot mid-test; the live test's afterTest then restored ITS uuid onto the + * skip's instance (service.ts `_cliTestUuids`), and from there the two tests' TEST/POSTs + * collapsed onto one uuid — one TestRunFinished was lost (test stuck "In Progress" until the + * ~60-min reap) and the survivor carried the wrong result. Deferring to the drain removes the + * interleave entirely: no test is in flight there, so each skip gets its own instance and uuid. + */ +interface QueuedSkip { + framework: TestFramework + test: Frameworks.Test + result: Frameworks.TestResult + suiteTitle?: string +} +const queuedSkips: QueuedSkip[] = [] + +/** + * Emit one skip's full event sequence, in order. + * + * Every step is attempted even if an earlier one rejects. TEST/POST is what ultimately + * produces the TestRunFinished, and abandoning the sequence on an earlier failure is the + * exact outcome this ticket exists to prevent: a test that is started and never finished + * sits "In Progress" until Test Hub's ~60-min idle reap. A partial report — worse ordering, + * a missing log payload — is strictly better than an unterminated test run. + * + * The first error is retained and rethrown so the caller still logs a real failure rather + * than silently reporting success. + */ +async function emitSkipReport({ framework, test, result, suiteTitle }: QueuedSkip): Promise { + // LOG_REPORT/POST is what loads the result into the instance (loadTestResult is + // gated on it, not on TEST/POST) — same sequence afterTest uses + const steps: Array<[State, State, Record]> = [ + [TestFrameworkState.INIT_TEST, HookState.PRE, { test }], + [TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }], + [TestFrameworkState.LOG_REPORT, HookState.POST, { test, result }], + [TestFrameworkState.TEST, HookState.POST, { test, result, suiteTitle }], + ] + + let firstError: unknown + for (const [state, hook, args] of steps) { + try { + await framework.trackEvent(state, hook, args) + } catch (err: unknown) { + firstError ??= err + } + } + if (firstError !== undefined) { + throw firstError + } +} + export function markTestStarted(identifier: string) { startedTests.add(identifier) } @@ -42,25 +97,58 @@ export function markTestStarted(identifier: string) { // so the chain completes while the session is still open. (Hook-skip cascades go via // reportSuiteSkipped inside afterHook, which is already awaited, so they were unaffected.) export function drainSkipReports(): Promise { + // Emit everything queued so far, strictly one at a time. Drains until empty rather than + // snapshotting: emitting a skip can enqueue nothing today, but draining a growing queue is + // the safe shape. Runs from service.after(), where no test is in flight. + reportChain = reportChain.then(async () => { + while (queuedSkips.length > 0) { + const queued = queuedSkips.shift()! + try { + await emitSkipReport(queued) + } catch (err: unknown) { + BStackLogger.debug(`Failed reporting skipped test '${queued.test.title}': ${err}`) + } + } + }) return reportChain } -export function reportSkippedTest(framework: TestFramework, identifier: string, test: Frameworks.Test, suiteTitle?: string): Promise { +export function reportSkippedTest( + framework: TestFramework, + identifier: string, + test: Frameworks.Test, + suiteTitle?: string, + options?: { immediate?: boolean } +): Promise { if (startedTests.has(identifier) || reportedSkips.has(identifier)) { return reportChain } reportedSkips.add(identifier) const result = { passed: false, skipped: true } as Frameworks.TestResult - reportChain = reportChain.then(async () => { - // LOG_REPORT/POST is what loads the result into the instance (loadTestResult is - // gated on it, not on TEST/POST) — same sequence afterTest uses - await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test }) - await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test, suiteTitle }) - await framework.trackEvent(TestFrameworkState.LOG_REPORT, HookState.POST, { test, result }) - await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test, result, suiteTitle }) - }).catch((err: unknown) => { - BStackLogger.debug(`Failed reporting skipped test '${identifier}': ${err}`) - }) + 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 + // 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 + } + + // The un-awaited `onTestSkip` path: queue it — see the QueuedSkip docs above. Emitting here + // would interleave this skip's events with whatever test is currently running. + // + // Tradeoff: delivery now depends on service.after() running. If the worker dies before it + // (SIGKILL, OOM, a teardown error that skips after()), queued skips are dropped with no + // send attempted, where the old inline path would at least have tried. Accepted because + // the inline path is the bug being fixed, and an aborted worker already leaves its + // in-progress test runs to Test Hub's idle reap regardless. + queuedSkips.push(queued) return reportChain } @@ -68,6 +156,11 @@ export function reportSkippedTest(framework: TestFramework, identifier: string, * Port of the legacy insights-handler skip propagation: when a BEFORE_ALL/BEFORE_EACH/ * AFTER_EACH hook fails (or skips), mocha silently drops the remaining tests in the * 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 + * 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. */ export async function reportSuiteSkipped(framework: TestFramework, suite: { tests?: unknown[], suites?: unknown[] }): Promise { for (const t of (suite.tests || []) as MochaRuntimeTest[]) { @@ -86,7 +179,7 @@ export async function reportSuiteSkipped(framework: TestFramework, suite: { test file: t.file, ctx: { test: { parent: t.parent } } } as unknown as Frameworks.Test - await reportSkippedTest(framework, identifier, synthetic, parentTitle) + await reportSkippedTest(framework, identifier, synthetic, parentTitle, { immediate: true }) } for (const sub of (suite.suites || []) as { tests?: unknown[], suites?: unknown[] }[]) { await reportSuiteSkipped(framework, sub) diff --git a/packages/browserstack-service/tests/cli/modules/testHubModule.deferredFinish.test.ts b/packages/browserstack-service/tests/cli/modules/testHubModule.deferredFinish.test.ts index 0a8a551..3b167c9 100644 --- a/packages/browserstack-service/tests/cli/modules/testHubModule.deferredFinish.test.ts +++ b/packages/browserstack-service/tests/cli/modules/testHubModule.deferredFinish.test.ts @@ -149,9 +149,11 @@ describe('TestHubModule — deferred last-test-finish delivery (SDK-7265)', () = for (const call of mockGrpcClient.testFrameworkEvent.mock.calls) { expect(call[0]).toMatchObject({ uuid: 'exhaust' }) } - // An exhausted event must NOT be re-stashed into the shared slot — re-stashing races the - // fire-and-forget flush call sites and can drop a newer test's finish (SDK-7265 review #1). - expect((testHubModule as unknown as { pendingTestFinish: unknown }).pendingTestFinish).toBeNull() + // An exhausted event must NOT be re-stashed — re-stashing races the fire-and-forget + // flush call sites and can drop a newer test's finish (SDK-7265 review #1). + // SDK-7493: the single `pendingTestFinish` slot is now a uuid-keyed map, so "not + // re-stashed" means the map is empty rather than the slot being null. + expect((testHubModule as unknown as { pendingTestFinishes: Map }).pendingTestFinishes.size).toBe(0) expect(testHubModule.logger.error).toHaveBeenCalledWith( expect.stringContaining('failed after all retries') ) @@ -192,4 +194,70 @@ describe('TestHubModule — deferred last-test-finish delivery (SDK-7265)', () = expect(mockGrpcClient.testFrameworkEvent).toHaveBeenCalledTimes(1) }) + + // SDK-7493 — the two hardenings that replaced the single `pendingTestFinish` slot. + // The queue-and-drain in skipReporter is the primary fix; these guard the deferral itself + // so a future interleave degrades into a late send rather than a silently lost finish. + + it('two finishes stashed against the SAME instance under different uuids both survive', async () => { + // The exact shape the single slot lost: an interleave presents one tracked instance + // whose uuid has moved on, so the old `instance !== instance` guard never fired and the + // second stash silently evicted the first. + const shared = makeMochaTestInstance('first') + testHubModule.onAllTestEvents({ instance: shared, test: { title: 'first' } as Frameworks.Test }) + + // Same object, uuid rewritten — as an interleaved skip report would leave it. + shared.__uuid = 'second' + testHubModule.onAllTestEvents({ instance: shared, test: { title: 'second' } as Frameworks.Test }) + + expect((testHubModule as unknown as { pendingTestFinishes: Map }).pendingTestFinishes.size).toBe(2) + + await testHubModule.flushPendingTestFinishEvent() + + const sent = mockGrpcClient.testFrameworkEvent.mock.calls.map((c: unknown[]) => (c[0] as { uuid: string }).uuid) + expect(sent).toHaveLength(2) + expect(new Set(sent)).toEqual(new Set(['first', 'second'])) + }) + + it('flushes the uuid captured at DEFER time, not the instance uuid at send time', async () => { + const inst = makeMochaTestInstance('at-defer') + testHubModule.onAllTestEvents({ instance: inst, test: { title: 't' } as Frameworks.Test }) + + // The instance's live uuid is rewritten before the flush runs. Reading it here would + // close the wrong test_run and leave this one open until Test Hub's idle reap — the + // binary keys closure on the request's top-level `uuid` field. + inst.__uuid = 'rewritten-after-defer' + await testHubModule.flushPendingTestFinishEvent() + + expect(mockGrpcClient.testFrameworkEvent).toHaveBeenCalledTimes(1) + expect(mockGrpcClient.testFrameworkEvent.mock.calls[0][0]).toMatchObject({ uuid: 'at-defer' }) + }) + + it('pins the uuid INSIDE event_json too — the binary routes on that, not the top-level field', async () => { + // `webdriverio/index.js` does `const event = JSON.parse(eventJson)` and the mocha + // handler builds the run with `uuid: event.test_uuid`. A stale test_uuid in the blob + // closes the wrong run, so pinning only the top-level field is not enough. + const inst = makeMochaTestInstance('pinned') + testHubModule.onAllTestEvents({ instance: inst, test: { title: 't' } as Frameworks.Test }) + + inst.__uuid = 'rewritten-after-defer' + await testHubModule.flushPendingTestFinishEvent() + + const payload = mockGrpcClient.testFrameworkEvent.mock.calls[0][0] as { uuid: string, eventJson: Buffer } + expect(payload.uuid).toBe('pinned') + expect(JSON.parse(payload.eventJson.toString()).test_uuid).toBe('pinned') + }) + + it('re-stashing the SAME uuid replaces rather than duplicating (LOG_REPORT re-entry)', async () => { + // onAllTestEvents re-enters for one test via the LOG_REPORT/POST recovery path; that + // must not send the same finish twice. + const inst = makeMochaTestInstance('same') + testHubModule.onAllTestEvents({ instance: inst, test: { title: 'same' } as Frameworks.Test }) + testHubModule.onAllTestEvents({ instance: inst, test: { title: 'same' } as Frameworks.Test }) + + expect((testHubModule as unknown as { pendingTestFinishes: Map }).pendingTestFinishes.size).toBe(1) + + await testHubModule.flushPendingTestFinishEvent() + expect(mockGrpcClient.testFrameworkEvent).toHaveBeenCalledTimes(1) + }) }) diff --git a/packages/browserstack-service/tests/cli/skipReporter.midRunInterleave.test.ts b/packages/browserstack-service/tests/cli/skipReporter.midRunInterleave.test.ts new file mode 100644 index 0000000..e8af8ff --- /dev/null +++ b/packages/browserstack-service/tests/cli/skipReporter.midRunInterleave.test.ts @@ -0,0 +1,135 @@ +import path from 'node:path' + +import { describe, expect, it, vi, beforeEach } from 'vitest' +import type { Frameworks } from '@wdio/types' + +vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) + +import { drainSkipReports, reportSkippedTest } from '../../src/cli/skipReporter.js' +import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' +import { HookState } from '../../src/cli/states/hookState.js' +import type TestFramework from '../../src/cli/frameworks/testFramework.js' + +const makeTest = (title: string, parent = 'Test A') => ({ title, parent }) as unknown as Frameworks.Test + +/** + * SDK-7493 — a skipped test in the MIDDLE of a spec was left rendering "In Progress". + * + * Customer shape (SDK-7493 comment 2359027), still failing on 9.35.3: + * + * it('TC-5944 Test 1') // runs + * it.skip('TC-5947 Test 2') // skipped, in the middle + * it('TC-5948 Test 3') // runs + * + * wdio does not await `onTestSkip`, so emitting the skip's events inline let them interleave + * with Test 3's. Both tests resolve through ONE per-worker tracked-instance slot, so the + * skip's INIT_TEST repointed that slot mid-test; Test 3's afterTest then restored ITS uuid + * onto the skip's instance (`service.ts` `_cliTestUuids`), and from there both tests' TEST/POSTs + * collapsed onto a single uuid — Test 2's TestRunFinished was never sent (stuck "In Progress" + * until Test Hub's ~60-min idle reap) and Test 3 was closed with the skip's result. + * + * The fix is that a skip report never fires while a test is in flight: it is queued and emitted + * only from `drainSkipReports()`, which `service.after()` calls with no test running. + */ +describe('skipReporter — a skip must not interleave with a running test (SDK-7493)', () => { + beforeEach(() => { + vi.clearAllMocks() + }) + + it('emits nothing at report time — the events are queued, not fired inline', async () => { + const framework = { trackEvent: vi.fn().mockResolvedValue(undefined) } as unknown as TestFramework + + await reportSkippedTest(framework, 'Test A - TC-5947 Test 2', makeTest('TC-5947 Test 2'), 'Test A') + + // The whole defect was these landing mid-test. Nothing may reach the tracker yet. + expect(framework.trackEvent).not.toHaveBeenCalled() + + await drainSkipReports() + expect(framework.trackEvent).toHaveBeenCalledTimes(4) + }) + + it('does not touch the tracker while a test is mid-flight, and still delivers on drain', async () => { + const events: string[] = [] + const framework = { + trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown, args: { test?: { title: string } }) => { + const shortState = String(state).split('.')[1] + const shortHook = String(hook).split('.')[1] + events.push(`${args?.test?.title ?? '?'}:${shortState}/${shortHook}`) + }) + } as unknown as TestFramework + + // Test 3 is "running": its INIT_TEST/TEST-PRE have fired and its afterTest has not yet. + await framework.trackEvent(TestFrameworkState.INIT_TEST, HookState.PRE, { test: makeTest('TC-5948 Test 3') }) + await framework.trackEvent(TestFrameworkState.TEST, HookState.PRE, { test: makeTest('TC-5948 Test 3') }) + + // wdio fires onTestSkip for the middle test right here, un-awaited. + void reportSkippedTest(framework, 'Test A - TC-5947 Test 2 (interleave)', makeTest('TC-5947 Test 2'), 'Test A') + await Promise.resolve() + + // Test 3 finishes. Nothing from the skip may appear between its PRE and its POST — + // that interleave is what hijacked the tracked slot and lost a TestRunFinished. + await framework.trackEvent(TestFrameworkState.TEST, HookState.POST, { test: makeTest('TC-5948 Test 3') }) + + expect(events).toEqual([ + 'TC-5948 Test 3:INIT_TEST/PRE', + 'TC-5948 Test 3:TEST/PRE', + 'TC-5948 Test 3:TEST/POST', + ]) + + // service.after() drains — now, with no test in flight, the skip reports itself in full. + await drainSkipReports() + expect(events.slice(3)).toEqual([ + 'TC-5947 Test 2:INIT_TEST/PRE', + 'TC-5947 Test 2:TEST/PRE', + 'TC-5947 Test 2:LOG_REPORT/POST', + 'TC-5947 Test 2:TEST/POST', + ]) + }) + + it('still attempts TEST/POST when an earlier lifecycle event rejects', async () => { + // TEST/POST is what produces the TestRunFinished. Bailing out of the sequence on an + // earlier failure would leave the test started-but-never-finished — i.e. "In Progress" + // until the ~60-min reap, which is the whole defect this ticket is about. + const seen: string[] = [] + const framework = { + trackEvent: vi.fn().mockImplementation(async (state: unknown, hook: unknown) => { + const name = `${String(state).split('.')[1]}/${String(hook).split('.')[1]}` + seen.push(name) + if (name === 'TEST/PRE') { + throw new Error('transport blip on TEST/PRE') + } + }) + } as unknown as TestFramework + + void reportSkippedTest(framework, 'Test A - rejects midway', makeTest('rejects midway'), 'Test A') + await drainSkipReports() + + // every step attempted, in order, despite the rejection in the middle + expect(seen).toEqual([ + 'INIT_TEST/PRE', + 'TEST/PRE', + 'LOG_REPORT/POST', + 'TEST/POST', + ]) + }) + + it('delivers every queued skip — none is dropped when several queue up', async () => { + const framework = { trackEvent: vi.fn().mockResolvedValue(undefined) } as unknown as TestFramework + + for (const title of ['skip one', 'skip two', 'skip three']) { + void reportSkippedTest(framework, `Test A - ${title}`, makeTest(title), 'Test A') + } + await drainSkipReports() + + const started = vi.mocked(framework.trackEvent).mock.calls + .filter(([state]) => state === TestFrameworkState.INIT_TEST) + .map(([, , args]) => (args as { test: { title: string } }).test.title) + const finished = vi.mocked(framework.trackEvent).mock.calls + .filter(([state, hook]) => state === TestFrameworkState.TEST && hook === HookState.POST) + .map(([, , args]) => (args as { test: { title: string } }).test.title) + + // A TestRunStarted with no TestRunFinished is exactly what leaves a test "In Progress". + expect(started).toEqual(['skip one', 'skip two', 'skip three']) + expect(finished).toEqual(started) + }) +}) diff --git a/packages/browserstack-service/tests/cli/skipReporter.test.ts b/packages/browserstack-service/tests/cli/skipReporter.test.ts index 12aea7e..6846e98 100644 --- a/packages/browserstack-service/tests/cli/skipReporter.test.ts +++ b/packages/browserstack-service/tests/cli/skipReporter.test.ts @@ -5,7 +5,7 @@ import type { Frameworks } from '@wdio/types' vi.mock('@wdio/logger', () => import(path.join(process.cwd(), '__mocks__', '@wdio/logger'))) -import { markTestStarted, reportSkippedTest, reportSuiteSkipped, resolveSpecFile } from '../../src/cli/skipReporter.js' +import { drainSkipReports, markTestStarted, reportSkippedTest, reportSuiteSkipped, resolveSpecFile } from '../../src/cli/skipReporter.js' import { TestFrameworkState } from '../../src/cli/states/testFrameworkState.js' import { HookState } from '../../src/cli/states/hookState.js' import type TestFramework from '../../src/cli/frameworks/testFramework.js' @@ -22,6 +22,8 @@ describe('skipReporter', () => { it('reports a skipped test through the INIT_TEST/TEST/LOG_REPORT sequence', async () => { const framework = makeFramework() await reportSkippedTest(framework, 'suite - reports once', makeTest('reports once'), 'suite') + // SDK-7493: reportSkippedTest only QUEUES; drainSkipReports emits. + await drainSkipReports() const calls = vi.mocked(framework.trackEvent).mock.calls expect(calls.map(([state, hook]) => [state, hook])).toEqual([ @@ -37,6 +39,7 @@ describe('skipReporter', () => { const framework = makeFramework() await reportSkippedTest(framework, 'suite - dedup', makeTest('dedup'), 'suite') await reportSkippedTest(framework, 'suite - dedup', makeTest('dedup'), 'suite') + await drainSkipReports() expect(framework.trackEvent).toHaveBeenCalledTimes(4) }) @@ -44,6 +47,7 @@ describe('skipReporter', () => { const framework = makeFramework() markTestStarted('suite - runtime skip') await reportSkippedTest(framework, 'suite - runtime skip', makeTest('runtime skip'), 'suite') + await drainSkipReports() expect(framework.trackEvent).not.toHaveBeenCalled() }) @@ -60,6 +64,7 @@ describe('skipReporter', () => { reportSkippedTest(framework, 'suite - first', makeTest('first'), 'suite'), reportSkippedTest(framework, 'suite - second', makeTest('second'), 'suite'), ]) + await drainSkipReports() expect(order).toEqual(['first', 'first', 'first', 'first', 'second', 'second', 'second', 'second']) }) @@ -77,6 +82,7 @@ describe('skipReporter', () => { }], } await reportSuiteSkipped(framework, suite) + await drainSkipReports() // 2 undetermined tests x 4 tracker events expect(framework.trackEvent).toHaveBeenCalledTimes(8) const reported = vi.mocked(framework.trackEvent).mock.calls