diff --git a/.changeset/pr-310.md b/.changeset/pr-310.md new file mode 100644 index 00000000..57b713cd --- /dev/null +++ b/.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. diff --git a/packages/browserstack-service/src/cli/frameworks/testFramework.ts b/packages/browserstack-service/src/cli/frameworks/testFramework.ts index 3e9404b2..e0da2b5b 100644 --- a/packages/browserstack-service/src/cli/frameworks/testFramework.ts +++ b/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) } diff --git a/packages/browserstack-service/src/cli/modules/testHubModule.ts b/packages/browserstack-service/src/cli/modules/testHubModule.ts index 5026bdaa..adb02391 100644 --- a/packages/browserstack-service/src/cli/modules/testHubModule.ts +++ b/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, 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) { 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) { 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 diff --git a/packages/browserstack-service/tests/cli/modules/testHubModule.dispatchedState.test.ts b/packages/browserstack-service/tests/cli/modules/testHubModule.dispatchedState.test.ts new file mode 100644 index 00000000..ba639811 --- /dev/null +++ b/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 = Promise.resolve() + let testHubModule: TestHubModule + let grpc: { testFrameworkEvent: ReturnType, testSessionEvent: ReturnType, logCreatedEvent: ReturnType } + + 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((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' }) + ) + }) +})