fix(cli): don't lose a test's finish after browser.reloadSession() inside the test

.changeset/pr-310.md

@@ -0,0 +1,5 @@
+---
+"@wdio/browserstack-service": patch
+---
+
+- Fixed tests that call `browser.reloadSession()` staying "in progress" on Test Reporting & Analytics, and their builds being reported as timed out, when an `afterTest` hook takes a screenshot or logs to the console.

packages/browserstack-service/src/cli/frameworks/testFramework.ts

@@ -112,6 +112,11 @@ export default class TestFramework {
         logger.info(`runHooks: instance=${instance} automationFrameworkState=${testFrameworkState} hookState=${hookState}`)
 
         const hookRegistryKey = CLIUtils.getHookRegistryKey(testFrameworkState, hookState)
+        // Observers run one after another and may await I/O, during which a concurrent trackEvent can
+        // move the shared instance's current state on. Carry the dispatched state so they act on it.
+        if (args && typeof args === 'object') {
+            Object.assign(args, { testFrameworkState, hookState })
+        }
         await eventDispatcher.notifyObserver(hookRegistryKey, args)
     }
 

packages/browserstack-service/src/cli/modules/testHubModule.ts

@@ -81,6 +81,19 @@ export default class TestHubModule extends BaseModule {
         return TestHubModule.MODULE_NAME
     }
 
+    /**
+     * The state this observer call was dispatched for (stamped by TestFramework.runHooks). The
+     * instance's current state is shared by every concurrent trackEvent, so an observer that runs
+     * after an earlier one awaited I/O can find it already moved on, e.g. to LOG by a screenshot
+     * from the user's own afterTest.
+     */
+    private static dispatchedState(args: Record<string, unknown>, instance: TestFrameworkInstance): { testState: State, hookState: State } {
+        return {
+            testState: (args.testFrameworkState as State | undefined) ?? instance.getCurrentTestState(),
+            hookState: (args.hookState as State | undefined) ?? instance.getCurrentHookState()
+        }
+    }
+
     onBeforeTest(args: Record<string, unknown>) {
         this.logger.debug('onBeforeTest: Called after test hook from cli configured module!!!')
         const autoInstance = AutomationFramework.getTrackedInstance() as AutomationFrameworkInstance
@@ -92,8 +105,7 @@ export default class TestHubModule extends BaseModule {
     onAllTestEvents(args: Record<string, unknown>) {
         this.logger.debug('onAllTestEvents: Called after all test events from cli configured module!!!')
         const instance = args.instance as TestFrameworkInstance
-        const testState = instance.getCurrentTestState()
-        const hookState = instance.getCurrentHookState()
+        const { testState, hookState } = TestHubModule.dispatchedState(args, instance)
         const keyTestDeferred = TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_DEFERRED)
 
         // A NEW test is starting (INIT_TEST minted a fresh instance) — the previous test's
@@ -126,7 +138,7 @@ export default class TestHubModule extends BaseModule {
         ) {
             // Create a modified args object with updated test framework state
             instance.setCurrentTestState(TestFrameworkState.TEST)
-            this.onAllTestEvents(args)
+            this.onAllTestEvents({ ...args, testFrameworkState: TestFrameworkState.TEST })
         }
 
         if (testState === TestFrameworkState.TEST || CLIUtils.matchHookRegex(testState.toString().split('.')[1])) {
@@ -206,8 +218,9 @@ export default class TestHubModule extends BaseModule {
             const testFrameworkVersion = testData.get(TestFrameworkConstants.KEY_TEST_FRAMEWORK_VERSION) || ''
             const startedAt = testData.get(TestFrameworkConstants.KEY_TEST_STARTED_AT) || ''
             const endedAt = testData.get(TestFrameworkConstants.KEY_TEST_ENDED_AT) || ''
-            const testFrameworkState = stateOverride?.testFrameworkState || instance.getCurrentTestState().toString().split('.')[1]
-            const testHookState = stateOverride?.testHookState || instance.getCurrentHookState().toString().split('.')[1]
+            const dispatched = TestHubModule.dispatchedState(args, instance)
+            const testFrameworkState = stateOverride?.testFrameworkState || dispatched.testState.toString().split('.')[1]
+            const testHookState = stateOverride?.testHookState || dispatched.hookState.toString().split('.')[1]
 
             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
@@ -264,8 +277,9 @@ export default class TestHubModule extends BaseModule {
             const trackedContext = instance.getContext()
             const testFWName = TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_FRAMEWORK_NAME) as string
             const testFWVersion = TestFramework.getState(instance, TestFrameworkConstants.KEY_TEST_FRAMEWORK_VERSION) as string
-            const testState = instance.getCurrentTestState().toString().split('.')[1]
-            const hookState = instance.getCurrentHookState().toString().split('.')[1]
+            const dispatched = TestHubModule.dispatchedState(args, instance)
+            const testState = dispatched.testState.toString().split('.')[1]
+            const hookState = dispatched.hookState.toString().split('.')[1]
             this.logger.debug('sendTestSessionEvent: setup')
 
             const executionContext = {
@@ -367,8 +381,9 @@ export default class TestHubModule extends BaseModule {
             const testData = instance.getAllData()
             const testFrameworkName = testData.get(TestFrameworkConstants.KEY_TEST_FRAMEWORK_NAME) || ''
             const testFrameworkVersion = testData.get(TestFrameworkConstants.KEY_TEST_FRAMEWORK_VERSION) || ''
-            const testFrameworkState = instance.getCurrentTestState().toString().split('.')[1]
-            const testHookState = instance.getCurrentHookState().toString().split('.')[1]
+            const dispatched = TestHubModule.dispatchedState(args, instance)
+            const testFrameworkState = dispatched.testState.toString().split('.')[1]
+            const testHookState = dispatched.hookState.toString().split('.')[1]
 
             this.logger.debug(`sendLogCreatedEvent testId: testFrameworkState: ${testFrameworkState} testHookState: ${testHookState}`)
             const platformIndex = process.env.WDIO_WORKER_ID ? parseInt(process.env.WDIO_WORKER_ID.split('-')[0]) : 0

packages/browserstack-service/tests/cli/modules/testHubModule.dispatchedState.test.ts

@@ -0,0 +1,124 @@
+import { describe, it, expect, beforeAll, beforeEach, afterEach, vi } from 'vitest'
+import TestHubModule from '../../../src/cli/modules/testHubModule.js'
+import TestFramework from '../../../src/cli/frameworks/testFramework.js'
+import AutomationFramework from '../../../src/cli/frameworks/automationFramework.js'
+import TestFrameworkInstance from '../../../src/cli/instances/testFrameworkInstance.js'
+import TrackedContext from '../../../src/cli/instances/trackedContext.js'
+import { TestFrameworkState } from '../../../src/cli/states/testFrameworkState.js'
+import { HookState } from '../../../src/cli/states/hookState.js'
+import { GrpcClient } from '../../../src/cli/grpcClient.js'
+import { TestFrameworkConstants } from '../../../src/cli/frameworks/constants/testFrameworkConstants.js'
+
+vi.mock('../../../src/cli/grpcClient.js', () => ({
+    GrpcClient: { getInstance: vi.fn() }
+}))
+
+vi.mock('../../../src/cli/frameworks/automationFramework.js', () => ({
+    default: { getTrackedInstance: vi.fn(), getState: vi.fn(), getDriver: vi.fn() }
+}))
+
+vi.mock('../../../src/cli/frameworks/wdioMochaTestFramework.js', () => ({
+    default: { getLogEntries: vi.fn(() => []), clearLogs: vi.fn() }
+}))
+
+vi.mock('../../../src/cli/cliLogger.js', () => ({
+    BStackLogger: { debug: vi.fn(), info: vi.fn(), error: vi.fn(), warn: vi.fn() }
+}))
+
+function makeMochaInstance(uuid: string, testState: State, hookState: State) {
+    const instance = new TestFrameworkInstance(new TrackedContext('ctx', 1, 2, 'test'), ['WebdriverIO-mocha'], {}, testState, hookState)
+    instance.updateMultipleEntries({
+        [TestFrameworkConstants.KEY_TEST_FRAMEWORK_NAME]: 'WebdriverIO-mocha',
+        [TestFrameworkConstants.KEY_TEST_UUID]: uuid,
+        [TestFrameworkConstants.KEY_TEST_RESULT_AT]: '2026-10-26T10:00:00.000Z'
+    })
+    return instance
+}
+
+describe('TestHubModule — acts on the dispatched state, not the shared instance state', () => {
+    const framework = new TestFramework(['WebdriverIO-mocha'], { 'WebdriverIO-mocha': '9.32.0' }, 'bin-session')
+    // Registered ahead of TestHub, like AutomateModule.onAfterTest, which awaits the session-name
+    // PUT when the test body reloaded the session.
+    let sessionNamePut: Promise<void> = Promise.resolve()
+    let testHubModule: TestHubModule
+    let grpc: { testFrameworkEvent: ReturnType<typeof vi.fn>, testSessionEvent: ReturnType<typeof vi.fn>, logCreatedEvent: ReturnType<typeof vi.fn> }
+
+    beforeAll(() => {
+        TestFramework.registerObserver(TestFrameworkState.TEST, HookState.POST, () => sessionNamePut)
+        testHubModule = new TestHubModule({})
+        Object.defineProperty(testHubModule, 'config', { value: { hubUrl: 'https://hub.browserstack.com' }, writable: true })
+    })
+
+    beforeEach(() => {
+        grpc = {
+            testFrameworkEvent: vi.fn().mockResolvedValue({ success: true }),
+            testSessionEvent: vi.fn().mockResolvedValue({ success: true }),
+            logCreatedEvent: vi.fn().mockResolvedValue({ success: true })
+        }
+        vi.mocked(GrpcClient.getInstance).mockReturnValue(grpc as never)
+    })
+
+    afterEach(() => {
+        sessionNamePut = Promise.resolve()
+    })
+
+    it('still sends TEST/POST when a LOG is tracked while an earlier TEST/POST observer is awaiting', async () => {
+        let releasePut!: () => void
+        sessionNamePut = new Promise<void>((resolve) => {
+            releasePut = resolve
+        })
+        const instance = makeMochaInstance('reloaded-test', TestFrameworkState.TEST, HookState.POST)
+
+        const dispatch = framework.runHooks(instance, TestFrameworkState.TEST, HookState.POST, { instance, test: { title: 'reloads the session' } })
+        // the user's afterTest screenshot is tracked on the same instance while the PUT is in flight
+        framework.updateInstanceState(instance, TestFrameworkState.LOG, HookState.POST)
+        releasePut()
+        await dispatch
+        await testHubModule.flushPendingTestFinishEvent()
+
+        expect(grpc.testFrameworkEvent).toHaveBeenCalledTimes(1)
+        expect(grpc.testFrameworkEvent).toHaveBeenCalledWith(
+            expect.objectContaining({ testFrameworkState: 'TEST', testHookState: 'POST', uuid: 'reloaded-test' })
+        )
+    })
+
+    it.each([
+        [TestFrameworkState.TEST, HookState.PRE, 'TEST', 'PRE'],
+        [TestFrameworkState.AFTER_EACH, HookState.POST, 'AFTER_EACH', 'POST']
+    ])('sends %s/%s with its own state after the instance has moved on to LOG', (testState, hookState, wireState, wireHook) => {
+        const instance = makeMochaInstance('moved-on', TestFrameworkState.LOG, HookState.POST)
+
+        testHubModule.onAllTestEvents({ instance, testFrameworkState: testState, hookState })
+
+        expect(grpc.testFrameworkEvent).toHaveBeenCalledTimes(1)
+        expect(grpc.testFrameworkEvent).toHaveBeenCalledWith(
+            expect.objectContaining({ testFrameworkState: wireState, testHookState: wireHook, uuid: 'moved-on' })
+        )
+    })
+
+    it('reports TEST/PRE on the test session event after the instance has moved on to LOG', () => {
+        vi.mocked(AutomationFramework.getTrackedInstance).mockReturnValue({ getRef: () => 'auto-ref', frameworkName: 'webdriverio', frameworkVersion: '9.32.0' } as never)
+        vi.mocked(AutomationFramework.getDriver).mockReturnValue({ capabilities: {} } as never)
+        vi.mocked(AutomationFramework.getState).mockReturnValue('session-id' as never)
+        const instance = makeMochaInstance('moved-on', TestFrameworkState.LOG, HookState.POST)
+
+        testHubModule.onBeforeTest({ instance, testFrameworkState: TestFrameworkState.TEST, hookState: HookState.PRE })
+
+        expect(grpc.testSessionEvent).toHaveBeenCalledWith(
+            expect.objectContaining({ testFrameworkState: 'TEST', testHookState: 'PRE', testUuid: 'moved-on' })
+        )
+    })
+
+    it('turns a LOG_REPORT/POST recovery into exactly one deferred TEST/POST', async () => {
+        const instance = makeMochaInstance('late-result', TestFrameworkState.LOG_REPORT, HookState.POST)
+        instance.updateMultipleEntries({ [TestFrameworkConstants.KEY_TEST_DEFERRED]: true })
+
+        testHubModule.onAllTestEvents({ instance, testFrameworkState: TestFrameworkState.LOG_REPORT, hookState: HookState.POST })
+        await testHubModule.flushPendingTestFinishEvent()
+
+        expect(grpc.testFrameworkEvent).toHaveBeenCalledTimes(1)
+        expect(grpc.testFrameworkEvent).toHaveBeenCalledWith(
+            expect.objectContaining({ testFrameworkState: 'TEST', testHookState: 'POST', uuid: 'late-result' })
+        )
+    })
+})