From 0ca31da829f481ff0099af910c701a740dd48244 Mon Sep 17 00:00:00 2001 From: xxshubhamxx Date: Wed, 10 Jun 2026 01:29:24 +0530 Subject: [PATCH 1/5] fix(observability): correlate cucumber finishes by unique attempt id and sweep open entities at teardown Key the cucumber _tests map by the unique testCaseStartedId instead of the non-unique testCaseId, so reruns/retries/parallel-interleaved attempts of the same scenario no longer clobber each other and every attempt emits its own TestRunFinished. Harden TestCaseFinished to reconstruct a minimal payload and still emit a terminal finish when the map entry is missing. Add a teardown sweep (run before queue drain / build stop in both the main and worker teardown paths) that emits terminal failed finishes for any scenario, hook, or native run left open, so nothing is left running to be reaped as a timeout. Make getCucumberHookType always return a known hook_type, and let TestMap.getUUID fall back to the most recent unfinished run. Co-Authored-By: Claude Opus 4.8 --- nightwatch/globals.js | 116 ++++++++++++++---- src/testObservability.js | 96 ++++++++++++++- src/utils/testMap.js | 30 ++++- .../test-observability/cucumberOrphanFix.js | 114 +++++++++++++++++ .../test-observability/orphanSweepUnits.js | 114 +++++++++++++++++ 5 files changed, 440 insertions(+), 30 deletions(-) create mode 100644 test/src/test-observability/cucumberOrphanFix.js create mode 100644 test/src/test-observability/orphanSweepUnits.js diff --git a/nightwatch/globals.js b/nightwatch/globals.js index 16f029b..9e4aa53 100644 --- a/nightwatch/globals.js +++ b/nightwatch/globals.js @@ -28,8 +28,9 @@ let testEventPromises = []; eventHelper.eventEmitter.on(EVENTS.LOG_INIT, (loggingData) => { const testCaseStartedId = loggingData.message.replace('TEST-OBSERVABILITY-PID-TESTCASE-MAPPING-', '').slice(1, -1); - const testCaseId = _testCasesData[testCaseStartedId]?.testCaseId; - currentTestUUID = _tests[testCaseId]?.uuid; + // _tests is keyed by the unique per-attempt testCaseStartedId so reruns and + // retries of the same scenario do not clobber each other's uuid. + currentTestUUID = _tests[testCaseStartedId]?.uuid; }); eventHelper.eventEmitter.on(EVENTS.LOG, (loggingData) => { @@ -115,8 +116,7 @@ module.exports = { } if (data.eventType === EVENTS.LOG_INIT) { const testCaseStartedId = data.loggingData.message.replace('TEST-OBSERVABILITY-PID-TESTCASE-MAPPING-', '').slice(1, -1); - const testCaseId = _testCasesData[testCaseStartedId]?.testCaseId; - const uuid = _tests[testCaseId]?.uuid; + const uuid = _tests[testCaseStartedId]?.uuid; await worker.process.send({testCaseStartedId, uuid}); } }); @@ -139,7 +139,10 @@ module.exports = { description: featureData.description }; } - _tests[testCaseId] = testMetaData; + // Key by the unique per-attempt id (envelope.id === testCaseStartedId) + // instead of the non-unique testCaseId, so a rerun/retry/parallel second + // attempt of the same scenario does not overwrite the first one's entry. + _tests[args.envelope.id] = testMetaData; await testObservability.sendTestRunEventForCucumber(reportData, gherkinDocument, pickleData, 'TestRunStarted', testMetaData, args); } catch (error) { CrashReporter.uploadCrashReport(error.message, error.stack); @@ -153,18 +156,33 @@ module.exports = { } try { const reportData = args.report; - const testCaseId = _testCasesData[args.envelope.testCaseStartedId].testCaseId; + const uniqueId = args.envelope.testCaseStartedId; + const testCaseId = _testCasesData[uniqueId].testCaseId; const pickleId = reportData.testCases.find((testCase) => testCase.id === testCaseId).pickleId; const pickleData = reportData.pickle.find((pickle) => pickle.id === pickleId); const gherkinDocument = reportData?.gherkinDocument.find((document) => document.uri === pickleData.uri); - const testMetaData = _tests[testCaseId]; - if (testMetaData) { - delete _tests[testCaseId]; - testMetaData.finishedAt = new Date().toISOString(); - CustomTagManager.drainPendingTestTags(testMetaData.uuid); - await testObservability.sendTestRunEventForCucumber(reportData, gherkinDocument, pickleData, 'TestRunFinished', testMetaData, args); + // Look up by the unique per-attempt id. If the entry is missing (a duplicate + // or out-of-order finish, or a start that was never recorded) reconstruct a + // minimal payload so a terminal finish is still emitted and the run can never + // be left open to be flipped to a timeout by the reaper. + let testMetaData = _tests[uniqueId]; + if (!testMetaData) { + testMetaData = { + uuid: uuidv4(), + startedAt: new Date().toISOString(), + scenario: {name: pickleData?.name}, + feature: (gherkinDocument && gherkinDocument.feature) ? { + path: gherkinDocument.uri, + name: gherkinDocument.feature.name, + description: gherkinDocument.feature.description + } : undefined + }; } + delete _tests[uniqueId]; + testMetaData.finishedAt = new Date().toISOString(); + CustomTagManager.drainPendingTestTags(testMetaData.uuid); + await testObservability.sendTestRunEventForCucumber(reportData, gherkinDocument, pickleData, 'TestRunFinished', testMetaData, args); } catch (error) { CrashReporter.uploadCrashReport(error.message, error.stack); Logger.error(`Something went wrong in processing report file for test reporting and analytics - ${error.message} with stacktrace ${error.stack}`); @@ -177,17 +195,18 @@ module.exports = { } try { const reportData = args.report; - const testCaseId = _testCasesData[args.envelope.testCaseStartedId].testCaseId; + const uniqueId = args.envelope.testCaseStartedId; + const testCaseId = _testCasesData[uniqueId].testCaseId; const pickleId = reportData.testCases.find((testCase) => testCase.id === testCaseId).pickleId; const pickleData = reportData.pickle.find((pickle) => pickle.id === pickleId); const testSteps = reportData.testCases.find((testCase) => testCase.id === testCaseId).testSteps; const testStepId = reportData.testStepStarted[args.envelope.testCaseStartedId].testStepId; - await testObservability.sendHook(args, 'HookRunStarted', testSteps, testStepId, _tests[testCaseId]); + await testObservability.sendHook(args, 'HookRunStarted', testSteps, testStepId, _tests[uniqueId]); const pickleStepId = testSteps.find((testStep) => testStep.id === testStepId).pickleStepId; - if (pickleStepId && _tests[testCaseId]?.['testStepId'] !== testStepId) { - _tests[testCaseId]['testStepId'] = testStepId; + if (pickleStepId && _tests[uniqueId]?.['testStepId'] !== testStepId) { + _tests[uniqueId]['testStepId'] = testStepId; const pickleStepData = pickleData.steps.find((pickle) => pickle.id === pickleStepId); - const testMetaData = _tests[testCaseId] || {steps: []}; + const testMetaData = _tests[uniqueId] || {steps: []}; if (testMetaData && !testMetaData.steps) { testMetaData.steps = []; } @@ -196,7 +215,7 @@ module.exports = { text: pickleStepData.text, started_at: new Date().toISOString() }); - _tests[testCaseId] = testMetaData; + _tests[uniqueId] = testMetaData; } } catch (error) { CrashReporter.uploadCrashReport(error.message, error.stack); @@ -211,13 +230,14 @@ module.exports = { try { const reportData = args.report; helper.storeSessionsData(args); - const testCaseId = _testCasesData[args.envelope.testCaseStartedId].testCaseId; + const uniqueId = args.envelope.testCaseStartedId; + const testCaseId = _testCasesData[uniqueId].testCaseId; const testStepFinished = reportData.testStepFinished[args.envelope.testCaseStartedId]; const pickleId = reportData.testCases.find((testCase) => testCase.id === testCaseId).pickleId; const pickleData = reportData.pickle.find((pickle) => pickle.id === pickleId); const testSteps = reportData.testCases.find((testCase) => testCase.id === testCaseId).testSteps; const testStepId = reportData.testStepFinished[args.envelope.testCaseStartedId].testStepId; - await testObservability.sendHook(args, 'HookRunFinished', testSteps, testStepId, _tests[testCaseId]); + await testObservability.sendHook(args, 'HookRunFinished', testSteps, testStepId, _tests[uniqueId]); const pickleStepId = testSteps.find((testStep) => testStep.id === testStepId).pickleStepId; let failure; let failureType; @@ -226,9 +246,9 @@ module.exports = { failureType = (testStepFinished.testStepResult?.exception === undefined) ? 'UnhandledError' : testStepFinished.testStepResult?.message; } - if (pickleStepId && _tests[testCaseId]['testStepId']) { + if (pickleStepId && _tests[uniqueId]['testStepId']) { const pickleStepData = pickleData.steps.find((pickle) => pickle.id === pickleStepId); - const testMetaData = _tests[testCaseId] || {steps: []}; + const testMetaData = _tests[uniqueId] || {steps: []}; if (!testMetaData.steps) { testMetaData.steps = [{ id: pickleStepData.id, @@ -250,8 +270,8 @@ module.exports = { } }); } - _tests[testCaseId] = testMetaData; - delete _tests[testCaseId]['testStepId']; + _tests[uniqueId] = testMetaData; + delete _tests[uniqueId]['testStepId']; if (testStepFinished.httpOutput && testStepFinished.httpOutput.length > 0) { for (const [index, output] of testStepFinished.httpOutput.entries()) { if (index % 2 === 0) { @@ -561,6 +581,10 @@ module.exports = { Logger.debug(`Error aggregating build-level tags from workers: ${err}`); } + // Sweep any still-open scenarios/hooks/native runs to terminal finishes + // BEFORE the queue is drained and the build is stopped, so they flush in + // this run instead of being left open for the reaper to time out. + await performTeardownSweep(); await testObservability.stopBuildUpstream(); if (process.env.BROWSERSTACK_TESTHUB_UUID) { Logger.info(`\nVisit https://automation.browserstack.com/builds/${process.env.BROWSERSTACK_TESTHUB_UUID} to view build report, insights, and many more debugging information all at one place!\n`); @@ -659,6 +683,9 @@ module.exports = { Logger.debug(`Error sending build-level tags from worker: ${err}`); } + // Sweep still-open entities to terminal finishes before the worker drains + // its request queue, so synthetic finishes are flushed for this worker. + await performTeardownSweep(); await helper.shutDownRequestHandler(); if (testEventPromises.length > 0) { await Promise.all(testEventPromises); @@ -667,6 +694,47 @@ module.exports = { } }; +const performTeardownSweep = async () => { + try { + // Cucumber: a scenario still present in _tests never received its + // TestCaseFinished. Emit a terminal finish, then drop the entry (idempotent). + for (const uniqueId of Object.keys(_tests)) { + const testMetaData = _tests[uniqueId]; + delete _tests[uniqueId]; + try { + await testObservability.sendSyntheticTestRunFinishedForCucumber(testMetaData); + } catch (err) { + Logger.debug(`Error sweeping open scenario ${uniqueId}: ${err && err.message}`); + } + } + + // Cucumber: hooks that started but never finished. + try { + await testObservability.sweepOpenHooks(); + } catch (err) { + Logger.debug(`Error sweeping open hooks: ${err && err.message}`); + } + + // Native: test runs still marked unfinished in the TestMap. + try { + const openRuns = TestMap.getOpenRuns(); + for (const run of openRuns) { + try { + await testObservability.sendSyntheticTestRunFinished(run.uuid, run); + } catch (err) { + Logger.debug(`Error sweeping open run ${run.uuid}: ${err && err.message}`); + } + TestMap.markTestFinished(run.uuid); + } + } catch (err) { + Logger.debug(`Error sweeping open native runs: ${err && err.message}`); + } + } catch (error) { + CrashReporter.uploadCrashReport(error.message, error.stack); + } +}; +module.exports.performTeardownSweep = performTeardownSweep; + const cucumberPatcher = () => { try { const Coordinator = helper.requireModule('@cucumber/cucumber/lib/runtime/parallel/coordinator.js'); diff --git a/src/testObservability.js b/src/testObservability.js index 7dcef52..5627703 100644 --- a/src/testObservability.js +++ b/src/testObservability.js @@ -871,17 +871,107 @@ class TestObservability { }; } - // BEFORE_ALL and AFTER_ALL are not implemented for TO + // Classify the cucumber hook so an emitted hook never carries a null hook_type. + // A hook found alongside scenario steps is a per-scenario hook (BEFORE_EACH / + // AFTER_EACH depending on whether any scenario step preceded it). A hook not + // found among the scenario steps is a suite-level hook, classified as + // BEFORE_ALL / AFTER_ALL by the same step-seen heuristic. getCucumberHookType(testSteps, hookData) { let isStep = false; - for (const step of testSteps) { + for (const step of testSteps || []) { if (step.pickleStepId) { isStep = true; } - if (hookData.id === step.id) { + if (hookData && hookData.id === step.id) { return (isStep) ? 'AFTER_EACH' : 'BEFORE_EACH'; } } + + return isStep ? 'AFTER_ALL' : 'BEFORE_ALL'; + } + + // Emit a terminal TestRunFinished for a cucumber scenario left open at teardown. + // Builds a minimal payload from the stored metadata and marks it failed so the + // backend treats the run as terminal and clears the running state. + async sendSyntheticTestRunFinishedForCucumber(testMetaData) { + const {feature, scenario, steps, uuid, startedAt} = testMetaData || {}; + if (!uuid) { + return; + } + const featurePath = feature && feature.path; + const testData = { + uuid: uuid, + started_at: startedAt, + finished_at: new Date().toISOString(), + type: 'test', + body: { + lang: 'nightwatch', + code: null + }, + name: scenario && scenario.name, + scope: scenario && scenario.name, + scopes: [feature && feature.name ? feature.name : ''], + identifier: scenario && scenario.name, + file_name: featurePath ? path.relative(process.cwd(), featurePath) : undefined, + location: featurePath ? path.relative(process.cwd(), featurePath) : undefined, + framework: 'nightwatch', + result: 'failed', + meta: { + feature: feature, + scenario: scenario, + steps: steps + } + }; + await helper.uploadEventData({event_type: 'TestRunFinished', test_run: testData}); + } + + // Emit a terminal TestRunFinished for a native (non-cucumber) run left open at + // teardown, built from the TestMap run info and marked failed so the backend + // clears the running state instead of letting the reaper time it out. + async sendSyntheticTestRunFinished(uuid, runInfo = {}) { + if (!uuid) { + return; + } + const identifier = runInfo.identifier || ''; + const separatorIndex = identifier.indexOf('::'); + const moduleName = separatorIndex === -1 ? identifier : identifier.slice(0, separatorIndex); + const testName = separatorIndex === -1 ? identifier : identifier.slice(separatorIndex + 2); + const testData = { + uuid: uuid, + type: 'test', + name: testName || 'unknown', + body: { + lang: 'javascript', + code: null + }, + scope: identifier, + scopes: [moduleName || ''], + started_at: runInfo.startedAt, + finished_at: new Date().toISOString(), + result: 'failed', + framework: 'nightwatch' + }; + await helper.uploadEventData({event_type: 'TestRunFinished', test_run: testData}); + } + + // Emit a terminal HookRunFinished for every hook that started but never finished + // (no finished_at). Idempotent: a finished hook is skipped, so re-running the + // sweep never double-finishes a hook. + async sweepOpenHooks() { + for (const testCaseStartedId of Object.keys(hooksMap)) { + const hookList = hooksMap[testCaseStartedId]; + if (!(hookList instanceof Array)) { + continue; + } + for (const hookEventData of hookList) { + if (hookEventData.finished_at) { + continue; + } + hookEventData.result = 'failed'; + hookEventData.finished_at = new Date().toISOString(); + await helper.uploadEventData({event_type: 'HookRunFinished', hook_run: hookEventData}); + } + } } async appendTestItemLog (log, testUuid) { diff --git a/src/utils/testMap.js b/src/utils/testMap.js index 1c95c0e..a528315 100644 --- a/src/utils/testMap.js +++ b/src/utils/testMap.js @@ -68,11 +68,35 @@ class TestMap { if (test) { const testIdentifier = typeof test === 'string' ? test : this.generateTestIdentifier(test); const testData = sharedTestMap.get(testIdentifier); - - return testData ? testData.currentUuid : null; + if (testData) { + return testData.currentUuid; + } } - return null; + // Fall back to the most recently started run that has not finished yet, so a + // finish event whose identifier cannot be resolved still lands on an open run + // instead of being dropped (which would otherwise leave that run to be reaped). + let fallbackUuid = null; + for (const [uuid, run] of activeTestRuns) { + if (!run.hasFinished) { + fallbackUuid = uuid; + } + } + + return fallbackUuid; + } + + // Returns every run that started but was never marked finished, joined with its + // stored metadata, so the teardown sweep can emit a terminal finish for each. + static getOpenRuns() { + const openRuns = []; + for (const [uuid, run] of activeTestRuns) { + if (!run.hasFinished) { + openRuns.push({uuid, ...run}); + } + } + + return openRuns; } static markTestFinished(uuid) { diff --git a/test/src/test-observability/cucumberOrphanFix.js b/test/src/test-observability/cucumberOrphanFix.js new file mode 100644 index 0000000..77b4d28 --- /dev/null +++ b/test/src/test-observability/cucumberOrphanFix.js @@ -0,0 +1,114 @@ +const assert = require('assert'); +const sinon = require('sinon'); + +const helper = require('../../../src/utils/helper'); +const TestObservability = require('../../../src/testObservability'); + +// Coverage for the cucumber orphan/timeout fix. +// +// The cucumber _tests map used to be keyed by the non-unique testCaseId. On +// reruns/retries/parallel interleaving, a second TestCaseStarted overwrote the +// first attempt's entry, so the first TestCaseFinished deleted it and the later +// attempt found no entry -> no TestRunFinished was emitted, leaving the run open +// to be reaped as a timeout. The map is now keyed by the unique testCaseStartedId, +// and a teardown sweep finishes anything still open. +const GLOBALS_PATH = require.resolve('../../../nightwatch/globals.js'); + +function loadGlobals() { + delete require.cache[GLOBALS_PATH]; + + return require('../../../nightwatch/globals.js'); +} + +function makeBroadcaster() { + const handlers = {}; + + return { + on(name, fn) { + handlers[name] = fn; + }, + handlers + }; +} + +function buildReport() { + return { + testCaseStarted: { + 'tcs-1': {testCaseId: 'tc-1'}, + 'tcs-2': {testCaseId: 'tc-1'} + }, + testCases: [{id: 'tc-1', pickleId: 'p-1', testSteps: []}], + pickle: [{id: 'p-1', name: 'Scenario A', uri: 'features/a.feature', tags: [], steps: []}], + gherkinDocument: [{uri: 'features/a.feature', feature: {name: 'Feature A', description: ''}}] + }; +} + +describe('globals - cucumber rerun correlation and teardown sweep', function () { + let sandbox; + let cucumberCalls; + let uploads; + + beforeEach(function () { + sandbox = sinon.createSandbox(); + cucumberCalls = []; + uploads = []; + + sandbox.stub(helper, 'isTestObservabilitySession').returns(true); + sandbox.stub(helper, 'isTestHubBuild').returns(true); + sandbox.stub(TestObservability.prototype, 'sendTestRunEventForCucumber') + .callsFake(async (reportData, gherkinDocument, pickleData, eventType, testMetaData) => { + cucumberCalls.push({eventType, uuid: testMetaData && testMetaData.uuid}); + }); + sandbox.stub(helper, 'uploadEventData').callsFake(async (payload) => { + uploads.push(payload); + }); + }); + + afterEach(function () { + sandbox.restore(); + }); + + it('emits a TestRunFinished for two attempts sharing a testCaseId but differing by testCaseStartedId', async function () { + const globals = loadGlobals(); + const broadcaster = makeBroadcaster(); + globals.registerEventHandlers(broadcaster); + const report = buildReport(); + + await broadcaster.handlers['TestCaseStarted']({envelope: {id: 'tcs-1', testCaseId: 'tc-1'}, report}); + await broadcaster.handlers['TestCaseStarted']({envelope: {id: 'tcs-2', testCaseId: 'tc-1'}, report}); + await broadcaster.handlers['TestCaseFinished']({envelope: {testCaseStartedId: 'tcs-1'}, report}); + await broadcaster.handlers['TestCaseFinished']({envelope: {testCaseStartedId: 'tcs-2'}, report}); + + const started = cucumberCalls.filter((c) => c.eventType === 'TestRunStarted'); + const finished = cucumberCalls.filter((c) => c.eventType === 'TestRunFinished'); + + assert.strictEqual(started.length, 2, 'both attempts should start'); + assert.strictEqual(finished.length, 2, 'both attempts should finish (no orphan)'); + + const startUuids = started.map((c) => c.uuid).sort(); + const finishUuids = finished.map((c) => c.uuid).sort(); + assert.notStrictEqual(startUuids[0], startUuids[1], 'attempts have distinct uuids'); + assert.deepStrictEqual(finishUuids, startUuids, 'both started uuids are finished'); + }); + + it('sweep emits a terminal failed TestRunFinished for a scenario left open in _tests, idempotently', async function () { + const globals = loadGlobals(); + const broadcaster = makeBroadcaster(); + globals.registerEventHandlers(broadcaster); + const report = buildReport(); + + await broadcaster.handlers['TestCaseStarted']({envelope: {id: 'tcs-1', testCaseId: 'tc-1'}, report}); + const startCall = cucumberCalls.find((c) => c.eventType === 'TestRunStarted'); + const openUuid = startCall.uuid; + + await globals.performTeardownSweep(); + + const swept = uploads.filter((u) => u.event_type === 'TestRunFinished' && u.test_run && u.test_run.uuid === openUuid); + assert.strictEqual(swept.length, 1, 'open scenario is finished exactly once by the sweep'); + assert.strictEqual(swept[0].test_run.result, 'failed', 'synthetic finish is terminal (failed)'); + + await globals.performTeardownSweep(); + const sweptAgain = uploads.filter((u) => u.event_type === 'TestRunFinished' && u.test_run && u.test_run.uuid === openUuid); + assert.strictEqual(sweptAgain.length, 1, 'second sweep does not double-finish the scenario'); + }); +}); diff --git a/test/src/test-observability/orphanSweepUnits.js b/test/src/test-observability/orphanSweepUnits.js new file mode 100644 index 0000000..f6c5059 --- /dev/null +++ b/test/src/test-observability/orphanSweepUnits.js @@ -0,0 +1,114 @@ +const assert = require('assert'); +const sinon = require('sinon'); + +const helper = require('../../../src/utils/helper'); +const TestMap = require('../../../src/utils/testMap'); +const TestObservability = require('../../../src/testObservability'); + +describe('TestObservability - getCucumberHookType never returns undefined', function () { + let testObservability; + + beforeEach(function () { + testObservability = new TestObservability(); + }); + + it('classifies a per-scenario hook before any step as BEFORE_EACH', function () { + const testSteps = [{id: 'h1', hookId: 'hook-1'}, {id: 's1', pickleStepId: 'ps1'}]; + assert.strictEqual(testObservability.getCucumberHookType(testSteps, {id: 'h1'}), 'BEFORE_EACH'); + }); + + it('classifies a per-scenario hook after a step as AFTER_EACH', function () { + const testSteps = [{id: 's1', pickleStepId: 'ps1'}, {id: 'h1', hookId: 'hook-1'}]; + assert.strictEqual(testObservability.getCucumberHookType(testSteps, {id: 'h1'}), 'AFTER_EACH'); + }); + + it('classifies a hook absent from the scenario steps as a suite-level hook', function () { + assert.strictEqual(testObservability.getCucumberHookType([], {id: 'missing'}), 'BEFORE_ALL'); + assert.strictEqual(testObservability.getCucumberHookType([{id: 's1', pickleStepId: 'ps1'}], {id: 'missing'}), 'AFTER_ALL'); + }); + + it('never returns undefined across malformed inputs', function () { + const cases = [ + testObservability.getCucumberHookType([], {}), + testObservability.getCucumberHookType(undefined, {id: 'x'}), + testObservability.getCucumberHookType([{id: 's1', pickleStepId: 'ps1'}], {id: 'h1'}) + ]; + cases.forEach((hookType) => { + assert.notStrictEqual(hookType, undefined, 'hook_type must never be undefined'); + assert.ok(['BEFORE_EACH', 'AFTER_EACH', 'BEFORE_ALL', 'AFTER_ALL'].includes(hookType)); + }); + }); +}); + +describe('TestObservability - sweepOpenHooks', function () { + let sandbox; + let uploads; + let testObservability; + + beforeEach(function () { + sandbox = sinon.createSandbox(); + uploads = []; + testObservability = new TestObservability(); + sandbox.stub(helper, 'uploadEventData').callsFake(async (payload) => { + uploads.push(payload); + }); + }); + + afterEach(function () { + sandbox.restore(); + }); + + it('finishes a hook that started but never finished, idempotently', async function () { + const args = { + envelope: {testCaseStartedId: 'sweep-tcs-1'}, + report: {hooks: [{id: 'hook-A', name: 'Before', sourceReference: {uri: 'features/support/hooks.js'}}]} + }; + const testSteps = [{id: 'step-A', hookId: 'hook-A'}]; + + await testObservability.sendHook(args, 'HookRunStarted', testSteps, 'step-A', {feature: {name: 'Feature A'}}); + await testObservability.sweepOpenHooks(); + + const finished = uploads.filter((u) => u.event_type === 'HookRunFinished' && u.hook_run && u.hook_run.uuid === 'step-A'); + assert.strictEqual(finished.length, 1, 'open hook is finished once'); + assert.strictEqual(finished[0].hook_run.result, 'failed', 'synthetic hook finish is terminal (failed)'); + + await testObservability.sweepOpenHooks(); + const finishedAgain = uploads.filter((u) => u.event_type === 'HookRunFinished' && u.hook_run && u.hook_run.uuid === 'step-A'); + assert.strictEqual(finishedAgain.length, 1, 'second sweep does not double-finish the hook'); + }); +}); + +describe('TestMap.getOpenRuns and synthetic native finish', function () { + let sandbox; + let uploads; + let testObservability; + + beforeEach(function () { + sandbox = sinon.createSandbox(); + uploads = []; + testObservability = new TestObservability(); + sandbox.stub(helper, 'uploadEventData').callsFake(async (payload) => { + uploads.push(payload); + }); + }); + + afterEach(function () { + sandbox.restore(); + }); + + it('reports an unfinished run, synthesises a failed finish, and clears it after markTestFinished', async function () { + const uuid = TestMap.storeTestDetails({testcase: 'native test', metadata: {name: 'Native Module'}}); + + const openBefore = TestMap.getOpenRuns().filter((r) => r.uuid === uuid); + assert.strictEqual(openBefore.length, 1, 'stored run is reported as open'); + + await testObservability.sendSyntheticTestRunFinished(uuid, openBefore[0]); + const finished = uploads.filter((u) => u.event_type === 'TestRunFinished' && u.test_run && u.test_run.uuid === uuid); + assert.strictEqual(finished.length, 1, 'a terminal finish is emitted for the open run'); + assert.strictEqual(finished[0].test_run.result, 'failed', 'synthetic native finish is terminal (failed)'); + + TestMap.markTestFinished(uuid); + const openAfter = TestMap.getOpenRuns().filter((r) => r.uuid === uuid); + assert.strictEqual(openAfter.length, 0, 'finished run is no longer reported as open'); + }); +}); From 2f2b0c4ab06cbc7c3b443a68dae64fc34d69b49f Mon Sep 17 00:00:00 2001 From: xxshubhamxx Date: Wed, 10 Jun 2026 11:39:38 +0530 Subject: [PATCH 2/5] fix(observability): make cucumber TestCaseFinished idempotent and drop fresh-uuid reconstruct A duplicate/out-of-order TestCaseFinished for the same attempt used to find the entry already deleted, hit the reconstruct branch, mint a fresh uuid, and emit a phantom TestRunFinished for a run the backend never saw started. And the reconstruct branch was dead code for the genuine start-never-recorded orphan: the unguarded _testCasesData read threw before it ran (and the reconstruct itself threw on undefined), all silently swallowed. Track handled attempt ids in a Set and early-return on a duplicate finish, guard the _testCasesData read so an unknown finish no-ops cleanly, and remove the fresh-uuid reconstruct branch entirely. True orphans (started, never finished) are owned solely by the teardown sweep, which holds the real stored uuid. The Set is per-process and bounded by attempt count (same bound as _testCasesData). Also: per-hook try/catch in sweepOpenHooks so one bad upload no longer aborts the remaining hook sweeps; fix the synthetic native finish lang to 'nightwatch'; and document the single-open-run-per-process assumption behind the TestMap.getUUID fallback. Add tests for the duplicate-finish and never-started-finish cases. Co-Authored-By: Claude Opus 4.8 --- nightwatch/globals.js | 44 +++++++++++-------- src/testObservability.js | 12 +++-- src/utils/testMap.js | 5 +++ .../test-observability/cucumberOrphanFix.js | 44 +++++++++++++++++++ 4 files changed, 83 insertions(+), 22 deletions(-) diff --git a/nightwatch/globals.js b/nightwatch/globals.js index 9e4aa53..9476760 100644 --- a/nightwatch/globals.js +++ b/nightwatch/globals.js @@ -21,6 +21,11 @@ const nightwatchRerun = process.env.NIGHTWATCH_RERUN_FAILED; const nightwatchRerunFile = process.env.NIGHTWATCH_RERUN_REPORT_FILE; const _tests = {}; const _testCasesData = {}; +// Per-attempt testCaseStartedId of every TestCaseFinished already handled, so a +// duplicate/out-of-order finish for the same attempt is a no-op instead of +// re-emitting a phantom TestRunFinished. Bounded by attempt count per worker +// process (same bound as _testCasesData), so it cannot grow unbounded. +const _finishedTestCaseIds = new Set(); let currentTestUUID = ''; let workerList = {}; let testRunner = ''; @@ -157,29 +162,29 @@ module.exports = { try { const reportData = args.report; const uniqueId = args.envelope.testCaseStartedId; - const testCaseId = _testCasesData[uniqueId].testCaseId; + // A duplicate/out-of-order finish for an attempt we have already finished + // is a no-op: re-emitting would mint a phantom TestRunFinished for a run the + // backend never saw started. + if (_finishedTestCaseIds.has(uniqueId)) { + return; + } + const testCaseId = _testCasesData[uniqueId]?.testCaseId; + const testMetaData = _tests[uniqueId]; + // A finish whose start was never recorded has no stored metadata to finish + // and no real backend run to terminate; no-op here. The teardown sweep is the + // single owner of true orphans (it holds the real stored uuid for any entry + // that started but never finished). + if (!testCaseId || !testMetaData) { + _finishedTestCaseIds.add(uniqueId); + + return; + } const pickleId = reportData.testCases.find((testCase) => testCase.id === testCaseId).pickleId; const pickleData = reportData.pickle.find((pickle) => pickle.id === pickleId); const gherkinDocument = reportData?.gherkinDocument.find((document) => document.uri === pickleData.uri); - // Look up by the unique per-attempt id. If the entry is missing (a duplicate - // or out-of-order finish, or a start that was never recorded) reconstruct a - // minimal payload so a terminal finish is still emitted and the run can never - // be left open to be flipped to a timeout by the reaper. - let testMetaData = _tests[uniqueId]; - if (!testMetaData) { - testMetaData = { - uuid: uuidv4(), - startedAt: new Date().toISOString(), - scenario: {name: pickleData?.name}, - feature: (gherkinDocument && gherkinDocument.feature) ? { - path: gherkinDocument.uri, - name: gherkinDocument.feature.name, - description: gherkinDocument.feature.description - } : undefined - }; - } delete _tests[uniqueId]; + _finishedTestCaseIds.add(uniqueId); testMetaData.finishedAt = new Date().toISOString(); CustomTagManager.drainPendingTestTags(testMetaData.uuid); await testObservability.sendTestRunEventForCucumber(reportData, gherkinDocument, pickleData, 'TestRunFinished', testMetaData, args); @@ -733,6 +738,9 @@ const performTeardownSweep = async () => { CrashReporter.uploadCrashReport(error.message, error.stack); } }; +// Attached as a named export (rather than folded into the module.exports object +// literal above) so unit tests can drive the sweep directly without relocating the +// const, which is referenced by the teardown closures earlier in the literal. module.exports.performTeardownSweep = performTeardownSweep; const cucumberPatcher = () => { diff --git a/src/testObservability.js b/src/testObservability.js index 5627703..8113cb1 100644 --- a/src/testObservability.js +++ b/src/testObservability.js @@ -941,7 +941,7 @@ class TestObservability { type: 'test', name: testName || 'unknown', body: { - lang: 'javascript', + lang: 'nightwatch', code: null }, scope: identifier, @@ -967,9 +967,13 @@ class TestObservability { if (hookEventData.finished_at) { continue; } - hookEventData.result = 'failed'; - hookEventData.finished_at = new Date().toISOString(); - await helper.uploadEventData({event_type: 'HookRunFinished', hook_run: hookEventData}); + try { + hookEventData.result = 'failed'; + hookEventData.finished_at = new Date().toISOString(); + await helper.uploadEventData({event_type: 'HookRunFinished', hook_run: hookEventData}); + } catch (err) { + Logger.debug(`Error sweeping open hook ${hookEventData.uuid}: ${err && err.message}`); + } } } } diff --git a/src/utils/testMap.js b/src/utils/testMap.js index a528315..4bdc6bf 100644 --- a/src/utils/testMap.js +++ b/src/utils/testMap.js @@ -76,6 +76,11 @@ class TestMap { // Fall back to the most recently started run that has not finished yet, so a // finish event whose identifier cannot be resolved still lands on an open run // instead of being dropped (which would otherwise leave that run to be reaped). + // Assumes a single open run per worker process: Nightwatch parallelism is across + // processes (each gets its own TestMap), and within a process tests run serially, + // so at most one run is open at a time. If in-process parallel tests are ever + // added, this "most recent open run" pick would need a real identifier match to + // avoid bleeding a finish onto the wrong concurrent run. let fallbackUuid = null; for (const [uuid, run] of activeTestRuns) { if (!run.hasFinished) { diff --git a/test/src/test-observability/cucumberOrphanFix.js b/test/src/test-observability/cucumberOrphanFix.js index 77b4d28..fe57be1 100644 --- a/test/src/test-observability/cucumberOrphanFix.js +++ b/test/src/test-observability/cucumberOrphanFix.js @@ -91,6 +91,50 @@ describe('globals - cucumber rerun correlation and teardown sweep', function () assert.deepStrictEqual(finishUuids, startUuids, 'both started uuids are finished'); }); + it('a duplicate TestCaseFinished for the same attempt emits exactly one TestRunFinished and no phantom uuid', async function () { + const globals = loadGlobals(); + const broadcaster = makeBroadcaster(); + globals.registerEventHandlers(broadcaster); + const report = buildReport(); + + await broadcaster.handlers['TestCaseStarted']({envelope: {id: 'tcs-1', testCaseId: 'tc-1'}, report}); + const startCall = cucumberCalls.find((c) => c.eventType === 'TestRunStarted'); + const startedUuid = startCall.uuid; + + await broadcaster.handlers['TestCaseFinished']({envelope: {testCaseStartedId: 'tcs-1'}, report}); + // Second finish for the SAME attempt: the entry is already gone, so the old + // reconstruct branch would have minted a fresh uuid and emitted a phantom + // TestRunFinished. It must now be a clean no-op. + await broadcaster.handlers['TestCaseFinished']({envelope: {testCaseStartedId: 'tcs-1'}, report}); + + const finished = cucumberCalls.filter((c) => c.eventType === 'TestRunFinished'); + assert.strictEqual(finished.length, 1, 'only one TestRunFinished for the attempt'); + assert.strictEqual(finished[0].uuid, startedUuid, 'finish carries the started uuid, not a fresh phantom one'); + }); + + it('a TestCaseFinished whose start was never recorded neither throws nor emits, and the sweep still finishes a stored-but-unfinished entry', async function () { + const globals = loadGlobals(); + const broadcaster = makeBroadcaster(); + globals.registerEventHandlers(broadcaster); + const report = buildReport(); + + // No TestCaseStarted for tcs-1: a finish arrives for an attempt we never saw start. + await broadcaster.handlers['TestCaseFinished']({envelope: {testCaseStartedId: 'tcs-1'}, report}); + + const finished = cucumberCalls.filter((c) => c.eventType === 'TestRunFinished'); + assert.strictEqual(finished.length, 0, 'an unknown finish emits nothing (no phantom run)'); + assert.strictEqual(uploads.length, 0, 'and uploads nothing'); + + // A genuine orphan (started, never finished) is still owned by the sweep, which + // holds the real stored uuid. + await broadcaster.handlers['TestCaseStarted']({envelope: {id: 'tcs-2', testCaseId: 'tc-1'}, report}); + const openUuid = cucumberCalls.find((c) => c.eventType === 'TestRunStarted').uuid; + + await globals.performTeardownSweep(); + const swept = uploads.filter((u) => u.event_type === 'TestRunFinished' && u.test_run && u.test_run.uuid === openUuid); + assert.strictEqual(swept.length, 1, 'the sweep finishes the stored-but-unfinished entry with its real uuid'); + }); + it('sweep emits a terminal failed TestRunFinished for a scenario left open in _tests, idempotently', async function () { const globals = loadGlobals(); const broadcaster = makeBroadcaster(); From 79142b2dfaf00e26f329a9f0795703554a783bd8 Mon Sep 17 00:00:00 2001 From: Kamalpreet Kaur Date: Wed, 10 Jun 2026 18:03:18 +0530 Subject: [PATCH 3/5] fix(accessibility): patch prototype command for class-based Nightwatch commands MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit commandWrapper() patched `originalCommand.command` directly, which only works for web-element commands that export a plain object (`module.exports.command = fn`). executeScript/executeAsyncScript (and the protocol/client/appium commands) export a class with `command` on the prototype, so the patch landed on a non-existent static method and the real prototype command Nightwatch invokes stayed unpatched. As a result `performScan` never ran for `browser.execute('mobile:scroll', ...)` (and all other class-based commands listed in commands.json) on App Accessibility sessions — no accessibility scan was captured for those interactions. Detect whether `command` lives as an own property (object export) or on the prototype (class export) and patch the correct target, mirroring how the `protocolAction` branch already handles class-based commands. The existing `shouldPatchExecuteScript` recursion guard now becomes effective and prevents the plugin's own `browserstack_executor` scan scripts from re-triggering a scan. Verified on a real-device Android App Accessibility session: `mobile:scroll` now triggers exactly one performScan, with no recursion, and the test passes. Co-Authored-By: Claude Opus 4.8 (1M context) --- src/accessibilityAutomation.js | 21 +++++++++++++++++++-- 1 file changed, 19 insertions(+), 2 deletions(-) diff --git a/src/accessibilityAutomation.js b/src/accessibilityAutomation.js index 7e914eb..c5816e5 100644 --- a/src/accessibilityAutomation.js +++ b/src/accessibilityAutomation.js @@ -437,9 +437,26 @@ class AccessibilityAutomation { try { const webElementCommandPath = path.join(nightwatchDir, `${commandJson[commandKey].path}`, `${commandName}.js`); const originalCommand = require(webElementCommandPath); - const originalCommandFn = originalCommand.command; - originalCommand.command = async function(...args) { + // Nightwatch commands are exported in two shapes: web-element commands + // export a plain object with an own `command` function, while client-commands, + // protocol and document commands (e.g. executeScript) export a class with + // `command` on the prototype. Patch wherever the command function actually lives. + const commandTarget = typeof originalCommand.command === 'function' + ? originalCommand + : (originalCommand.prototype && typeof originalCommand.prototype.command === 'function' + ? originalCommand.prototype + : null); + + if (!commandTarget) { + Logger.debug(`Failed to patch command ${commandName}: no command function found`); + + return; + } + + const originalCommandFn = commandTarget.command; + + commandTarget.command = async function(...args) { if ( !commandName.includes('execute') || !accessibilityInstance.shouldPatchExecuteScript(args.length ? args[0] : null) From 10352c4eec97de25b3f7efdb5b6d23abf3c26ba5 Mon Sep 17 00:00:00 2001 From: Kamalpreet Kaur Date: Wed, 10 Jun 2026 18:25:26 +0530 Subject: [PATCH 4/5] fix(accessibility): scan function-form execute/executeAsyncScript user scripts MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit shouldPatchExecuteScript() treated any non-string script as a script to skip (`!script || typeof script !== 'string'` -> return true), so user scripts passed as functions — `browser.execute(function(){...})` / `executeAsyncScript(fn)` — never triggered performScan, even though they can mutate page/screen state just like a string script. The plugin's own scan scripts are always strings carrying the `browserstack_executor` token (verified: every internal execute* call in the SDK passes a string), so a non-string script is always a user script and is safe to scan — the string-based recursion guard is unaffected. Treat an empty/undefined script as skip (unchanged) and a function script as a user script to scan. Verified on a real-device Android App Accessibility session: executeAsyncScript(fn) now triggers exactly one performScan; the 18 internal browserstack_executor scan scripts are still skipped (no recursion); test passes. Co-Authored-By: Claude Opus 4.8 (1M context) --- src/accessibilityAutomation.js | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/src/accessibilityAutomation.js b/src/accessibilityAutomation.js index c5816e5..67b24f3 100644 --- a/src/accessibilityAutomation.js +++ b/src/accessibilityAutomation.js @@ -475,10 +475,17 @@ class AccessibilityAutomation { } shouldPatchExecuteScript(script) { - if (!script || typeof script !== 'string') { + if (!script) { return true; } + // A non-string script (a function passed to .execute()/.executeAsyncScript()) + // is always a user script — the plugin's own scan scripts are always strings + // carrying the browserstack_executor token. Scan it. + if (typeof script !== 'string') { + return false; + } + return ( script.toLowerCase().indexOf('browserstack_executor') !== -1 || script.toLowerCase().indexOf('browserstack_accessibility_automation_script') !== -1 From 9659b4544f82095e2e23eefc4bd7f16e5b25ed97 Mon Sep 17 00:00:00 2001 From: Kamalpreet Kaur Date: Wed, 10 Jun 2026 18:58:29 +0530 Subject: [PATCH 5/5] test(accessibility): cover commandWrapper prototype patching + executeScript guard Adds unit tests for the two accessibility command-wrapping fixes: - shouldPatchExecuteScript: empty -> skip, internal browserstack_executor / accessibility scripts -> skip, user string scripts -> scan, and (regression) function-form user scripts -> scan. - commandWrapper: wraps the own `command` of object-export (web-element) commands and the prototype `command` of class-export commands (executeScript) without creating a phantom static; verifies the wrapped command triggers performScan, delegates to the original, honours the recursion guard, and scans function-form scripts. Drives commandWrapper deterministically by stubbing require.resolve('nightwatch') and injecting fake command modules via require.cache. Co-Authored-By: Claude Opus 4.8 (1M context) --- test/src/accessibilityAutomation.js | 136 ++++++++++++++++++++++++++++ 1 file changed, 136 insertions(+) create mode 100644 test/src/accessibilityAutomation.js diff --git a/test/src/accessibilityAutomation.js b/test/src/accessibilityAutomation.js new file mode 100644 index 0000000..44aa6bf --- /dev/null +++ b/test/src/accessibilityAutomation.js @@ -0,0 +1,136 @@ +const path = require('path'); +const Module = require('module'); +const sinon = require('sinon'); +const {expect} = require('chai'); + +// accessibilityAutomation participates in a circular require +// (accessibilityAutomation -> helper -> logPatcher -> testObservability -> accessibilityAutomation), +// and testObservability instantiates AccessibilityAutomation at load time. Warm up the chain via +// helper first so the class is fully exported before we require it directly. +require('../../src/utils/helper'); +const AccessibilityAutomation = require('../../src/accessibilityAutomation'); +const AccessibilityScripts = require('../../src/scripts/accessibilityScripts'); + +describe('AccessibilityAutomation.shouldPatchExecuteScript', () => { + let instance; + + before(() => { + instance = new AccessibilityAutomation(); + }); + + it('returns true (skip scan) for an empty/undefined script', () => { + expect(instance.shouldPatchExecuteScript(undefined)).to.eq(true); + expect(instance.shouldPatchExecuteScript(null)).to.eq(true); + expect(instance.shouldPatchExecuteScript('')).to.eq(true); + }); + + it('returns true (skip scan) for the plugin\'s internal browserstack scripts', () => { + expect(instance.shouldPatchExecuteScript('browserstack_executor: {"action":"appAllyScan"}')).to.eq(true); + expect(instance.shouldPatchExecuteScript('BROWSERSTACK_EXECUTOR: {}')).to.eq(true); + expect(instance.shouldPatchExecuteScript('browserstack_accessibility_automation_script')).to.eq(true); + }); + + it('returns false (trigger scan) for a normal user string script', () => { + expect(instance.shouldPatchExecuteScript('mobile:scroll')).to.eq(false); + expect(instance.shouldPatchExecuteScript('return document.title')).to.eq(false); + }); + + it('returns false (trigger scan) for a function-form user script', () => { + // Regression: a function script was previously treated as "skip", so + // browser.execute(function(){...}) never triggered an accessibility scan. + expect(instance.shouldPatchExecuteScript(function () {})).to.eq(false); + expect(instance.shouldPatchExecuteScript(() => {})).to.eq(false); + }); +}); + +describe('AccessibilityAutomation.commandWrapper', () => { + const fakeMain = path.join('/tmp', 'fake-nightwatch', 'index.js'); + const fakeDir = path.dirname(fakeMain); + const objPath = path.join(fakeDir, 'api/web-element/commands', 'objCmd.js'); + const classPath = path.join(fakeDir, 'api/client-commands/document', 'executeScript.js'); + + let resolveStub; let instance; let perfStub; let objModule; let ClassModule; let origObjCmd; let origClassCmd; + + beforeEach(async () => { + const origResolve = Module._resolveFilename; + resolveStub = sinon.stub(Module, '_resolveFilename').callsFake(function (request, ...rest) { + if (request === 'nightwatch') { + return fakeMain; + } + if (request === objPath || request === classPath) { + return request; + } + + return origResolve.call(this, request, ...rest); + }); + + // Object-export command (web-element style): `module.exports.command = fn`. + origObjCmd = function () { return 'obj-orig' }; + objModule = {command: origObjCmd}; + + // Class-export command (executeScript style): `command` lives on the prototype. + origClassCmd = function () { return 'class-orig' }; + ClassModule = class ExecuteScript {}; + ClassModule.prototype.command = origClassCmd; + + require.cache[objPath] = {id: objPath, filename: objPath, loaded: true, exports: objModule}; + require.cache[classPath] = {id: classPath, filename: classPath, loaded: true, exports: ClassModule}; + + AccessibilityScripts.commandsToWrap = [ + {method: 'command', path: 'api/web-element/commands', name: ['objCmd']}, + {method: 'command', path: 'api/client-commands/document', name: ['executeScript']} + ]; + + global.browser = {}; + instance = new AccessibilityAutomation(); + perfStub = sinon.stub(instance, 'performScan').resolves('scanned'); + + await instance.commandWrapper(); + }); + + afterEach(() => { + resolveStub.restore(); + delete require.cache[objPath]; + delete require.cache[classPath]; + delete global.browser; + AccessibilityScripts.commandsToWrap = null; + }); + + it('wraps the own `command` of an object-export (web-element) command', () => { + expect(objModule.command).to.be.a('function'); + expect(objModule.command).to.not.eq(origObjCmd); + }); + + it('wraps the prototype `command` of a class-export command, not a static', () => { + expect(ClassModule.prototype.command).to.not.eq(origClassCmd); + // The original bug patched a non-existent static `command`; ensure we did NOT create one. + expect(Object.prototype.hasOwnProperty.call(ClassModule, 'command')).to.eq(false); + }); + + it('class-export wrapped command triggers performScan and delegates to the original', async () => { + const result = await new ClassModule().command('mobile:scroll'); + + expect(perfStub.calledOnce).to.eq(true); + expect(perfStub.firstCall.args[1]).to.eq('executeScript'); + expect(result).to.eq('class-orig'); + }); + + it('skips performScan for the plugin\'s internal browserstack_executor script (recursion guard)', async () => { + await new ClassModule().command('browserstack_executor: {"action":"appAllyScan"}'); + + expect(perfStub.called).to.eq(false); + }); + + it('triggers performScan for a function-form user script passed to execute', async () => { + await new ClassModule().command(function () {}); + + expect(perfStub.calledOnce).to.eq(true); + }); + + it('triggers performScan for a non-execute object-export command', async () => { + await objModule.command(); + + expect(perfStub.calledOnce).to.eq(true); + expect(perfStub.firstCall.args[1]).to.eq('objCmd'); + }); +});