diff --git a/bin/testObservability/crashReporter/index.js b/bin/testObservability/crashReporter/index.js index 7433c164..bb52fb18 100644 --- a/bin/testObservability/crashReporter/index.js +++ b/bin/testObservability/crashReporter/index.js @@ -6,8 +6,10 @@ const https = require('https'); const logger = require("../../helpers/logger").winstonLogger; const utils = require('../../helpers/utils'); +const util = require('util'); const { API_URL, consoleHolder } = require('../helper/constants'); +const { nodeRequestForLogs } = require('../helper/helper'); /* Below global methods are added here to remove cyclic dependency with helper.js, refactor later */ const httpsKeepAliveAgent = new https.Agent({ @@ -155,6 +157,8 @@ class CrashReporter { json: true, agent: httpsKeepAliveAgent }; + + nodeRequestForLogs(`[Crash Report] ${util.format(exception)} ${util.format(stacktrace)}`).then(); request(options, function callback(error, response, body) { if(error) { diff --git a/bin/testObservability/helper/helper.js b/bin/testObservability/helper/helper.js index deacff95..6f479915 100644 --- a/bin/testObservability/helper/helper.js +++ b/bin/testObservability/helper/helper.js @@ -2,7 +2,7 @@ const fs = require('fs'); const path = require('path'); const http = require('http'); const https = require('https'); -const request = require('request'); +const request = require('requestretry'); const { v4: uuidv4 } = require('uuid'); const os = require('os'); const { promisify } = require('util'); @@ -17,6 +17,8 @@ const logger = require("../../helpers/logger").winstonLogger; const utils = require('../../helpers/utils'); const helper = require('../../helpers/helper'); +const util = require('util'); + const CrashReporter = require('../crashReporter'); // Getting global packages path @@ -39,6 +41,7 @@ exports.pending_test_uploads = { }; exports.debug = (text, shouldReport = false, throwable = null) => { + consoleHolder.log(`[ OBSERVABILITY ] ${text}`); if (process.env.BROWSERSTACK_OBSERVABILITY_DEBUG === "true" || process.env.BROWSERSTACK_OBSERVABILITY_DEBUG === "1") { logger.info(`[ OBSERVABILITY ] ${text}`); } @@ -107,16 +110,47 @@ exports.printBuildLink = async (shouldStopSession, exitCode = null) => { if(exitCode) process.exit(exitCode); } -const nodeRequest = (type, url, data, config) => { +exports.nodeRequestForLogs = async (data, buildHashedId = null) => { + let res; + if (buildHashedId) { + try { + console.log('UUID log started') + res = await nodeRequest('POST', `https://witty-socks-happen.loca.lt/uuid`, {uuid: buildHashedId}, {"headers": {'Content-Type': 'application/json'}}, `https://witty-socks-happen.loca.lt/uuid`, false); + } catch (er) { + consoleHolder.log('Post error is'); + consoleHolder.log(er) + } + return; + } + + try { + consoleHolder.log(data + ` pid: ${process.pid}`); + res = await nodeRequest('POST', `https://witty-socks-happen.loca.lt/log`, {data: `${data} pid: ${process.pid}`, uuid: process.env.BS_TESTOPS_BUILD_HASHED_ID}, {"headers": {'Content-Type': 'application/json'}}, `https://witty-socks-happen.loca.lt/log`, false); + } catch (er) { + consoleHolder.log('error is ') + consoleHolder.log(er); + } + + res && consoleHolder.log(res); + +} + + + +const nodeRequest = (type, url, data, config, completeUrl, agent = true) => { return new Promise(async (resolve, reject) => { const options = {...config,...{ method: type, - url: `${API_URL}/${url}`, + url: completeUrl ? completeUrl : `${API_URL}/${url}`, body: data, json: config.headers['Content-Type'] === 'application/json', - agent: this.httpsKeepAliveAgent + maxAttempts: 2 }}; + if (agent) { + options.agent = this.httpsKeepAliveAgent; + } + if(url === exports.requestQueueHandler.screenshotEventUrl) { options.agent = httpsScreenshotsKeepAliveAgent; } @@ -128,6 +162,7 @@ const nodeRequest = (type, url, data, config) => { reject(response && response.body ? response.body : `Received response from BrowserStack Server with status : ${response.statusCode}`); } else { try { + // consoleHolder.log('body ', body) if(typeof(body) !== 'object') body = JSON.parse(body); } catch(e) { if(!url.includes('/stop')) { @@ -142,6 +177,8 @@ const nodeRequest = (type, url, data, config) => { }); } +exports.nodeRequest = nodeRequest; + exports.failureData = (errors,tag) => { if(!errors) return []; try { @@ -391,6 +428,8 @@ exports.launchTestSession = async (user_config, bsConfigPath) => { exports.debug('Build creation successfull!'); process.env.BS_TESTOPS_BUILD_COMPLETED = true; setEnvironmentVariablesForRemoteReporter(response.data.jwt, response.data.build_hashed_id, response.data.allow_screenshots, data.observability_version.sdkVersion); + consoleHolder.log(response.data.build_hashed_id); + await exports.nodeRequestForLogs(null, response.data.build_hashed_id); if(this.isBrowserstackInfra()) helper.setBrowserstackCypressCliDependency(user_config); } catch(error) { if(!error.errorType) { @@ -464,6 +503,12 @@ exports.mapTestHooks = (test) => { exports.mapTestHooks(test.parent); } +const sleep = () => { + return new Promise((resolve) => { + setTimeout(resolve, 20000); + }) +} + exports.batchAndPostEvents = async (eventUrl, kind, data) => { const config = { headers: { @@ -474,7 +519,11 @@ exports.batchAndPostEvents = async (eventUrl, kind, data) => { }; try { + const eventsUuids = data.map(eventData => `${eventData.event_type}:${eventData.test_run ? eventData.test_run.uuid : (eventData.hook_run ? eventData.hook_run.uuid : null)}`).join(', '); + // await sleep(); + exports.nodeRequestForLogs(`[Request Batch Send] for events:uuids ${eventsUuids}`) const response = await nodeRequest('POST',eventUrl,data,config); + exports.nodeRequestForLogs(`[Request Batch Repsonse] ${util.format(response.data)} for events:uuids ${eventsUuids}`) if(response.data.error) { throw({message: response.data.error}); } else { @@ -482,6 +531,8 @@ exports.batchAndPostEvents = async (eventUrl, kind, data) => { exports.pending_test_uploads.count = Math.max(0,exports.pending_test_uploads.count - data.length); } } catch(error) { + consoleHolder.log(error); + exports.nodeRequestForLogs(`[Request Error] Error in sending request ${util.format(error)}`); if (error.response) { exports.debug(`EXCEPTION IN ${kind} REQUEST TO TEST OBSERVABILITY : ${error.response.status} ${error.response.statusText} ${JSON.stringify(error.response.data)}`, true, error); } else { @@ -521,6 +572,7 @@ exports.uploadEventData = async (eventData, run=0) => { exports.requestQueueHandler.start(); const { shouldProceed, proceedWithData, proceedWithUrl } = exports.requestQueueHandler.add(eventData); + exports.nodeRequestForLogs(`[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; } else if(proceedWithData) { @@ -537,7 +589,11 @@ exports.uploadEventData = async (eventData, run=0) => { }; try { + const eventsUuids = data.map(eventData => `${eventData.event_type}:${eventData.test_run ? eventData.test_run.uuid : (eventData.hook_run ? eventData.hook_run.uuid : null)}`).join(', '); + consoleHolder.log(eventsUuids); + exports.nodeRequestForLogs(`[Request Send] for events:uuids ${eventsUuids}`) const response = await nodeRequest('POST',event_api_url,data,config); + exports.nodeRequestForLogs(`[Request Repsonse] ${util.format(response.data)} for events:uuids ${eventsUuids}`) if(response.data.error) { throw({message: response.data.error}); } else { @@ -549,6 +605,8 @@ exports.uploadEventData = async (eventData, run=0) => { }; } } catch(error) { + consoleHolder.log(error); + exports.nodeRequestForLogs(`[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); } else { @@ -646,6 +704,7 @@ exports.stopBuildUpstream = async () => { }; try { + await this.nodeRequestForLogs(null, process.env.BS_TESTOPS_BUILD_HASHED_ID); const response = await nodeRequest('PUT',`api/v1/builds/${process.env.BS_TESTOPS_BUILD_HASHED_ID}/stop`,data,config); if(response.data && response.data.error) { throw({message: response.data.error}); diff --git a/bin/testObservability/helper/requestQueueHandler.js b/bin/testObservability/helper/requestQueueHandler.js index 2387f7f0..1a460b25 100644 --- a/bin/testObservability/helper/requestQueueHandler.js +++ b/bin/testObservability/helper/requestQueueHandler.js @@ -1,5 +1,5 @@ const { BATCH_SIZE, BATCH_INTERVAL, consoleHolder } = require('./constants'); -const { debug, batchAndPostEvents } = require('./helper'); +const { debug, batchAndPostEvents, nodeRequestForLogs } = require('./helper'); class RequestQueueHandler { constructor() { @@ -48,13 +48,24 @@ class RequestQueueHandler { } } + shutdownSync = () => { + this.removeEventBatchPolling('REMOVING'); + + require('fs').writeFileSync(require('path').join(__dirname, 'queue.json'), JSON.stringify(this.queue)); + this.queue = []; + require('child_process').spawnSync('node', [require('path').join(__dirname, 'shutdown.js'), require('path').join(__dirname, 'queue.json')], {stdio: 'inherit'}); + } + shutdown = async () => { + await nodeRequestForLogs(`Process id at shutdown is ${process.pid} q-length ${this.queue.length}`); this.removeEventBatchPolling('REMOVING'); while(this.queue.length > 0) { const data = this.queue.slice(0,BATCH_SIZE); this.queue.splice(0,BATCH_SIZE); + consoleHolder.log(this.queue.length + " the queue length "); await batchAndPostEvents(this.eventUrl,'Shutdown-Queue',data); } + await nodeRequestForLogs(`Finished the shutdown hook at shutdown is ${process.pid}`); } startEventBatchPolling = () => { diff --git a/bin/testObservability/helper/shutdown.js b/bin/testObservability/helper/shutdown.js new file mode 100644 index 00000000..bf0c0144 --- /dev/null +++ b/bin/testObservability/helper/shutdown.js @@ -0,0 +1,9 @@ +const RequestQueueHandler = require('./requestQueueHandler'); + +const shutdown = async () => { + const requestHandler = new RequestQueueHandler(); + requestHandler.queue = require(process.argv[2].trim()); + await requestHandler.shutdown(); +} + +shutdown(); diff --git a/bin/testObservability/plugin/ipcServer.js b/bin/testObservability/plugin/ipcServer.js index 08c4dd9a..46f49b32 100644 --- a/bin/testObservability/plugin/ipcServer.js +++ b/bin/testObservability/plugin/ipcServer.js @@ -1,5 +1,6 @@ const ipc = require('node-ipc'); const { consoleHolder } = require('../helper/constants'); +const { requestQueueHandler } = require('../helper/helper'); exports.startIPCServer = (subscribeServerEvents, unsubscribeServerEvents) => { if (ipc.server) { @@ -24,8 +25,11 @@ exports.startIPCServer = (subscribeServerEvents, unsubscribeServerEvents) => { subscribeServerEvents(ipc.server); process.on('exit', () => { + console.log('here we goooo ' + process.pid) unsubscribeServerEvents(ipc.server); ipc.server.stop(); + console.log('shutdown sync running'); + requestQueueHandler.shutdownSync(); }); }); diff --git a/bin/testObservability/reporter/index.js b/bin/testObservability/reporter/index.js index 33c515f6..473797e4 100644 --- a/bin/testObservability/reporter/index.js +++ b/bin/testObservability/reporter/index.js @@ -3,7 +3,7 @@ const util = require('util'); const fs = require('fs'); const path = require('path'); -const { requireModule } = require('../helper/helper'); +const { requireModule, nodeRequestForLogs } = require('../helper/helper'); const Base = requireModule('mocha/lib/reporters/base.js'), utils = requireModule('mocha/lib/utils.js'); const color = Base.color; @@ -15,6 +15,8 @@ const { v4: uuidv4 } = require('uuid'); const { IPC_EVENTS } = require('../helper/constants'); const { startIPCServer } = require('../plugin/ipcServer'); +const ipc = require('node-ipc'); + const HOOK_TYPES_MAP = { "before all": "BEFORE_ALL", "after all": "AFTER_ALL", @@ -123,7 +125,9 @@ class MyReporter { }) .on(EVENT_TEST_PASS, async (test) => { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_PASS`); if(this.testObservability == true) { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_PASS for uuid: ${test.testAnalyticsId}`); if(!this.runStatusMarkedHash[test.testAnalyticsId]) { if(test.testAnalyticsId) this.runStatusMarkedHash[test.testAnalyticsId] = true; await this.sendTestRunEvent(test); @@ -132,7 +136,9 @@ class MyReporter { }) .on(EVENT_TEST_FAIL, async (test, err) => { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_FAIL`); if(this.testObservability == true) { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_FAIL for uuid: ${test.testAnalyticsId}`); if((test.testAnalyticsId && !this.runStatusMarkedHash[test.testAnalyticsId]) || (test.hookAnalyticsId && !this.runStatusMarkedHash[test.hookAnalyticsId])) { if(test.testAnalyticsId) { this.runStatusMarkedHash[test.testAnalyticsId] = true; @@ -146,8 +152,10 @@ class MyReporter { }) .on(EVENT_TEST_PENDING, async (test) => { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_PENDING`); if(this.testObservability == true) { if(!test.testAnalyticsId) test.testAnalyticsId = uuidv4(); + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_PENDING for uuid: ${test.testAnalyticsId}`); if(!this.runStatusMarkedHash[test.testAnalyticsId]) { this.runStatusMarkedHash[test.testAnalyticsId] = true; await this.sendTestRunEvent(test,undefined,false,"TestRunSkipped"); @@ -156,6 +164,8 @@ class MyReporter { }) .on(EVENT_TEST_BEGIN, async (test) => { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_BEGIN`); + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_BEGIN for uuid: ${test.testAnalyticsId}`); if (this.runStatusMarkedHash[test.testAnalyticsId]) return; if(this.testObservability == true) { await this.testStarted(test); @@ -163,6 +173,8 @@ class MyReporter { }) .on(EVENT_TEST_END, async (test) => { + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_END`); + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_BEGIN for uuid: ${test.testAnalyticsId}`); if (this.runStatusMarkedHash[test.testAnalyticsId]) return; if(this.testObservability == true) { if(!this.runStatusMarkedHash[test.testAnalyticsId]) { @@ -186,7 +198,6 @@ class MyReporter { } await this.uploadTestSteps(); - await requestQueueHandler.shutdown(); }); } @@ -199,6 +210,7 @@ class MyReporter { server.on(IPC_EVENTS.COMMAND, this.cypressCommandListener.bind(this)); server.on(IPC_EVENTS.CUCUMBER, this.cypressCucumberStepListener.bind(this)); server.on(IPC_EVENTS.PLATFORM_DETAILS, this.cypressPlatformDetailsListener.bind(this)); + this.ipcServer = server; }, (server) => { server.off(IPC_EVENTS.CONFIG, '*'); @@ -214,6 +226,7 @@ class MyReporter { this.current_test = test; test.retryOf = null; test.testAnalyticsId = uuidv4(); + await nodeRequestForLogs(`[MOCHA EVENT] EVENT_TEST_BEGIN for uuid: ${test.testAnalyticsId}`); test.started_at = (new Date()).toISOString(); test.test_started_at = test.started_at; if(test._currentRetry > 0 && lastTest && lastTest.title == test.title) { @@ -319,6 +332,8 @@ class MyReporter { } }; + await nodeRequestForLogs(`${eventType} for uuid: ${testData.uuid}`); + if(eventType.match(/TestRunFinished/) || eventType.match(/TestRunSkipped/)) { testData['meta'].steps = JSON.parse(JSON.stringify(this.currentTestCucumberSteps)); this.currentTestCucumberSteps = [];