From fca9d695869f9a0ceb575ef7d0a8246d9e281430 Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 25 Nov 2024 14:23:13 -0800 Subject: [PATCH 01/11] feat: Make logging session aware This will ensure the logging mode is consistent across the session and stops collecting logging events after session expiration/inactivity. --- src/common/session/session-entity.js | 2 + src/features/logging/aggregate/index.js | 38 +++++- src/features/utils/aggregate-base.js | 4 + tests/components/session-entity.test.js | 18 ++- tests/components/session-helpers.js | 1 + tests/specs/logging/session-pages.e2e.js | 166 +++++++++++++++++++++++ tests/specs/util/helpers.js | 20 +++ tools/wdio/plugins/custom-commands.mjs | 14 ++ 8 files changed, 254 insertions(+), 9 deletions(-) create mode 100644 tests/specs/logging/session-pages.e2e.js diff --git a/src/common/session/session-entity.js b/src/common/session/session-entity.js index db4e92540..75900a632 100644 --- a/src/common/session/session-entity.js +++ b/src/common/session/session-entity.js @@ -12,6 +12,7 @@ import { handle } from '../event-emitter/handle' import { SUPPORTABILITY_METRIC_CHANNEL } from '../../features/metrics/constants' import { FEATURE_NAMES } from '../../loaders/features/features' import { windowAddEventListener } from '../event-listener/event-listener-opts' +import { LOGGING_MODE } from '../../features/logging/constants' // this is what can be stored in local storage (not enforced but probably should be) // these values should sync between local storage and the parent class props @@ -24,6 +25,7 @@ const model = { sessionReplaySentFirstChunk: false, sessionTraceMode: MODE.OFF, traceHarvestStarted: false, + loggingMode: LOGGING_MODE.OFF, serverTimeDiff: null, // set by TimeKeeper; "undefined" value will not be stringified and stored but "null" will custom: {} } diff --git a/src/features/logging/aggregate/index.js b/src/features/logging/aggregate/index.js index f878d015f..6b84bd186 100644 --- a/src/features/logging/aggregate/index.js +++ b/src/features/logging/aggregate/index.js @@ -10,7 +10,9 @@ import { Log } from '../shared/log' import { isValidLogLevel } from '../shared/utils' import { applyFnToProps } from '../../../common/util/traverse' import { MAX_PAYLOAD_SIZE } from '../../../common/constants/agent-constants' -import { FEATURE_TO_ENDPOINT } from '../../../loaders/features/features' +import { FEATURE_NAMES, FEATURE_TO_ENDPOINT } from '../../../loaders/features/features' +import { SESSION_EVENT_TYPES, SESSION_EVENTS } from '../../../common/session/constants' +import { ABORT_REASONS } from '../../session_replay/constants' export class Aggregate extends AggregateBase { static featureName = FEATURE_NAME @@ -18,13 +20,33 @@ export class Aggregate extends AggregateBase { super(agentRef, FEATURE_NAME) this.harvestTimeSeconds = agentRef.init.logging.harvestTimeSeconds + // The SessionEntity class can emit a message indicating the session was cleared and reset (expiry, inactivity). This feature must abort and never resume if that occurs. + this.ee.on(SESSION_EVENTS.RESET, () => { + this.abort(ABORT_REASONS.RESET) + }) + + this.ee.on(SESSION_EVENTS.UPDATE, (type, data) => { + if (this.blocked || type !== SESSION_EVENT_TYPES.CROSS_TAB) return + if (this.mode !== LOGGING_MODE.OFF && data.loggingMode === LOGGING_MODE.OFF) this.abort(ABORT_REASONS.CROSS_TAB) + else this.mode = data.loggingMode + }) + this.waitForFlags(['log']).then(([loggingMode]) => { - if (!loggingMode) { + const session = this.agentRef.runtime.session + if (session.isNew) { + this.loggingMode = loggingMode + this.syncWithSessionManager({ + loggingMode: this.loggingMode + }) + } else { + this.loggingMode = session.state.loggingMode + } + + if (!this.loggingMode) { this.blocked = true this.deregisterDrain() return } - this.loggingMode = loggingMode this.scheduler = new HarvestScheduler(FEATURE_TO_ENDPOINT[this.featureName], { onFinished: (result) => this.postHarvestCleanup(result.sent && result.retry), retryDelay: this.harvestTimeSeconds, @@ -123,4 +145,14 @@ export class Aggregate extends AggregateBase { queryStringsBuilder () { return { browser_monitoring_key: this.agentRef.info.licenseKey } } + + /** Abort the feature, once aborted it will not resume */ + abort (reason = {}) { + handle(SUPPORTABILITY_METRIC_CHANNEL, [`Logging/Abort/${reason.sm}`], undefined, FEATURE_NAMES.logging, this.ee) + this.blocked = true + this.loggingMode = LOGGING_MODE.OFF + this.syncWithSessionManager({ loggingMode: this.loggingMode }) + this.events.clear() + this.deregisterDrain() + } } diff --git a/src/features/utils/aggregate-base.js b/src/features/utils/aggregate-base.js index 873b64b61..f2219c8b3 100644 --- a/src/features/utils/aggregate-base.js +++ b/src/features/utils/aggregate-base.js @@ -117,4 +117,8 @@ export class AggregateBase extends FeatureBase { existingAgent.runtime.obfuscator = new Obfuscator(this.agentIdentifier) } } + + syncWithSessionManager (state = {}) { + this.agentRef.runtime.session.write(state) + } } diff --git a/tests/components/session-entity.test.js b/tests/components/session-entity.test.js index 49a5bbdbc..b0aaee62a 100644 --- a/tests/components/session-entity.test.js +++ b/tests/components/session-entity.test.js @@ -39,7 +39,8 @@ describe('constructor', () => { inactiveAt: expect.any(Number), sessionReplayMode: expect.any(Number), sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number) + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) }) }) }) @@ -53,7 +54,8 @@ describe('constructor', () => { updatedAt: expect.any(Number), sessionReplayMode: expect.any(Number), sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number) + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) })) }) @@ -117,7 +119,8 @@ describe('constructor', () => { updatedAt: expect.any(Number), sessionReplayMode: expect.any(Number), sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number) + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) })) }) @@ -133,7 +136,8 @@ describe('constructor', () => { updatedAt: expect.any(Number), sessionReplayMode: expect.any(Number), sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number) + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) })) }) @@ -149,7 +153,8 @@ describe('constructor', () => { updatedAt: expect.any(Number), sessionReplayMode: expect.any(Number), sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number) + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) })) }) }) @@ -218,7 +223,8 @@ describe('read()', () => { inactiveAt: expect.any(Number), sessionReplayMode: expect.any(Number), sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number) + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) })) }) diff --git a/tests/components/session-helpers.js b/tests/components/session-helpers.js index 8e90f6919..e85f81dc4 100644 --- a/tests/components/session-helpers.js +++ b/tests/components/session-helpers.js @@ -38,6 +38,7 @@ export const model = { sessionReplaySentFirstChunk: false, sessionTraceMode: 0, traceHarvestStarted: false, + loggingMode: 0, serverTimeDiff: null, custom: {} } diff --git a/tests/specs/logging/session-pages.e2e.js b/tests/specs/logging/session-pages.e2e.js new file mode 100644 index 000000000..49bb724ad --- /dev/null +++ b/tests/specs/logging/session-pages.e2e.js @@ -0,0 +1,166 @@ +import { testLogsRequest } from '../../../tools/testing-server/utils/expect-tests' +import { LOGGING_MODE } from '../../../src/features/logging/constants' +import { supportsMultiTabSessions } from '../../../tools/browser-matcher/common-matchers.mjs' +import { getLogs } from '../util/helpers' + +describe('Logging Across Pages', () => { + let logsCapture + const TIMEOUT = 10000 + + beforeEach(async () => { + logsCapture = await browser.testHandle.createNetworkCaptures('bamServer', { + test: testLogsRequest + }) + await browser.enableLogging() + }) + + afterEach(async () => { + await browser.destroyAgentSession() + }) + + it('should record across same-tab page refresh', async () => { + let [logsHarvests] = await Promise.all([ + logsCapture.waitForResult({ totalCount: 1 }), + browser.url(await browser.testHandle.assetURL('logs-console-logger-pre-load.html')) + ]) + + const { localStorage } = await browser.getAgentSessionInfo() + const sessionId = localStorage.value + const page1Payload = JSON.parse(logsHarvests[0].request.body) + expect(page1Payload[0].common.attributes.session).toEqual(sessionId) + // expect log entries for: error, warn, info, log + expect(page1Payload[0].logs.length).toBe(4) + + // simulate a second call to rum in same session, which should return log = 0 + await browser.enableLogging({ logMode: LOGGING_MODE.OFF }) + let [refreshHarvests] = await Promise.all([ + logsCapture.waitForResult({ timeout: TIMEOUT }), + browser.refresh() + ]) + + // confirm we are still sending logs because logging is already enabled in this session + // note: the network capture has not been cleared, so the previous harvest is still there + expect(refreshHarvests.length).toBe(2) + const page2Payload = JSON.parse(refreshHarvests[1].request.body) + expect(page2Payload[0].common.attributes.session).toEqual(sessionId) + expect(page2Payload[0].logs.length).toBe(4) + }) + + it('should record across same-tab page navigation', async () => { + let [logsHarvests] = await Promise.all([ + logsCapture.waitForResult({ totalCount: 1 }), + browser.url(await browser.testHandle.assetURL('logs-console-logger-pre-load.html')) + ]) + + const { localStorage } = await browser.getAgentSessionInfo() + const sessionId = localStorage.value + const page1Payload = JSON.parse(logsHarvests[0].request.body) + expect(page1Payload[0].common.attributes.session).toEqual(sessionId) + // expect log entries for: error, warn, info, log + expect(page1Payload[0].logs.length).toBe(4) + + // simulate a second call to rum in same session, which should return log = 0 + await browser.enableLogging({ logMode: LOGGING_MODE.OFF }) + let [navigationHarvests] = await Promise.all([ + logsCapture.waitForResult({ timeout: TIMEOUT }), + browser.url(await browser.testHandle.assetURL('logs-console-logger-post-load.html')) + ]) + + // confirm we are still sending logs because logging is already enabled in this session + // note: the network capture has not been cleared, so the previous harvest is still there + expect(navigationHarvests.length).toBe(2) + const page2Payload = JSON.parse(navigationHarvests[1].request.body) + expect(page2Payload[0].common.attributes.session).toEqual(sessionId) + expect(page2Payload[0].logs.length).toBe(4) + }) + + it.withBrowsersMatching(supportsMultiTabSessions)('should record across new-tab page navigation', async () => { + let [logsHarvests] = await Promise.all([ + logsCapture.waitForResult({ totalCount: 1 }), + browser.url(await browser.testHandle.assetURL('logs-console-logger-pre-load.html')) + ]) + + const { localStorage } = await browser.getAgentSessionInfo() + const sessionId = localStorage.value + const page1Payload = JSON.parse(logsHarvests[0].request.body) + expect(page1Payload[0].common.attributes.session).toEqual(sessionId) + // expect log entries for: error, warn, info, log + expect(page1Payload[0].logs.length).toBe(4) + + // simulate a second call to rum in same session, which should return log = 0 + await browser.enableLogging({ logMode: LOGGING_MODE.OFF }) + let [newTabHarvests] = await Promise.all([ + logsCapture.waitForResult({ timeout: TIMEOUT }), + browser.newWindow(await browser.testHandle.assetURL('logs-console-logger-post-load.html'), { type: 'tab' }), + browser.waitForAgentLoad() + ]) + + // confirm we are still sending logs because logging is already enabled in this session + // note: the network capture has not been cleared, so the previous harvest is still there + expect(newTabHarvests.length).toBe(2) + const page2Payload = JSON.parse(newTabHarvests[1].request.body) + expect(page2Payload[0].common.attributes.session).toEqual(sessionId) + expect(page2Payload[0].logs.length).toBe(4) + + // IMPORTANT! - Reset the browser for the next test or it will fail + await browser.closeWindow() + await browser.switchToWindow((await browser.getWindowHandles())[0]) + }) + + it.withBrowsersMatching(supportsMultiTabSessions)('should kill active tab if killed in backgrounded tab', async () => { + let [logsHarvests] = await Promise.all([ + logsCapture.waitForResult({ totalCount: 1 }), + browser.url(await browser.testHandle.assetURL('logs-console-logger-pre-load.html')) + ]) + + const { localStorage } = await browser.getAgentSessionInfo() + const sessionId = localStorage.value + const page1Payload = JSON.parse(logsHarvests[0].request.body) + expect(page1Payload[0].common.attributes.session).toEqual(sessionId) + // expect log entries for: error, warn, info, log + expect(page1Payload[0].logs.length).toBe(4) + + await Promise.all([ + logsCapture.waitForResult({ timeout: TIMEOUT }), + browser.newWindow(await browser.testHandle.assetURL('logs-console-logger-post-load.html'), { type: 'tab' }), + browser.waitForAgentLoad() + ]) + + const page2BlockedBeforeAbort = await browser.execute(function () { + try { + return Object.values(newrelic.initializedAgents)[0].features.logging.featAggregate.blocked + } catch (err) { + return false + } + }) + expect(page2BlockedBeforeAbort).toEqual(false) + + const page2Blocked = await browser.execute(function () { + try { + var agg = Object.values(newrelic.initializedAgents)[0].features.logging.featAggregate + agg.abort() + return agg.blocked + } catch (err) { + return false + } + }) + expect(page2Blocked).toEqual(true) + + await browser.pause(1000) // Give the agent time to update the session state + await expect(getLogs()).resolves.toEqual(expect.objectContaining({ + events: [], + blocked: true, + loggingMode: 0 + })) + + await browser.closeWindow() + await browser.switchToWindow((await browser.getWindowHandles())[0]) + + await browser.pause(1000) // Give the agent time to update the session state + await expect(getLogs()).resolves.toEqual(expect.objectContaining({ + events: [], + blocked: true, + loggingMode: 0 + })) + }) +}) diff --git a/tests/specs/util/helpers.js b/tests/specs/util/helpers.js index 0a54bc20d..8fdb0cadf 100644 --- a/tests/specs/util/helpers.js +++ b/tests/specs/util/helpers.js @@ -166,3 +166,23 @@ export async function getSR () { } }) } + +export async function getLogs () { + return browser.execute(function () { + try { + var logs = Object.values(newrelic.initializedAgents)[0].features.logging.featAggregate + return { + events: logs.events.get(), + blocked: logs.blocked, + loggingMode: logs.loggingMode + } + } catch (err) { + return { + events: [], + blocked: undefined, + loggingMode: undefined, + err: JSON.stringify(err) + } + } + }) +} diff --git a/tools/wdio/plugins/custom-commands.mjs b/tools/wdio/plugins/custom-commands.mjs index 148493415..1471e31a2 100644 --- a/tools/wdio/plugins/custom-commands.mjs +++ b/tools/wdio/plugins/custom-commands.mjs @@ -115,6 +115,20 @@ export default class CustomCommands { }) }) + /** + * Sets a permanent scheduled reply for the rum call to include the log flag with sampling rate. + * Defaults to 100% sampling rate and log mode = 3/INFO. + */ + browser.addCommand('enableLogging', async function ({ sampling_rate = 100, logMode = 3 } = {}) { + const loggingMode = Math.random() * 100 < sampling_rate ? logMode : 0 + await browser.testHandle.clearScheduledReply('bamServer', { test: testRumRequest }) + await browser.testHandle.scheduleReply('bamServer', { + test: testRumRequest, + permanent: true, + body: JSON.stringify(rumFlags({ log: loggingMode })) + }) + }) + /** * Sets a permanent scheduled reply for the rum call to define the Date header * to a specific value. Default is to set the header to one hour in the past. From 0b6c8ab98ec1308014d6b76258434657cfcad883 Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 25 Nov 2024 14:25:13 -0800 Subject: [PATCH 02/11] chore: Cleanup --- src/features/session_replay/aggregate/index.js | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/src/features/session_replay/aggregate/index.js b/src/features/session_replay/aggregate/index.js index c824a5390..34342aadc 100644 --- a/src/features/session_replay/aggregate/index.js +++ b/src/features/session_replay/aggregate/index.js @@ -73,7 +73,7 @@ export class Aggregate extends AggregateBase { this.ee.on(SESSION_EVENTS.UPDATE, (type, data) => { if (!this.recorder || !this.initialized || this.blocked || type !== SESSION_EVENT_TYPES.CROSS_TAB) return if (this.mode !== MODE.OFF && data.sessionReplayMode === MODE.OFF) this.abort(ABORT_REASONS.CROSS_TAB) - this.mode = data.sessionReplay + this.mode = data.sessionReplayMode }) // Bespoke logic for blobs endpoint. @@ -394,8 +394,4 @@ export class Aggregate extends AggregateBase { this.ee.emit('REPLAY_ABORTED') while (this.recorder?.getEvents().events.length) this.recorder?.clearBuffer?.() } - - syncWithSessionManager (state = {}) { - this.agentRef.runtime.session.write(state) - } } From dffc37452e4dce5acf9852107a71253ce38d4d0c Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 25 Nov 2024 15:20:08 -0800 Subject: [PATCH 03/11] chore: Cleanup extra arg --- src/features/session_replay/aggregate/index.js | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/src/features/session_replay/aggregate/index.js b/src/features/session_replay/aggregate/index.js index 34342aadc..6bd9b90d6 100644 --- a/src/features/session_replay/aggregate/index.js +++ b/src/features/session_replay/aggregate/index.js @@ -147,16 +147,14 @@ export class Aggregate extends AggregateBase { this.scheduler.startTimer(this.harvestTimeSeconds) this.syncWithSessionManager({ sessionReplayMode: this.mode }) } else { - this.initializeRecording(false, true, true) + this.initializeRecording(false, true) } } /** - * Evaluate entitlements and sampling before starting feature mechanics, importing and configuring recording library, and setting storage state - * @param {boolean} entitlements - the true/false state of the "sr" flag from RUM response - * @param {boolean} errorSample - the true/false state of the error sampling decision - * @param {boolean} fullSample - the true/false state of the full sampling decision - * @param {boolean} ignoreSession - whether to force the method to ignore the session state and use just the sample flags + * Evaluate entitlements (which already accounts for sampling) before starting feature mechanics, importing and configuring recording library, and setting storage state + * @param {boolean} srMode - the true/false state of the "sr" flag from RUM response + * @param {boolean} ignoreSession - whether to force the method to ignore the session state and use just the "sr" flag * @returns {void} */ async initializeRecording (srMode, ignoreSession) { From 4a53f1a92778edcc00a28ae9660c414285b2b42c Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 25 Nov 2024 17:01:58 -0800 Subject: [PATCH 04/11] fix: Logging disable harvest test needs fresh session --- .../harvesting/disable-harvesting.e2e.js | 28 +++++++++++++++++-- 1 file changed, 25 insertions(+), 3 deletions(-) diff --git a/tests/specs/harvesting/disable-harvesting.e2e.js b/tests/specs/harvesting/disable-harvesting.e2e.js index cdf8c8667..a20c2a57a 100644 --- a/tests/specs/harvesting/disable-harvesting.e2e.js +++ b/tests/specs/harvesting/disable-harvesting.e2e.js @@ -1,5 +1,6 @@ import { testBlobTraceRequest, testErrorsRequest, testEventsRequest, testInsRequest, testLogsRequest, testMetricsRequest, testRumRequest } from '../../../tools/testing-server/utils/expect-tests' import { rumFlags } from '../../../tools/testing-server/constants' +import { LOGGING_MODE } from '../../../src/features/logging/constants' describe('disable harvesting', () => { it('should disable harvesting metrics and errors when err entitlement is 0', async () => { @@ -61,10 +62,11 @@ describe('disable harvesting', () => { }) it('should disable harvesting console logs when log entitlement is 0', async () => { - const logsCapture = await browser.testHandle.createNetworkCaptures('bamServer', { test: testLogsRequest }) - await browser.testHandle.scheduleReply('bamServer', { + // logging mode will only take effect on a fresh session + const logsCapture = await browser.testHandle.createNetworkCaptures('bamServer2', { test: testLogsRequest }) + await browser.testHandle.scheduleReply('bamServer2', { test: testRumRequest, - body: JSON.stringify(rumFlags({ log: 0 })) + body: JSON.stringify(rumFlags({ log: LOGGING_MODE.OFF })) }) const [logsHarvests] = await Promise.all([ @@ -112,3 +114,23 @@ describe('disable harvesting', () => { }) }) }) + +// logging mode will only take effect on a fresh session +// describe('disable harvesting - logging', () => { +// it('should disable harvesting console logs when log entitlement is 0', async () => { +// const logsCapture = await browser.testHandle.createNetworkCaptures('bamServer2', { test: testLogsRequest }) +// await browser.testHandle.scheduleReply('bamServer2', { +// test: testRumRequest, +// body: JSON.stringify(rumFlags({ log: 0 })) +// }) +// +// const [logsHarvests] = await Promise.all([ +// logsCapture.waitForResult({ timeout: 10000 }), +// browser.url(await browser.testHandle.assetURL('obfuscate-pii.html')) +// .then(() => browser.waitForAgentLoad()) +// ]) +// +// console.log('logHarvests: ', logsHarvests) +// expect(logsHarvests).toEqual([]) +// }) +// }) From d28b1abbdc6366e799d0bc4dd746c9acc33571f4 Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 25 Nov 2024 17:34:17 -0800 Subject: [PATCH 05/11] fix: More session state expectations --- tests/components/session-entity.test.js | 65 +++---------------------- tests/specs/session-manager.e2e.js | 10 +--- tests/specs/util/helpers.js | 13 +++++ 3 files changed, 22 insertions(+), 66 deletions(-) diff --git a/tests/components/session-entity.test.js b/tests/components/session-entity.test.js index b0aaee62a..0cf3728be 100644 --- a/tests/components/session-entity.test.js +++ b/tests/components/session-entity.test.js @@ -2,6 +2,7 @@ import { PREFIX } from '../../src/common/session/constants' import { SessionEntity } from '../../src/common/session/session-entity' import { LocalMemory, model } from './session-helpers' import * as runtimeModule from '../../src/common/constants/runtime' +import { buildExpectedSessionState } from '../specs/util/helpers' jest.useFakeTimers() @@ -33,30 +34,13 @@ describe('constructor', () => { inactiveTimer: expect.any(Object), isNew: expect.any(Boolean), storage: expect.any(Object), - state: expect.objectContaining({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), - loggingMode: expect.any(Number) - }) + state: expect.objectContaining(buildExpectedSessionState()) }) }) test('can use sane defaults', () => { const session = new SessionEntity({ agentIdentifier, key, storage }) - expect(session.state).toEqual(expect.objectContaining({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - updatedAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), - loggingMode: expect.any(Number) - })) + expect(session.state).toEqual(expect.objectContaining(buildExpectedSessionState())) }) test('expiresAt is the correct future timestamp - new session', () => { @@ -112,16 +96,7 @@ describe('constructor', () => { // missing required fields const storage = new LocalMemory({ [`${PREFIX}_${key}`]: { invalid_fields: true } }) const session = new SessionEntity({ agentIdentifier, key, storage }) - expect(session.state).toEqual(expect.objectContaining({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - updatedAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), - loggingMode: expect.any(Number) - })) + expect(session.state).toEqual(expect.objectContaining(buildExpectedSessionState())) }) test('expired expiresAt value in storage sets new defaults', () => { @@ -129,16 +104,7 @@ describe('constructor', () => { jest.setSystemTime(now) const storage = new LocalMemory({ [`${PREFIX}_${key}`]: { value, expiresAt: now - 100, inactiveAt: Infinity } }) const session = new SessionEntity({ agentIdentifier, key, storage }) - expect(session.state).toEqual(expect.objectContaining({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - updatedAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), - loggingMode: expect.any(Number) - })) + expect(session.state).toEqual(expect.objectContaining(buildExpectedSessionState())) }) test('expired inactiveAt value in storage sets new defaults', () => { @@ -146,16 +112,7 @@ describe('constructor', () => { jest.setSystemTime(now) const storage = new LocalMemory({ [`${PREFIX}_${key}`]: { value, inactiveAt: now - 100, expiresAt: Infinity } }) const session = new SessionEntity({ agentIdentifier, key, storage }) - expect(session.state).toEqual(expect.objectContaining({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - updatedAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), - loggingMode: expect.any(Number) - })) + expect(session.state).toEqual(expect.objectContaining(buildExpectedSessionState())) }) }) @@ -217,15 +174,7 @@ describe('read()', () => { const newSession = new SessionEntity({ agentIdentifier, key, storage, expiresMs: 10 }) expect(newSession.isNew).toBeTruthy() - expect(newSession.read()).toEqual(expect.objectContaining({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), - loggingMode: expect.any(Number) - })) + expect(newSession.read()).toEqual(expect.objectContaining(buildExpectedSessionState())) }) test('"pre-existing" sessions get data from read()', () => { diff --git a/tests/specs/session-manager.e2e.js b/tests/specs/session-manager.e2e.js index 7bb371c50..00654e655 100644 --- a/tests/specs/session-manager.e2e.js +++ b/tests/specs/session-manager.e2e.js @@ -1,5 +1,6 @@ import { supportsMultiTabSessions } from '../../tools/browser-matcher/common-matchers.mjs' import { testErrorsRequest } from '../../tools/testing-server/utils/expect-tests' +import { buildExpectedSessionState } from './util/helpers' const config = { init: { @@ -8,14 +9,7 @@ const config = { } describe('newrelic session ID', () => { - const anySession = () => ({ - value: expect.any(String), - expiresAt: expect.any(Number), - inactiveAt: expect.any(Number), - updatedAt: expect.any(Number), - sessionReplayMode: expect.any(Number), - sessionReplaySentFirstChunk: expect.any(Boolean), - sessionTraceMode: expect.any(Number), + const anySession = () => buildExpectedSessionState({ traceHarvestStarted: expect.any(Boolean), custom: expect.any(Object), serverTimeDiff: expect.any(Number) diff --git a/tests/specs/util/helpers.js b/tests/specs/util/helpers.js index 8fdb0cadf..296ba0dfb 100644 --- a/tests/specs/util/helpers.js +++ b/tests/specs/util/helpers.js @@ -14,6 +14,19 @@ export const RRWEB_EVENT_TYPES = { Custom: 5 } +export function buildExpectedSessionState (additionalExpectations) { + return Object.assign({ + value: expect.any(String), + expiresAt: expect.any(Number), + inactiveAt: expect.any(Number), + updatedAt: expect.any(Number), + sessionReplayMode: expect.any(Number), + sessionReplaySentFirstChunk: expect.any(Boolean), + sessionTraceMode: expect.any(Number), + loggingMode: expect.any(Number) + }, additionalExpectations) +} + export function testExpectedReplay ({ data, session, hasMeta, hasSnapshot, hasError, isFirstChunk, contentEncoding, decompressedBytes, appId, entityGuid, harvestId, currentUrl }) { expect(data.query).toMatchObject({ browser_monitoring_key: expect.any(String), From ef72a21047644ef19354eb6c096097c223ecfe7f Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 25 Nov 2024 17:35:20 -0800 Subject: [PATCH 06/11] chore: Use LOGGING_MODE constants --- tests/specs/logging/session-pages.e2e.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/specs/logging/session-pages.e2e.js b/tests/specs/logging/session-pages.e2e.js index 49bb724ad..f7996d437 100644 --- a/tests/specs/logging/session-pages.e2e.js +++ b/tests/specs/logging/session-pages.e2e.js @@ -150,7 +150,7 @@ describe('Logging Across Pages', () => { await expect(getLogs()).resolves.toEqual(expect.objectContaining({ events: [], blocked: true, - loggingMode: 0 + loggingMode: LOGGING_MODE.OFF })) await browser.closeWindow() @@ -160,7 +160,7 @@ describe('Logging Across Pages', () => { await expect(getLogs()).resolves.toEqual(expect.objectContaining({ events: [], blocked: true, - loggingMode: 0 + loggingMode: LOGGING_MODE.OFF })) }) }) From a18e0fb6af48658dbbfe1c903c3d1f1592af2db7 Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Tue, 26 Nov 2024 15:16:16 -0800 Subject: [PATCH 07/11] fix: Failing tests --- src/features/logging/aggregate/index.js | 14 +++++----- src/features/utils/instrument-base.js | 2 ++ .../harvesting/disable-harvesting.e2e.js | 26 +++---------------- tests/specs/logging/harvesting.e2e.js | 12 ++++++--- 4 files changed, 22 insertions(+), 32 deletions(-) diff --git a/src/features/logging/aggregate/index.js b/src/features/logging/aggregate/index.js index 6b84bd186..190205ecc 100644 --- a/src/features/logging/aggregate/index.js +++ b/src/features/logging/aggregate/index.js @@ -13,6 +13,7 @@ import { MAX_PAYLOAD_SIZE } from '../../../common/constants/agent-constants' import { FEATURE_NAMES, FEATURE_TO_ENDPOINT } from '../../../loaders/features/features' import { SESSION_EVENT_TYPES, SESSION_EVENTS } from '../../../common/session/constants' import { ABORT_REASONS } from '../../session_replay/constants' +import { canEnableSessionTracking } from '../../utils/feature-gates' export class Aggregate extends AggregateBase { static featureName = FEATURE_NAME @@ -33,7 +34,12 @@ export class Aggregate extends AggregateBase { this.waitForFlags(['log']).then(([loggingMode]) => { const session = this.agentRef.runtime.session - if (session.isNew) { + if (this.loggingMode === LOGGING_MODE.OFF || (session.isNew && loggingMode === LOGGING_MODE.OFF)) { + this.blocked = true + this.deregisterDrain() + return + } + if (session.isNew || !canEnableSessionTracking(this.agentRef.agentIdentifier)) { this.loggingMode = loggingMode this.syncWithSessionManager({ loggingMode: this.loggingMode @@ -41,12 +47,6 @@ export class Aggregate extends AggregateBase { } else { this.loggingMode = session.state.loggingMode } - - if (!this.loggingMode) { - this.blocked = true - this.deregisterDrain() - return - } this.scheduler = new HarvestScheduler(FEATURE_TO_ENDPOINT[this.featureName], { onFinished: (result) => this.postHarvestCleanup(result.sent && result.retry), retryDelay: this.harvestTimeSeconds, diff --git a/src/features/utils/instrument-base.js b/src/features/utils/instrument-base.js index a0803d536..fc7faab9f 100644 --- a/src/features/utils/instrument-base.js +++ b/src/features/utils/instrument-base.js @@ -139,6 +139,8 @@ export class InstrumentBase extends FeatureBase { return hasReplayPrerequisite(this.agentIdentifier) && !!session case FEATURE_NAMES.sessionTrace: return !!session + case FEATURE_NAMES.logging: + return !!session default: return true } diff --git a/tests/specs/harvesting/disable-harvesting.e2e.js b/tests/specs/harvesting/disable-harvesting.e2e.js index a20c2a57a..bb5a297fe 100644 --- a/tests/specs/harvesting/disable-harvesting.e2e.js +++ b/tests/specs/harvesting/disable-harvesting.e2e.js @@ -63,8 +63,10 @@ describe('disable harvesting', () => { it('should disable harvesting console logs when log entitlement is 0', async () => { // logging mode will only take effect on a fresh session - const logsCapture = await browser.testHandle.createNetworkCaptures('bamServer2', { test: testLogsRequest }) - await browser.testHandle.scheduleReply('bamServer2', { + await browser.destroyAgentSession() + + const logsCapture = await browser.testHandle.createNetworkCaptures('bamServer', { test: testLogsRequest }) + await browser.testHandle.scheduleReply('bamServer', { test: testRumRequest, body: JSON.stringify(rumFlags({ log: LOGGING_MODE.OFF })) }) @@ -114,23 +116,3 @@ describe('disable harvesting', () => { }) }) }) - -// logging mode will only take effect on a fresh session -// describe('disable harvesting - logging', () => { -// it('should disable harvesting console logs when log entitlement is 0', async () => { -// const logsCapture = await browser.testHandle.createNetworkCaptures('bamServer2', { test: testLogsRequest }) -// await browser.testHandle.scheduleReply('bamServer2', { -// test: testRumRequest, -// body: JSON.stringify(rumFlags({ log: 0 })) -// }) -// -// const [logsHarvests] = await Promise.all([ -// logsCapture.waitForResult({ timeout: 10000 }), -// browser.url(await browser.testHandle.assetURL('obfuscate-pii.html')) -// .then(() => browser.waitForAgentLoad()) -// ]) -// -// console.log('logHarvests: ', logsHarvests) -// expect(logsHarvests).toEqual([]) -// }) -// }) diff --git a/tests/specs/logging/harvesting.e2e.js b/tests/specs/logging/harvesting.e2e.js index 5e42fdc6b..2cc842828 100644 --- a/tests/specs/logging/harvesting.e2e.js +++ b/tests/specs/logging/harvesting.e2e.js @@ -11,12 +11,18 @@ describe('logging harvesting', () => { }) }) + afterEach(async () => { + // logging mode is sticky to the session, so we need to reset before the next test + await await browser.destroyAgentSession() + }) + const mockRumResponse = async (logLevel) => { await browser.testHandle.scheduleReply('bamServer', { test: testRumRequest, body: JSON.stringify(rumFlags({ log: logLevel })) }) } + const checkPayload = (actualPayload, expectedPayload) => { expect(actualPayload).toContainAllKeys(['common', 'logs']) expect(actualPayload.common).toEqual(expectedPayload.common) @@ -70,8 +76,8 @@ describe('logging harvesting', () => { it(`should harvest expected logs - ${type} pre load - logging mode: ${mode}`, async () => { await mockRumResponse(logLevel) const [[{ request: { body } }]] = await Promise.all([ - logsCapture.waitForResult({ totalCount: 1 }), - browser.url(await browser.testHandle.assetURL(`logs-${type}-pre-load.html`)) + logsCapture.waitForResult({ totalCount: 1, timeout: 15000 }), + await browser.url(await browser.testHandle.assetURL(`logs-${type}-pre-load.html`)) ]) const actualPayload = JSON.parse(body) @@ -81,7 +87,7 @@ describe('logging harvesting', () => { it(`should harvest expected logs - ${type} post load - logging mode: ${mode}`, async () => { await mockRumResponse(logLevel) const [[{ request: { body } }]] = await Promise.all([ - logsCapture.waitForResult({ totalCount: 1 }), + logsCapture.waitForResult({ totalCount: 1, timeout: 15000 }), browser.url(await browser.testHandle.assetURL(`logs-${type}-post-load.html`)) ]) const actualPayload = JSON.parse(body) From 0840445983e6bebb503c40c756313e3fe113c387 Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 2 Dec 2024 08:24:32 -0800 Subject: [PATCH 08/11] fix: Failing micro-agent smoke test --- tests/specs/npm/micro-agent.e2e.js | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/tests/specs/npm/micro-agent.e2e.js b/tests/specs/npm/micro-agent.e2e.js index e3ee368d4..c10e59097 100644 --- a/tests/specs/npm/micro-agent.e2e.js +++ b/tests/specs/npm/micro-agent.e2e.js @@ -3,6 +3,10 @@ import { testErrorsRequest, testInsRequest, testLogsRequest, testRumRequest } from '../../../tools/testing-server/utils/expect-tests' describe('micro-agent', () => { + beforeEach(async () => { + await browser.enableLogging() + }) + it('Smoke Test - Can send distinct payloads of all relevant data types to 2 distinct app IDs', async () => { const [rumCapture, errorsCapture, insightsCapture, logsCapture] = await browser.testHandle.createNetworkCaptures('bamServer', [ { test: testRumRequest }, @@ -40,7 +44,7 @@ describe('micro-agent', () => { rumCapture.waitForResult({ totalCount: 2 }), errorsCapture.waitForResult({ totalCount: 2 }), insightsCapture.waitForResult({ totalCount: 2 }), - logsCapture.waitForResult({ totalCount: 2 }) + logsCapture.waitForResult({ totalCount: 2, timeout: 15000 }) ]) // these props will get set to true once a test has matched it From 2947cf55d0a4ebd0645c0e07b49b49b1ea5b161d Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 2 Dec 2024 12:04:01 -0800 Subject: [PATCH 09/11] fix: Typo --- tests/specs/logging/harvesting.e2e.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/specs/logging/harvesting.e2e.js b/tests/specs/logging/harvesting.e2e.js index 2cc842828..73d5fbf5b 100644 --- a/tests/specs/logging/harvesting.e2e.js +++ b/tests/specs/logging/harvesting.e2e.js @@ -13,7 +13,7 @@ describe('logging harvesting', () => { afterEach(async () => { // logging mode is sticky to the session, so we need to reset before the next test - await await browser.destroyAgentSession() + await browser.destroyAgentSession() }) const mockRumResponse = async (logLevel) => { From 013a6b2f9fca20d6d5d05ba7f40fcd05b319502c Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 2 Dec 2024 12:06:30 -0800 Subject: [PATCH 10/11] fix: Session handling --- src/features/logging/aggregate/index.js | 14 +++++++----- src/features/utils/aggregate-base.js | 6 ++++- src/features/utils/instrument-base.js | 2 -- tests/specs/harvesting/index.e2e.js | 30 ++++++++++++++++++++++--- 4 files changed, 40 insertions(+), 12 deletions(-) diff --git a/src/features/logging/aggregate/index.js b/src/features/logging/aggregate/index.js index 190205ecc..467fcc16b 100644 --- a/src/features/logging/aggregate/index.js +++ b/src/features/logging/aggregate/index.js @@ -13,7 +13,6 @@ import { MAX_PAYLOAD_SIZE } from '../../../common/constants/agent-constants' import { FEATURE_NAMES, FEATURE_TO_ENDPOINT } from '../../../loaders/features/features' import { SESSION_EVENT_TYPES, SESSION_EVENTS } from '../../../common/session/constants' import { ABORT_REASONS } from '../../session_replay/constants' -import { canEnableSessionTracking } from '../../utils/feature-gates' export class Aggregate extends AggregateBase { static featureName = FEATURE_NAME @@ -33,17 +32,20 @@ export class Aggregate extends AggregateBase { }) this.waitForFlags(['log']).then(([loggingMode]) => { - const session = this.agentRef.runtime.session + const session = this.agentRef.runtime.session ?? {} if (this.loggingMode === LOGGING_MODE.OFF || (session.isNew && loggingMode === LOGGING_MODE.OFF)) { this.blocked = true this.deregisterDrain() return } - if (session.isNew || !canEnableSessionTracking(this.agentRef.agentIdentifier)) { + if (session.isNew || !this.isSessionTrackingEnabled) { this.loggingMode = loggingMode - this.syncWithSessionManager({ - loggingMode: this.loggingMode - }) + + if (this.isSessionTrackingEnabled) { + this.syncWithSessionManager({ + loggingMode: this.loggingMode + }) + } } else { this.loggingMode = session.state.loggingMode } diff --git a/src/features/utils/aggregate-base.js b/src/features/utils/aggregate-base.js index f2219c8b3..a884c2100 100644 --- a/src/features/utils/aggregate-base.js +++ b/src/features/utils/aggregate-base.js @@ -7,6 +7,7 @@ import { activatedFeatures } from '../../common/util/feature-flags' import { Obfuscator } from '../../common/util/obfuscate' import { EventBuffer } from './event-buffer' import { FEATURE_NAMES } from '../../loaders/features/features' +import { canEnableSessionTracking } from './feature-gates' export class AggregateBase extends FeatureBase { constructor (agentRef, featureName) { @@ -18,6 +19,7 @@ export class AggregateBase extends FeatureBase { else if (![FEATURE_NAMES.pageViewEvent, FEATURE_NAMES.sessionTrace].includes(this.featureName)) this.events = new EventBuffer() this.checkConfiguration(agentRef) this.obfuscator = agentRef.runtime.obfuscator + this.isSessionTrackingEnabled = canEnableSessionTracking(this.agentIdentifier) } /** @@ -119,6 +121,8 @@ export class AggregateBase extends FeatureBase { } syncWithSessionManager (state = {}) { - this.agentRef.runtime.session.write(state) + if (this.isSessionTrackingEnabled) { + this.agentRef.runtime.session.write(state) + } } } diff --git a/src/features/utils/instrument-base.js b/src/features/utils/instrument-base.js index fc7faab9f..a0803d536 100644 --- a/src/features/utils/instrument-base.js +++ b/src/features/utils/instrument-base.js @@ -139,8 +139,6 @@ export class InstrumentBase extends FeatureBase { return hasReplayPrerequisite(this.agentIdentifier) && !!session case FEATURE_NAMES.sessionTrace: return !!session - case FEATURE_NAMES.logging: - return !!session default: return true } diff --git a/tests/specs/harvesting/index.e2e.js b/tests/specs/harvesting/index.e2e.js index 681e235d2..8aa461249 100644 --- a/tests/specs/harvesting/index.e2e.js +++ b/tests/specs/harvesting/index.e2e.js @@ -1,6 +1,6 @@ import { faker } from '@faker-js/faker' import { testExpectedTrace } from '../util/helpers' -import { testAjaxEventsRequest, testAjaxTimeSlicesRequest, testBlobTraceRequest, testErrorsRequest, testInsRequest, testInteractionEventsRequest, testRumRequest, testTimingEventsRequest } from '../../../tools/testing-server/utils/expect-tests' +import { testAjaxEventsRequest, testAjaxTimeSlicesRequest, testBlobTraceRequest, testErrorsRequest, testInsRequest, testInteractionEventsRequest, testLogsRequest, testRumRequest, testTimingEventsRequest } from '../../../tools/testing-server/utils/expect-tests' describe('harvesting', () => { let rumCapture @@ -11,9 +11,10 @@ describe('harvesting', () => { let insightsCapture let interactionEventsCapture let errorMetricsCapture + let loggingEventsCapture beforeEach(async () => { - [rumCapture, timingEventsCapture, ajaxEventsCapture, ajaxMetricsCapture, traceCapture, insightsCapture, interactionEventsCapture, errorMetricsCapture] = await browser.testHandle.createNetworkCaptures('bamServer', [ + [rumCapture, timingEventsCapture, ajaxEventsCapture, ajaxMetricsCapture, traceCapture, insightsCapture, interactionEventsCapture, errorMetricsCapture, loggingEventsCapture] = await browser.testHandle.createNetworkCaptures('bamServer', [ { test: testRumRequest }, { test: testTimingEventsRequest }, { test: testAjaxEventsRequest }, @@ -21,7 +22,8 @@ describe('harvesting', () => { { test: testBlobTraceRequest }, { test: testInsRequest }, { test: testInteractionEventsRequest }, - { test: testErrorsRequest } + { test: testErrorsRequest }, + { test: testLogsRequest } ]) }) @@ -315,6 +317,28 @@ describe('harvesting', () => { interactionEventsHarvests.forEach(harvest => expect(harvest.request.query.s).toEqual('0')) }) + it('should not contain session data in the logs request when cookies_enabled is false', async () => { + const testURL = await browser.testHandle.assetURL('obfuscate-pii.html', { + init: { + privacy: { + cookies_enabled: false + } + } + }) + + const [ + loggingEventsHarvests + ] = await Promise.all([ + loggingEventsCapture.waitForResult({ totalCount: 1 }), + browser.url(testURL) + .then(() => browser.waitForAgentLoad()) + ]) + + loggingEventsHarvests.forEach(harvest => { + expect(harvest.request.query.session).toBeUndefined() + }) + }) + it('should not harvest features when there is no data', async () => { const [ insightsHarvests, From 5561e6d1b64ed68243fa9cf92766a70fd2a6b6c8 Mon Sep 17 00:00:00 2001 From: Pik Tang Date: Mon, 2 Dec 2024 14:44:08 -0800 Subject: [PATCH 11/11] fix: Handle second session failure mode --- src/features/utils/aggregate-base.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/features/utils/aggregate-base.js b/src/features/utils/aggregate-base.js index a884c2100..286bce283 100644 --- a/src/features/utils/aggregate-base.js +++ b/src/features/utils/aggregate-base.js @@ -19,7 +19,7 @@ export class AggregateBase extends FeatureBase { else if (![FEATURE_NAMES.pageViewEvent, FEATURE_NAMES.sessionTrace].includes(this.featureName)) this.events = new EventBuffer() this.checkConfiguration(agentRef) this.obfuscator = agentRef.runtime.obfuscator - this.isSessionTrackingEnabled = canEnableSessionTracking(this.agentIdentifier) + this.isSessionTrackingEnabled = canEnableSessionTracking(this.agentIdentifier) && this.agentRef.runtime.session } /**