From 6e5aaf5dc03120f94aca594a2076d8aa53590148 Mon Sep 17 00:00:00 2001 From: Anish Sinha Date: Mon, 4 May 2026 16:27:01 +0530 Subject: [PATCH 1/5] capture cy.log at enqueue time so logs survive sync test failures --- bin/testObservability/cypress/index.js | 19 ++++++++++++++++--- 1 file changed, 16 insertions(+), 3 deletions(-) diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index dfdc27e2..f8a1e8ff 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -201,24 +201,37 @@ Cypress.on('command:end', (command) => { }); }); -Cypress.Commands.overwrite('log', (originalFn, ...args) => { +/* + * cy.log capture must happen at command-enqueue time, not command-execute time. + * If a test body throws synchronously (e.g. a failing chai assertion) before the + * Cypress queue drains, queued commands are dropped — so an execute-time wrapper + * never fires and pre-throw cy.log calls are lost from the timeline. Hooking + * command:enqueue runs synchronously at the user's cy.log() call site. + */ +Cypress.on('command:enqueue', (attrs) => { + if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) return; + if (!attrs || attrs.name !== 'log') return; + const args = attrs.args || []; 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(' '); } - return [result, logItem ? logItem.toString() : ''].join(' '); }, ''); eventsQueue.push({ task: 'test_observability_log', data: { - 'level': 'info', + level: 'info', message, timestamp: new Date().toISOString() }, options: { log: false } }); +}); + +Cypress.Commands.overwrite('log', (originalFn, ...args) => { + if (args.includes('test_observability_log') || args.includes('test_observability_command')) return; originalFn(...args); }); From 0fb6a7c95f8cad0a4e3c7e9589cb0b40b058d581 Mon Sep 17 00:00:00 2001 From: Anish Sinha Date: Tue, 5 May 2026 10:43:11 +0530 Subject: [PATCH 2/5] correct command:enqueued event name --- bin/testObservability/cypress/index.js | 6 +++--- bin/testObservability/reporter/index.js | 16 +++++++++++++++- 2 files changed, 18 insertions(+), 4 deletions(-) diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index f8a1e8ff..05b9431b 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -205,10 +205,10 @@ Cypress.on('command:end', (command) => { * cy.log capture must happen at command-enqueue time, not command-execute time. * If a test body throws synchronously (e.g. a failing chai assertion) before the * Cypress queue drains, queued commands are dropped — so an execute-time wrapper - * never fires and pre-throw cy.log calls are lost from the timeline. Hooking - * command:enqueue runs synchronously at the user's cy.log() call site. + * never fires and pre-throw cy.log calls are lost from the timeline. The + * command:enqueued event runs synchronously at the user's cy.log() call site. */ -Cypress.on('command:enqueue', (attrs) => { +Cypress.on('command:enqueued', (attrs) => { if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) return; if (!attrs || attrs.name !== 'log') return; const args = attrs.args || []; diff --git a/bin/testObservability/reporter/index.js b/bin/testObservability/reporter/index.js index 4a6c04b8..f2361a39 100644 --- a/bin/testObservability/reporter/index.js +++ b/bin/testObservability/reporter/index.js @@ -628,10 +628,24 @@ class MyReporter { appendTestItemLog = async (log) => { try { + /* + * SDK-5709: keep the hash gate on hook side (avoids attributing a log to + * a stale hook pointer between hooks). Drop it on the test side. In + * Cypress, EVENT_TEST_FAIL fires synchronously when a test body throws + * — *before* afterEach runs. The SDK's internal afterEach flushes its + * cy.log buffer via cy.task during afterEach, so by the time those logs + * reach this listener, runStatusMarkedHash[testAnalyticsId] is already + * set and the log gets dropped without ever attaching a test_run_uuid. + * Without the gate, the log uploads with test_run_uuid even after + * TestRunFinished — accepted by the analytics backend (uploadTestSteps + * takes the same path with no gate). + */ if(this.current_hook && ( this.current_hook.hookAnalyticsId && !this.runStatusMarkedHash[this.current_hook.hookAnalyticsId] )) { log.hook_run_uuid = this.current_hook.hookAnalyticsId; } - if(!log.hook_run_uuid && this.current_test && ( this.current_test.testAnalyticsId && !this.runStatusMarkedHash[this.current_test.testAnalyticsId] )) log.test_run_uuid = this.current_test.testAnalyticsId; + if(!log.hook_run_uuid && this.current_test && this.current_test.testAnalyticsId) { + log.test_run_uuid = this.current_test.testAnalyticsId; + } if(log.hook_run_uuid || log.test_run_uuid) { await uploadEventData({ event_type: 'LogCreated', From b4cb261ba9c8d7298296d7ef08b6a539dbbbaa51 Mon Sep 17 00:00:00 2001 From: Anish Sinha Date: Tue, 5 May 2026 12:27:33 +0530 Subject: [PATCH 3/5] dispatch cy.log via Cypress.backend, bypassing the queue --- bin/testObservability/cypress/index.js | 25 +++++++++++++++++-------- bin/testObservability/reporter/index.js | 16 +--------------- 2 files changed, 18 insertions(+), 23 deletions(-) diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index 05b9431b..2303a6b5 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -202,11 +202,18 @@ Cypress.on('command:end', (command) => { }); /* - * cy.log capture must happen at command-enqueue time, not command-execute time. - * If a test body throws synchronously (e.g. a failing chai assertion) before the - * Cypress queue drains, queued commands are dropped — so an execute-time wrapper - * never fires and pre-throw cy.log calls are lost from the timeline. The - * command:enqueued event runs synchronously at the user's cy.log() call site. + * cy.log capture must happen at command-enqueue time AND must bypass Cypress's + * test command queue. When a test body throws synchronously (e.g. a failing + * chai assertion), Cypress drops every pending command in the test queue — + * which means an execute-time wrapper on cy.log never runs, and even a + * deferred cy.task(...) inside the SDK's afterEach is just another queued + * command that won't survive the drop. + * + * Cypress.backend('task', ...) emits directly over the runner-to-Node + * websocket (see Cypress driver), bypassing the queue entirely. Combined + * with command:enqueued (which fires synchronously at the user's cy.log() + * call site, before the throw), the log reaches the Node-side task handler + * regardless of whether the test passes or fails. */ Cypress.on('command:enqueued', (attrs) => { if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) return; @@ -219,14 +226,16 @@ Cypress.on('command:enqueued', (attrs) => { } return [result, logItem ? logItem.toString() : ''].join(' '); }, ''); - eventsQueue.push({ + Cypress.backend('task', { task: 'test_observability_log', - data: { + arg: { level: 'info', message, timestamp: new Date().toISOString() }, - options: { log: false } + timeout: 60000 + }).catch(() => { + /* Don't let observability failures bubble into the test */ }); }); diff --git a/bin/testObservability/reporter/index.js b/bin/testObservability/reporter/index.js index f2361a39..4a6c04b8 100644 --- a/bin/testObservability/reporter/index.js +++ b/bin/testObservability/reporter/index.js @@ -628,24 +628,10 @@ class MyReporter { appendTestItemLog = async (log) => { try { - /* - * SDK-5709: keep the hash gate on hook side (avoids attributing a log to - * a stale hook pointer between hooks). Drop it on the test side. In - * Cypress, EVENT_TEST_FAIL fires synchronously when a test body throws - * — *before* afterEach runs. The SDK's internal afterEach flushes its - * cy.log buffer via cy.task during afterEach, so by the time those logs - * reach this listener, runStatusMarkedHash[testAnalyticsId] is already - * set and the log gets dropped without ever attaching a test_run_uuid. - * Without the gate, the log uploads with test_run_uuid even after - * TestRunFinished — accepted by the analytics backend (uploadTestSteps - * takes the same path with no gate). - */ if(this.current_hook && ( this.current_hook.hookAnalyticsId && !this.runStatusMarkedHash[this.current_hook.hookAnalyticsId] )) { log.hook_run_uuid = this.current_hook.hookAnalyticsId; } - if(!log.hook_run_uuid && this.current_test && this.current_test.testAnalyticsId) { - log.test_run_uuid = this.current_test.testAnalyticsId; - } + if(!log.hook_run_uuid && this.current_test && ( this.current_test.testAnalyticsId && !this.runStatusMarkedHash[this.current_test.testAnalyticsId] )) log.test_run_uuid = this.current_test.testAnalyticsId; if(log.hook_run_uuid || log.test_run_uuid) { await uploadEventData({ event_type: 'LogCreated', From edf2e19858e6575498a909a5315212ed6ab1b838 Mon Sep 17 00:00:00 2001 From: Anish Sinha Date: Tue, 5 May 2026 12:45:32 +0530 Subject: [PATCH 4/5] updated code --- bin/testObservability/cypress/index.js | 28 ++++++++++--------------- bin/testObservability/reporter/index.js | 16 +++++++++++++- 2 files changed, 26 insertions(+), 18 deletions(-) diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index 2303a6b5..fc51d540 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -202,18 +202,14 @@ Cypress.on('command:end', (command) => { }); /* - * cy.log capture must happen at command-enqueue time AND must bypass Cypress's - * test command queue. When a test body throws synchronously (e.g. a failing - * chai assertion), Cypress drops every pending command in the test queue — - * which means an execute-time wrapper on cy.log never runs, and even a - * deferred cy.task(...) inside the SDK's afterEach is just another queued - * command that won't survive the drop. - * - * Cypress.backend('task', ...) emits directly over the runner-to-Node - * websocket (see Cypress driver), bypassing the queue entirely. Combined - * with command:enqueued (which fires synchronously at the user's cy.log() - * call site, before the throw), the log reaches the Node-side task handler - * regardless of whether the test passes or fails. + * cy.log capture must happen at command-enqueue time, not at command-execute + * time. When a test body throws synchronously (e.g. a failing chai assertion), + * Cypress drops every pending command in the test queue — so an execute-time + * wrapper on cy.log never fires for queued logs preceding the throw. + * command:enqueued fires synchronously at the user's cy.log() call site, + * before the throw, so the buffer is populated regardless of pass/fail. + * The buffered entries are then flushed via cy.task in the SDK's afterEach, + * which Mocha runs even on test failure. */ Cypress.on('command:enqueued', (attrs) => { if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) return; @@ -226,16 +222,14 @@ Cypress.on('command:enqueued', (attrs) => { } return [result, logItem ? logItem.toString() : ''].join(' '); }, ''); - Cypress.backend('task', { + eventsQueue.push({ task: 'test_observability_log', - arg: { + data: { level: 'info', message, timestamp: new Date().toISOString() }, - timeout: 60000 - }).catch(() => { - /* Don't let observability failures bubble into the test */ + options: { log: false } }); }); diff --git a/bin/testObservability/reporter/index.js b/bin/testObservability/reporter/index.js index 4a6c04b8..2359f354 100644 --- a/bin/testObservability/reporter/index.js +++ b/bin/testObservability/reporter/index.js @@ -628,10 +628,24 @@ class MyReporter { appendTestItemLog = async (log) => { try { + /* + * SDK-5709: keep the hash gate on hook side (avoids attributing logs to + * a stale hook pointer between hooks). Drop it on the test side. In + * Cypress, EVENT_TEST_FAIL fires synchronously when a test body throws — + * before afterEach runs. The SDK's internal afterEach flushes its + * cy.log buffer via cy.task during afterEach, so by the time those logs + * reach this listener runStatusMarkedHash[testAnalyticsId] is already + * set and the log was being dropped without ever attaching a + * test_run_uuid. Late LogCreated events with test_run_uuid are accepted + * by the analytics backend (uploadTestSteps takes the same path with + * no gate). + */ if(this.current_hook && ( this.current_hook.hookAnalyticsId && !this.runStatusMarkedHash[this.current_hook.hookAnalyticsId] )) { log.hook_run_uuid = this.current_hook.hookAnalyticsId; } - if(!log.hook_run_uuid && this.current_test && ( this.current_test.testAnalyticsId && !this.runStatusMarkedHash[this.current_test.testAnalyticsId] )) log.test_run_uuid = this.current_test.testAnalyticsId; + if(!log.hook_run_uuid && this.current_test && this.current_test.testAnalyticsId) { + log.test_run_uuid = this.current_test.testAnalyticsId; + } if(log.hook_run_uuid || log.test_run_uuid) { await uploadEventData({ event_type: 'LogCreated', From 54b6f036bd840dd0c477cd6010d73e334a09651a Mon Sep 17 00:00:00 2001 From: Anish Sinha Date: Tue, 5 May 2026 16:00:34 +0530 Subject: [PATCH 5/5] removed unnecessary comments --- bin/testObservability/cypress/index.js | 10 ---------- bin/testObservability/reporter/index.js | 12 ------------ 2 files changed, 22 deletions(-) diff --git a/bin/testObservability/cypress/index.js b/bin/testObservability/cypress/index.js index fc51d540..bb898811 100644 --- a/bin/testObservability/cypress/index.js +++ b/bin/testObservability/cypress/index.js @@ -201,16 +201,6 @@ Cypress.on('command:end', (command) => { }); }); -/* - * cy.log capture must happen at command-enqueue time, not at command-execute - * time. When a test body throws synchronously (e.g. a failing chai assertion), - * Cypress drops every pending command in the test queue — so an execute-time - * wrapper on cy.log never fires for queued logs preceding the throw. - * command:enqueued fires synchronously at the user's cy.log() call site, - * before the throw, so the buffer is populated regardless of pass/fail. - * The buffered entries are then flushed via cy.task in the SDK's afterEach, - * which Mocha runs even on test failure. - */ Cypress.on('command:enqueued', (attrs) => { if (!Cypress.env('BROWSERSTACK_O11Y_LOGS')) return; if (!attrs || attrs.name !== 'log') return; diff --git a/bin/testObservability/reporter/index.js b/bin/testObservability/reporter/index.js index 2359f354..219a593c 100644 --- a/bin/testObservability/reporter/index.js +++ b/bin/testObservability/reporter/index.js @@ -628,18 +628,6 @@ class MyReporter { appendTestItemLog = async (log) => { try { - /* - * SDK-5709: keep the hash gate on hook side (avoids attributing logs to - * a stale hook pointer between hooks). Drop it on the test side. In - * Cypress, EVENT_TEST_FAIL fires synchronously when a test body throws — - * before afterEach runs. The SDK's internal afterEach flushes its - * cy.log buffer via cy.task during afterEach, so by the time those logs - * reach this listener runStatusMarkedHash[testAnalyticsId] is already - * set and the log was being dropped without ever attaching a - * test_run_uuid. Late LogCreated events with test_run_uuid are accepted - * by the analytics backend (uploadTestSteps takes the same path with - * no gate). - */ if(this.current_hook && ( this.current_hook.hookAnalyticsId && !this.runStatusMarkedHash[this.current_hook.hookAnalyticsId] )) { log.hook_run_uuid = this.current_hook.hookAnalyticsId; }