diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index 7c11ae10..1227c38b 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -50,7 +50,9 @@ 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)))); + /* test_observability_batch must be filtered here too, or each batch dispatch would + * itself be captured as a command event and refill the queue. [SDK-7399] */ + return command.attributes.name == 'log' || (command.attributes.name == 'task' && (['test_observability_platform_details', 'test_observability_step', 'test_observability_command', 'test_observability_batch', 'browserstack_log', 'test_observability_log'].some(event => command.attributes.args.includes(event)))); } Cypress.on('log:changed', (attrs) => { @@ -339,6 +341,94 @@ Cypress.Commands.add('fatal', (message, file) => { }); }); +/* console.warn, not browserStackLog/cy.task — routing a diagnostic through another + * Cypress command would reintroduce the failure this boundary contains. [SDK-7399] */ +const warnFlushFailure = (stage, err) => { + try { + console.warn(`BrowserStack Test Observability: suppressed ${stage} error, event(s) dropped: ${err && err.message ? err.message : err}`); + } catch (e) { /* logging must never throw either */ } +}; + +/* + * [SDK-7399] Send the whole drain as ONE cy.task instead of one cy.task per event. + * + * Each cy.task round-trip costs roughly 0.8s on a remote terminal. Measured there, with + * N events queued per afterEach: N=10 -> 114s, N=100 -> 581s, N=1000 -> the session was + * killed. A command-heavy test queues hundreds of events, so the old per-event flush ran + * for minutes inside the hook, the spec exceeded spec_timeout, and every test that had not + * run yet was reported as SKIPPED. Nothing throws in that failure — build-info on a + * reproducing build shows failed:0 with the sessions killed at the timeout. Locally the + * same dispatch is effectively free, which is why local runs never reproduced it. + * + * Batching is what fixes it: the same 600 events sent as one call took 109s versus 581s. + * + * Dispatch deliberately stays on cy.task. cy.now('task', ...) throws on Cypress 14 in + * every context — test body, hook and listener — so using it stops the skipping only by + * never delivering anything, which silently empties the dashboard. + * + * The try/catch here is a backstop for anything raised synchronously while building or + * enqueuing. It cannot catch a cy.task failure, which surfaces later while the command + * queue drains — hence fixing the cost rather than trying to contain the symptom. + */ + +/* Split each batch under the ~1MB per-cy.task ceiling measured on a remote terminal + * (768KB succeeds, 1MB fails), so a large flush is split rather than lost. */ +const MAX_BATCH_CHARS = 512 * 1024; + +const flushEventsQueue = () => { + try { + const queued = eventsQueue; + eventsQueue = []; /* cleared before dispatch so a throw cannot replay these events */ + if (queued.length === 0) return; + + let batch = []; + let batchChars = 0; + + const sendBatch = () => { + if (batch.length === 0) return; + const toSend = batch; + batch = []; + batchChars = 0; + try { + cy.task('test_observability_batch', toSend, { log: false }); + } catch (e) { + warnFlushFailure(`batch dispatch of ${toSend.length} event(s)`, e); + } + }; + + queued.forEach(event => { + try { + const payload = sanitizeForTask(event.data); + if (payload === null) { + warnFlushFailure(`unserializable payload for '${event.task}'`, + new Error('event skipped')); + return; + } + const size = JSON.stringify(payload).length; + if (size > MAX_BATCH_CHARS) { + /* A single event this large cannot be sent under the ~1MB per-cy.task ceiling + * measured on a remote terminal (768KB passes, 1MB fails). Dropping it is not a + * fidelity regression: before batching it was dispatched alone and would have + * failed the command anyway. Nothing smaller is altered or truncated. */ + warnFlushFailure(`event too large to send for '${event.task}' (${size} chars)`, + new Error('event skipped')); + return; + } + if (batchChars + size > MAX_BATCH_CHARS) sendBatch(); + batch.push({ task: event.task, data: payload }); + batchChars += size; + } catch (e) { + warnFlushFailure(`preparing '${event.task}'`, e); /* skip one event, not the rest */ + } + }); + + sendBatch(); + } catch (e) { + warnFlushFailure('queue flush', e); + eventsQueue = []; + } +}; + beforeEach(() => { /* browserstack internal helper hook */ @@ -346,13 +436,7 @@ beforeEach(() => { return; } - if (eventsQueue.length > 0) { - eventsQueue.forEach(event => { - const payload = sanitizeForTask(event.data); - if (payload !== null) cy.task(event.task, payload, event.options); - }); - } - eventsQueue = []; + flushEventsQueue(); testRunStarted = true; }); @@ -362,13 +446,6 @@ afterEach(function() { return; } - if (eventsQueue.length > 0) { - eventsQueue.forEach(event => { - const payload = sanitizeForTask(event.data); - if (payload !== null) cy.task(event.task, payload, event.options); - }); - } - - eventsQueue = []; + flushEventsQueue(); testRunStarted = false; }); diff --git a/bin/testObservability/plugin/index.js b/bin/testObservability/plugin/index.js index d32ade0d..f13d012b 100644 --- a/bin/testObservability/plugin/index.js +++ b/bin/testObservability/plugin/index.js @@ -11,6 +11,13 @@ const browserstackTestObservabilityPlugin = (on, config, callbacks) => { connectIPCClient(config); + const IPC_EVENT_FOR_TASK = { + test_observability_log: IPC_EVENTS.LOG, + test_observability_command: IPC_EVENTS.COMMAND, + test_observability_platform_details: IPC_EVENTS.PLATFORM_DETAILS, + test_observability_step: IPC_EVENTS.CUCUMBER, + }; + on('task', { test_observability_log(log) { ipc.of.browserstackTestObservability.emit(IPC_EVENTS.LOG, log); @@ -27,6 +34,29 @@ const browserstackTestObservabilityPlugin = (on, config, callbacks) => { test_observability_step(log) { ipc.of.browserstackTestObservability.emit(IPC_EVENTS.CUCUMBER, log); return null; + }, + /* + * [SDK-7399] Accepts a whole flush as ONE task so the browser side issues one + * Cypress command per flush instead of one per event. Each cy.task round-trip costs + * roughly 0.8s on a remote terminal, so a command-heavy test used to spend minutes + * in its afterEach and the spec was killed at spec_timeout, reporting every test that + * had not run yet as skipped. Measured: 600 events as 600 calls = 581s; the same 600 + * events as 1 call = 109s, i.e. baseline. + * Fans out to exactly the same IPC events as the individual tasks above, which stay + * registered for backward compatibility. + */ + test_observability_batch(events) { + if (!Array.isArray(events)) return null; + events.forEach((event) => { + try { + const ipcEvent = event && IPC_EVENT_FOR_TASK[event.task]; + if (!ipcEvent) return; + ipc.of.browserstackTestObservability.emit(ipcEvent, event.data); + } catch (e) { + /* one malformed event must not drop the rest of the batch */ + } + }); + return null; } });