diff --git a/bin/commands/runs.js b/bin/commands/runs.js index 0a439ff6..dd04775f 100644 --- a/bin/commands/runs.js +++ b/bin/commands/runs.js @@ -192,6 +192,10 @@ module.exports = function run(args, rawArgs) { logger.debug("Completed setting the configs"); if(!isBrowserstackInfra) { + if(process.env.BS_TESTOPS_BUILD_COMPLETED) { + setEventListeners(bsConfig); + } + return runCypressTestsLocally(bsConfig, args, rawArgs); } @@ -203,7 +207,7 @@ module.exports = function run(args, rawArgs) { setAccessibilityEventListeners(bsConfig); } if(process.env.BS_TESTOPS_BUILD_COMPLETED) { - // setEventListeners(bsConfig); + setEventListeners(bsConfig); } markBlockEnd('validateConfig'); logger.debug("Completed configs validation"); diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index 78482442..0eb2f3d8 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -1,86 +1,137 @@ /* Event listeners + custom commands for Cypress */ /* Used to detect Gherkin steps */ + +const util = require('util'); + +let eventsQueue = []; +let testRunStarted = false; + +const browserStackLog = (message) => { + + if (!Cypress.env('BROWSERSTACK_LOGS')) return; + cy.task('browserstack_log', message); +} + +const shouldSkipCommand = (command) => { + if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) { + return true; + } + return command.attributes.name == 'log' || (command.attributes.name == 'task' && (['test_observability_platform_details', 'test_observability_step', 'test_observability_command', 'browserstack_log', 'test_observability_log'].some(event => command.attributes.args.includes(event)))); +} + Cypress.on('log:added', (log) => { - return () => { - return cy.now('task', 'test_observability_step', { - log - }, {log: false}) + return () => { + if (shouldSkipCommand(command)) { + return; } - }); - + eventsQueue.push({ + task: 'test_observability_step', + data: { + log, + started_at: new Date().toISOString(), + finished_at: new Date().toISOString() + }, + options: { log: false } + }); + } +}); + Cypress.on('command:start', (command) => { - if(!command || !command.attributes) return; - if(command.attributes.name == 'log' || (command.attributes.name == 'task' && (command.attributes.args.includes('test_observability_command') || command.attributes.args.includes('test_observability_log')))) { + + if (!command || !command.attributes) return; + if (shouldSkipCommand(command)) { return; } + /* Send command details */ - cy.now('task', 'test_observability_command', { - type: 'COMMAND_START', - command: { - attributes: { - id: command.attributes.id, - name: command.attributes.name, - args: command.attributes.args - }, - state: 'pending' - } - }, {log: false}).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_command', + data: { + type: 'COMMAND_START', + command: { + attributes: { + id: command.attributes.id, + name: command.attributes.name, + args: command.attributes.args + }, + state: 'pending', + started_at: new Date().toISOString(), + location: testRunStarted ? 'test' : 'hook' + } + }, + options: { log: false } }); - /* Send platform details */ - cy.now('task', 'test_observability_platform_details', { - testTitle: Cypress.currentTest.title, - browser: Cypress.browser, - platform: Cypress.platform, - cypressVersion: Cypress.version - }, {log: false}).then((res) => { - }).catch((err) => { + let testTitle = ''; + try { + const runner = Cypress.mocha.getRunner(); + const ctx = runner.suite.ctx; + testTitle = ctx.currentTest.title || ctx._runnable.title; + } catch (error) { + // Silently handle if any property is undefined + } + + eventsQueue.push({ + task: 'test_observability_platform_details', + data: { + testTitle, + browser: Cypress.browser, + platform: Cypress.platform, + cypressVersion: Cypress.version + }, + options: { log: false } }); }); Cypress.on('command:retry', (command) => { - if(!command || !command.attributes) return; - if(command.attributes.name == 'log' || (command.attributes.name == 'task' && (command.attributes.args.includes('test_observability_command') || command.attributes.args.includes('test_observability_log')))) { + if (!command || !command.attributes) return; + if (shouldSkipCommand(command)) { return; } - cy.now('task', 'test_observability_command', { - type: 'COMMAND_RETRY', - command: { - _log: command._log, - error: { - message: command && command.error ? command.error.message : null, - isDefaultAssertionErr: command && command.error ? command.error.isDefaultAssertionErr : null + eventsQueue.push({ + task: 'test_observability_command', + data: { + type: 'COMMAND_RETRY', + command: { + _log: command._log, + error: { + message: command && command.error ? command.error.message : null, + isDefaultAssertionErr: command && command.error ? command.error.isDefaultAssertionErr : null + }, + location: testRunStarted ? 'test' : 'hook' } - } - }, {log: false}).then((res) => { - }).catch((err) => { + }, + options: { log: false } }); }); Cypress.on('command:end', (command) => { - if(!command || !command.attributes) return; - if(command.attributes.name == 'log' || (command.attributes.name == 'task' && (command.attributes.args.includes('test_observability_command') || command.attributes.args.includes('test_observability_log')))) { + if (!command || !command.attributes) return; + if (shouldSkipCommand(command)) { return; } - cy.now('task', 'test_observability_command', { - 'type': 'COMMAND_END', - 'command': { - 'attributes': { - 'id': command.attributes.id, - 'name': command.attributes.name, - 'args': command.attributes.args - }, - 'state': command.state - } - }, {log: false}).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_command', + data: { + 'type': 'COMMAND_END', + 'command': { + 'attributes': { + 'id': command.attributes.id, + 'name': command.attributes.name, + 'args': command.attributes.args + }, + 'state': command.state, + finished_at: new Date().toISOString(), + location: testRunStarted ? 'test' : 'hook' + } + }, + options: { log: false } }); }); Cypress.Commands.overwrite('log', (originalFn, ...args) => { - if(args.includes('test_observability_log') || args.includes('test_observability_command')) return; + if (args.includes('test_observability_log') || args.includes('test_observability_command')) return; const message = args.reduce((result, logItem) => { if (typeof logItem === 'object') { return [result, JSON.stringify(logItem)].join(' '); @@ -88,71 +139,118 @@ Cypress.Commands.overwrite('log', (originalFn, ...args) => { return [result, logItem ? logItem.toString() : ''].join(' '); }, ''); - cy.now('task', 'test_observability_log', { - 'level': 'info', - message, - }, {log: false}).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + 'level': 'info', + message, + timestamp: new Date().toISOString() + }, + options: { log: false } }); originalFn(...args); }); Cypress.Commands.add('trace', (message, file) => { - cy.now('task', 'test_observability_log', { - level: 'trace', - message, - file, - }).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + level: 'trace', + message, + file, + }, + options: { log: false } }); }); Cypress.Commands.add('logDebug', (message, file) => { - cy.now('task', 'test_observability_log', { - level: 'debug', - message, - file, - }).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + level: 'debug', + message, + file, + }, + options: { log: false } }); }); Cypress.Commands.add('info', (message, file) => { - cy.now('task', 'test_observability_log', { - level: 'info', - message, - file, - }).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + level: 'info', + message, + file, + }, + options: { log: false } }); }); Cypress.Commands.add('warn', (message, file) => { - cy.now('task', 'test_observability_log', { - level: 'warn', - message, - file, - }).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + level: 'warn', + message, + file, + }, + options: { log: false } }); }); Cypress.Commands.add('error', (message, file) => { - cy.now('task', 'test_observability_log', { - level: 'error', - message, - file, - }).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + level: 'error', + message, + file, + }, + options: { log: false } }); }); Cypress.Commands.add('fatal', (message, file) => { - cy.now('task', 'test_observability_log', { - level: 'fatal', - message, - file, - }).then((res) => { - }).catch((err) => { + eventsQueue.push({ + task: 'test_observability_log', + data: { + level: 'fatal', + message, + file, + }, + options: { log: false } }); }); + +beforeEach(() => { + /* browserstack internal helper hook */ + + if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) { + return; + } + + if (eventsQueue.length > 0) { + eventsQueue.forEach(event => { + cy.task(event.task, event.data, event.options); + }); + } + eventsQueue = []; + testRunStarted = true; +}); + +afterEach(function() { + /* browserstack internal helper hook */ + if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) { + return; + } + + if (eventsQueue.length > 0) { + eventsQueue.forEach(event => { + cy.task(event.task, event.data, event.options); + }); + } + + eventsQueue = []; + testRunStarted = false; +}); diff --git a/bin/testObservability/helper/cleanupQueueSync.js b/bin/testObservability/helper/cleanupQueueSync.js index aa2603f4..3cf76c10 100644 --- a/bin/testObservability/helper/cleanupQueueSync.js +++ b/bin/testObservability/helper/cleanupQueueSync.js @@ -2,10 +2,9 @@ * Sending all the remaining queues for synchronous manner */ -const RequestQueueHandler = require('./requestQueueHandler'); +const requestHandler = require('./requestQueueHandler'); const shutdown = async () => { - const requestHandler = new RequestQueueHandler(); requestHandler.queue = require(process.argv[2].trim()); await requestHandler.shutdown(); } diff --git a/bin/testObservability/helper/helper.js b/bin/testObservability/helper/helper.js index 467f090c..2b253416 100644 --- a/bin/testObservability/helper/helper.js +++ b/bin/testObservability/helper/helper.js @@ -117,6 +117,7 @@ exports.printBuildLink = async (shouldStopSession, exitCode = null) => { } const nodeRequest = (type, url, data, config) => { + const requestQueueHandler = require('./requestQueueHandler'); return new Promise(async (resolve, reject) => { const options = { ...config, @@ -140,8 +141,8 @@ const nodeRequest = (type, url, data, config) => { options.proxy = false options.httpsAgent = new HttpsProxyAgent(process.env.HTTPS_PROXY); } - - if(url === exports.requestQueueHandler.screenshotEventUrl) { + + if(url === requestQueueHandler.screenshotEventUrl) { options.agent = httpsScreenshotsKeepAliveAgent; } axios(options) @@ -521,10 +522,8 @@ exports.batchAndPostEvents = async (eventUrl, kind, data) => { } } -const RequestQueueHandler = require('./requestQueueHandler'); -exports.requestQueueHandler = new RequestQueueHandler(); - exports.uploadEventData = async (eventData, run=0) => { + const requestQueueHandler = require('./requestQueueHandler'); exports.debugOnConsole(`[uploadEventData] ${eventData.event_type}`); const log_tag = { ['TestRunStarted']: 'Test_Start_Upload', @@ -550,8 +549,8 @@ exports.uploadEventData = async (eventData, run=0) => { } else { let data = eventData, event_api_url = 'api/v1/event'; - exports.requestQueueHandler.start(); - const { shouldProceed, proceedWithData, proceedWithUrl } = exports.requestQueueHandler.add(eventData); + requestQueueHandler.start(); + const { shouldProceed, proceedWithData, proceedWithUrl } = requestQueueHandler.add(eventData); exports.debugOnConsole(`[Request Queue] ${eventData.event_type} with uuid ${eventData.test_run ? eventData.test_run.uuid : (eventData.hook_run ? eventData.hook_run.uuid : null)} is added`) if(!shouldProceed) { return; @@ -576,7 +575,7 @@ exports.uploadEventData = async (eventData, run=0) => { if(response.data.error) { throw({message: response.data.error}); } else { - exports.debug(`${event_api_url !== exports.requestQueueHandler.eventUrl ? log_tag : 'Batch-Queue'}[${run}] event successfull!`) + exports.debug(`${event_api_url !== requestQueueHandler.eventUrl ? log_tag : 'Batch-Queue'}[${run}] event successfull!`) exports.pending_test_uploads.count = Math.max(0,exports.pending_test_uploads.count - (event_api_url === 'api/v1/event' ? 1 : data.length)); return { status: 'success', @@ -586,9 +585,9 @@ exports.uploadEventData = async (eventData, run=0) => { } catch(error) { exports.debugOnConsole(`[Request Error] Error in sending request ${util.format(error)}`); if (error.response) { - exports.debug(`EXCEPTION IN ${event_api_url !== exports.requestQueueHandler.eventUrl ? log_tag : 'Batch-Queue'} REQUEST TO TEST OBSERVABILITY : ${error.response.status} ${error.response.statusText} ${JSON.stringify(error.response.data)}`, true, error); + exports.debug(`EXCEPTION IN ${event_api_url !== requestQueueHandler.eventUrl ? log_tag : 'Batch-Queue'} REQUEST TO TEST OBSERVABILITY : ${error.response.status} ${error.response.statusText} ${JSON.stringify(error.response.data)}`, true, error); } else { - exports.debug(`EXCEPTION IN ${event_api_url !== exports.requestQueueHandler.eventUrl ? log_tag : 'Batch-Queue'} REQUEST TO TEST OBSERVABILITY : ${error.message || error}`, true, error); + exports.debug(`EXCEPTION IN ${event_api_url !== requestQueueHandler.eventUrl ? log_tag : 'Batch-Queue'} REQUEST TO TEST OBSERVABILITY : ${error.message || error}`, true, error); } exports.pending_test_uploads.count = Math.max(0,exports.pending_test_uploads.count - (event_api_url === 'api/v1/event' ? 1 : data.length)); return { diff --git a/bin/testObservability/helper/requestQueueHandler.js b/bin/testObservability/helper/requestQueueHandler.js index 424e1a20..245a4bd8 100644 --- a/bin/testObservability/helper/requestQueueHandler.js +++ b/bin/testObservability/helper/requestQueueHandler.js @@ -98,4 +98,4 @@ class RequestQueueHandler { } } -module.exports = RequestQueueHandler; +module.exports = new RequestQueueHandler(); diff --git a/bin/testObservability/plugin/index.js b/bin/testObservability/plugin/index.js index 6880eb75..d32ade0d 100644 --- a/bin/testObservability/plugin/index.js +++ b/bin/testObservability/plugin/index.js @@ -3,6 +3,12 @@ const { connectIPCClient } = require('./ipcClient'); const { IPC_EVENTS } = require('../helper/constants'); const browserstackTestObservabilityPlugin = (on, config, callbacks) => { + + try { + config.env.BROWSERSTACK_O11Y_LOGS = 'true'; + process.env.BROWSERSTACK_O11Y_LOGS = 'true'; + } catch (err) {} + connectIPCClient(config); on('task', { diff --git a/bin/testObservability/plugin/ipcServer.js b/bin/testObservability/plugin/ipcServer.js index 62e84394..9ac1b398 100644 --- a/bin/testObservability/plugin/ipcServer.js +++ b/bin/testObservability/plugin/ipcServer.js @@ -1,6 +1,6 @@ const ipc = require('node-ipc'); const { consoleHolder } = require('../helper/constants'); -const { requestQueueHandler } = require('../helper/helper'); +const requestQueueHandler = require('../helper/requestQueueHandler'); exports.startIPCServer = (subscribeServerEvents, unsubscribeServerEvents) => { if (ipc.server) { diff --git a/bin/testObservability/reporter/index.js b/bin/testObservability/reporter/index.js index 396ad0e3..9e18b4df 100644 --- a/bin/testObservability/reporter/index.js +++ b/bin/testObservability/reporter/index.js @@ -52,7 +52,6 @@ const { mapTestHooks, debug, isBrowserstackInfra, - requestQueueHandler, getHookSkippedTests, getOSDetailsFromSystem, findGitConfig, @@ -88,6 +87,7 @@ class MyReporter { }) .on(EVENT_HOOK_BEGIN, async (hook) => { + if (this.isInternalHook(hook)) return; debugOnConsole(`[MOCHA EVENT] EVENT_HOOK_BEGIN`); if(this.testObservability == true) { if(!hook.hookAnalyticsId) { @@ -105,6 +105,7 @@ class MyReporter { }) .on(EVENT_HOOK_END, async (hook) => { + if (this.isInternalHook(hook)) return; debugOnConsole(`[MOCHA EVENT] EVENT_HOOK_END`); if(this.testObservability == true) { if(!this.runStatusMarkedHash[hook.hookAnalyticsId]) { @@ -206,6 +207,13 @@ class MyReporter { }); } + isInternalHook(hook) { + if (hook && hook.body && hook.body.includes('/* browserstack internal helper hook */')) { + return true; + } + return false; + } + registerListeners() { startIPCServer( (server) => { @@ -247,7 +255,7 @@ class MyReporter { } } - uploadTestSteps = async (shouldClearCurrentSteps = true, cypressSteps = null) => { + uploadTestSteps = async (shouldClearCurrentSteps = true, cypressSteps = null) => { const currentTestSteps = cypressSteps ? cypressSteps : JSON.parse(JSON.stringify(this.currentTestSteps)); /* TODO - Send as test logs */ const allStepsAsLogs = []; @@ -518,7 +526,7 @@ class MyReporter { cypressConfigListener = async (config) => { } - cypressCucumberStepListener = async ({log}) => { + cypressCucumberStepListener = async ({log, started_at, finished_at}) => { if(log.name == 'step' && log.consoleProps && log.consoleProps.step && log.consoleProps.step.keyword) { this.currentTestCucumberSteps = [ ...this.currentTestCucumberSteps, @@ -526,8 +534,8 @@ class MyReporter { id: log.chainerId, keyword: log.consoleProps.step.keyword, text: log.consoleProps.step.text, - started_at: new Date().toISOString(), - finished_at: new Date().toISOString(), + started_at: started_at || new Date().toISOString(), + finished_at: finished_at || new Date().toISOString(), duration: 0, result: 'passed' } @@ -537,8 +545,8 @@ class MyReporter { if(gherkinStep.id == log.chainerId) { this.currentTestCucumberSteps[idx] = { ...gherkinStep, - finished_at: new Date().toISOString(), - duration: Date.now() - (new Date(gherkinStep.started_at)).getTime(), + finished_at: finished_at || new Date().toISOString(), + duration: (finished_at ? new Date(finished_at).getTime() : Date.now()) - (new Date(gherkinStep.started_at)).getTime(), result: log.state, failure: log.err?.stack || log.err?.message, failure_reason: log.err?.stack || log.err?.message, @@ -549,9 +557,9 @@ class MyReporter { } } - cypressLogListener = async ({level, message, file}) => { + cypressLogListener = async ({timestamp, level, message}) => { this.appendTestItemLog({ - timestamp: new Date().toISOString(), + timestamp: timestamp || new Date().toISOString(), level: level.toUpperCase(), message, kind: 'TEST_LOG', @@ -612,12 +620,12 @@ class MyReporter { const currentStepObj = { id: command.attributes.id, text: 'cy.' + command.attributes.name + '(' + this.getFormattedArgs(command.attributes.args) + ')', - started_at: new Date().toISOString(), + started_at: command.started_at || new Date().toISOString(), finished_at: null, duration: null, result: 'pending', - test_run_uuid: this.current_test?.testAnalyticsId && !this.runStatusMarkedHash[this.current_test.testAnalyticsId] ? this.current_test.testAnalyticsId : null, - hook_run_uuid : this.current_hook?.hookAnalyticsId && !this.runStatusMarkedHash[this.current_hook.hookAnalyticsId] ? this.current_hook.hookAnalyticsId : null + test_run_uuid: command.location === 'test' ? this.current_test?.testAnalyticsId : null, + hook_run_uuid : command.location === 'hook' ? this.current_hook?.hookAnalyticsId : null }; if(currentStepObj.hook_run_uuid && currentStepObj.test_run_uuid) delete currentStepObj.test_run_uuid; this.currentTestSteps = [ @@ -630,8 +638,8 @@ class MyReporter { if(val.id == command.attributes.id) { this.currentTestSteps[idx] = { ...val, - finished_at: new Date().toISOString(), - duration: Date.now() - (new Date(val.started_at)).getTime(), + finished_at: command.finished_at || new Date().toISOString(), + duration: (command.finished_at ? new Date(command.finished_at).getTime() : Date.now()) - (new Date(val.started_at)).getTime(), result: command.state }; stepUpdated = true; @@ -647,8 +655,8 @@ class MyReporter { finished_at: new Date().toISOString(), duration: 0, result: command.state, - test_run_uuid: this.current_test?.testAnalyticsId && !this.runStatusMarkedHash[this.current_test.testAnalyticsId] ? this.current_test.testAnalyticsId : null, - hook_run_uuid : this.current_hook?.hookAnalyticsId && !this.runStatusMarkedHash[this.current_hook.hookAnalyticsId] ? this.current_hook.hookAnalyticsId : null + test_run_uuid: command.location === 'test' ? this.current_test?.testAnalyticsId : null, + hook_run_uuid : command.location === 'hook' ? this.current_hook?.hookAnalyticsId : null }; if(currentStepObj.hook_run_uuid && currentStepObj.test_run_uuid) delete currentStepObj.test_run_uuid; this.currentTestSteps = [