Skip to content

Commit

Permalink
fix: Session trace nodes de-duplication (#1008)
Browse files Browse the repository at this point in the history
Co-authored-by: Jordan Porter <[email protected]>
  • Loading branch information
cwli24 and metal-messiah authored May 3, 2024
1 parent 38a502b commit 44f229e
Show file tree
Hide file tree
Showing 6 changed files with 147 additions and 26 deletions.
4 changes: 2 additions & 2 deletions src/features/jserrors/aggregate/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -202,15 +202,15 @@ export class Aggregate extends AggregateBase {

// Trace sends the error in its payload, and both trace & replay simply listens for any error to occur.
const jsErrorEvent = [type, bucketHash, params, newMetrics, customAttributes]
handle('errorAgg', jsErrorEvent, undefined, FEATURE_NAMES.sessionTrace, this.ee)
handle('trace-jserror', jsErrorEvent, undefined, FEATURE_NAMES.sessionTrace, this.ee)
// still send EE events for other features such as above, but stop this one from aggregating internal data
if (this.blocked) return

const softNavInUse = Boolean(getNREUMInitializedAgent(this.agentIdentifier)?.features[FEATURE_NAMES.softNav])
// Note: the following are subject to potential race cond wherein if the other feature aren't fully initialized, it'll be treated as there being no associated interaction.
// They each will also tack on their respective properties to the params object as part of the decision flow.
if (softNavInUse) handle('jserror', [params, time], undefined, FEATURE_NAMES.softNav, this.ee)
else handle('errorAgg', jsErrorEvent, undefined, FEATURE_NAMES.spa, this.ee)
else handle('spa-jserror', jsErrorEvent, undefined, FEATURE_NAMES.spa, this.ee)

if (params.browserInteractionId && !params._softNavFinished) { // hold onto the error until the in-progress interaction is done, eithered saved or discarded
this.bufferedErrorsUnderSpa[params.browserInteractionId] ??= []
Expand Down
8 changes: 6 additions & 2 deletions src/features/session_trace/aggregate/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,7 @@ export class Aggregate extends AggregateBase {
this.trace = {}
this.nodeCount = 0
this.sentTrace = null
this.prevStoredEvents = new Set()
this.harvestTimeSeconds = getConfigurationValue(agentIdentifier, 'session_trace.harvestTimeSeconds') || 10
this.maxNodesPerHarvest = getConfigurationValue(agentIdentifier, 'session_trace.maxNodesPerHarvest') || 1000
/**
Expand Down Expand Up @@ -108,7 +109,7 @@ export class Aggregate extends AggregateBase {
this.isStandalone = true
this.waitForFlags((['stn'])).then(([on]) => controlTraceOp(on), this.featureName, this.ee)
} else {
registerHandler('errorAgg', () => {
registerHandler('trace-jserror', () => {
seenAnError = true
switchToFull()
}, this.featureName, this.ee)
Expand Down Expand Up @@ -169,7 +170,7 @@ export class Aggregate extends AggregateBase {
registerHandler('bstHist', (...args) => operationalGate.settle(() => this.storeHist(...args)), this.featureName, this.ee)
registerHandler('bstXhrAgg', (...args) => operationalGate.settle(() => this.storeXhrAgg(...args)), this.featureName, this.ee)
registerHandler('bstApi', (...args) => operationalGate.settle(() => this.storeSTN(...args)), this.featureName, this.ee)
registerHandler('errorAgg', (...args) => operationalGate.settle(() => this.storeErrorAgg(...args)), this.featureName, this.ee)
registerHandler('trace-jserror', (...args) => operationalGate.settle(() => this.storeErrorAgg(...args)), this.featureName, this.ee)
registerHandler('pvtAdded', (...args) => operationalGate.settle(() => this.processPVT(...args)), this.featureName, this.ee)
this.drain()
}
Expand Down Expand Up @@ -208,6 +209,7 @@ export class Aggregate extends AggregateBase {
}

#prepareHarvest (options) {
this.prevStoredEvents.clear() // release references to past events for GC
if (this.isStandalone) {
if (this.ptid && now() >= MAX_TRACE_DURATION) {
// Perform a final harvest once we hit or exceed the max session trace time
Expand Down Expand Up @@ -272,6 +274,8 @@ export class Aggregate extends AggregateBase {
// Tracks the events and their listener's duration on objects wrapped by wrap-events.
storeEvent (currentEvent, target, start, end) {
if (this.shouldIgnoreEvent(currentEvent, target)) return
if (this.prevStoredEvents.has(currentEvent)) return // prevent multiple listeners of an event from creating duplicate trace nodes per occurrence. Cleared every harvest. near-zero chance for re-duplication after clearing per harvest since the timestamps of the event are considered for uniqueness.
this.prevStoredEvents.add(currentEvent)

const evt = {
n: this.evtName(currentEvent.type),
Expand Down
2 changes: 1 addition & 1 deletion src/features/spa/aggregate/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -698,7 +698,7 @@ export class Aggregate extends AggregateBase {
}
}

baseEE.on('errorAgg', function (type, name, params, metrics) {
baseEE.on('spa-jserror', function (type, name, params, metrics) {
if (!state.currentNode) return
params._interactionId = state.currentNode.interaction.id
// do not capture parentNodeId when in root node
Expand Down
44 changes: 38 additions & 6 deletions tests/components/session_trace/index.test.js
Original file line number Diff line number Diff line change
Expand Up @@ -22,9 +22,20 @@ jest.mock('../../../src/common/window/load', () => ({
const aggregator = new Aggregator({ agentIdentifier: 'abcd', ee })

describe('session trace', () => {
test('creates right nodes', async () => {
const traceInstrument = new SessionTrace('abcd', aggregator)
let traceInstrument, traceAggregate
beforeAll(async () => {
traceInstrument = new SessionTrace('abcd', aggregator)
await traceInstrument.onAggregateImported
traceAggregate = traceInstrument.featAggregate
traceAggregate.operationalGate.decide(true) // all the nodes get created from buffered data
})
beforeEach(() => {
traceAggregate.trace = {}
traceAggregate.sentTrace = null
traceAggregate.prevStoredEvents = new Set()
})

test('creates right nodes', async () => {
// create session trace nodes for load events
document.addEventListener('DOMContentLoaded', () => null)
window.addEventListener('load', () => null)
Expand All @@ -33,15 +44,12 @@ describe('session trace', () => {

document.dispatchEvent(new CustomEvent('DOMContentLoaded')) // simulate natural browser event
window.dispatchEvent(new CustomEvent('load')) // load is actually ignored by Trace as it should be passed by the PVT feature, so it should not be in payload
await traceInstrument.onAggregateImported

const traceAggregate = traceInstrument.featAggregate
traceAggregate.storeXhrAgg('xhr', '[200,null,null]', { method: 'GET', status: 200 }, { rxSize: 770, duration: 99, cbTime: 0, time: 217 }) // fake ajax data
traceAggregate.processPVT('fi', 30, { fid: 8 }) // fake pvt data
traceAggregate.operationalGate.decide(true) // all the nodes get created from buffered data

traceAggregate.resourceObserver = true // so takeSTNs will skip check for performance entries
const payload = traceInstrument.featAggregate.takeSTNs()
const payload = traceAggregate.takeSTNs()
let res = payload.body.res
let qs = payload.qs

Expand Down Expand Up @@ -80,4 +88,28 @@ describe('session trace', () => {
let unknown = res.filter(n => n.o === 'unknown')
expect(unknown.length).toEqual(0) // no events with unknown origin
})

test('tracks previously stored events and processes them once per occurrence', () => {
jest.useFakeTimers()
document.addEventListener('visibilitychange', () => 1)
document.addEventListener('visibilitychange', () => 2)
document.addEventListener('visibilitychange', () => 3) // additional listeners should not generate additional nodes
Object.defineProperty(document, 'visibilityState', { value: 'hidden', writable: true })

document.dispatchEvent(new Event('visibilitychange'))
expect(traceAggregate.trace.visibilitychange[0]).toEqual(expect.objectContaining({
n: 'visibilitychange',
t: 'event',
o: 'document'
}))
expect(traceAggregate.prevStoredEvents.size).toEqual(1)

jest.advanceTimersByTime(1000)
document.dispatchEvent(new Event('visibilitychange'))
expect(traceAggregate.trace.visibilitychange.length).toEqual(2)
expect(traceAggregate.trace.visibilitychange[0].s).not.toEqual(traceAggregate.trace.visibilitychange[1].s) // should not have same start times
expect(traceAggregate.prevStoredEvents.size).toEqual(2)

jest.useRealTimers()
})
})
100 changes: 100 additions & 0 deletions tests/specs/stn/trace-nodes.e2e.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,100 @@
import { testRumRequest } from '../../../tools/testing-server/utils/expect-tests.js'
import { notIE } from '../../../tools/browser-matcher/common-matchers.mjs'

describe('Trace nodes', () => {
const config = { init: { session_trace: { harvestTimeSeconds: 2 } } }

it.withBrowsersMatching(notIE)('are not duplicated for events', async () => {
const url = await browser.testHandle.assetURL('pagehide.html', config)
await browser.url(url).then(() => browser.waitForAgentLoad())

await browser.execute(function () {
const storedEvents = Object.values(newrelic.initializedAgents)[0].features.session_trace.featAggregate.prevStoredEvents
for (let i = 0; i < 10; i++) storedEvents.add(i) // artificially add "events" since the counter is otherwise unreliable
})
const resPromise = browser.testHandle.expectResources()
$('#btn1').click() // since the agent has multiple listeners on vischange, this is a good example of often duplicated event
const { request } = await resPromise

const vischangeEvts = request.body.res.filter(node => node.t === 'event' && node.n === 'visibilitychange')
expect(vischangeEvts.length).toEqual(1)

// In addition, our Set keeping track of stored Events should have reset during harvest to prevent mem leak.
const trackedEventsPostHarvest = await browser.execute(getEventsSetSize)
expect(trackedEventsPostHarvest).toBeLessThan(10)
})
it.withBrowsersMatching(notIE)('are not stored for events when trace is not on', async () => {
await browser.testHandle.scheduleReply('bamServer', {
test: testRumRequest,
body: JSON.stringify({ stn: 0, err: 1, ins: 1, cap: 1, spa: 0, loaded: 1 })
})

const url = await browser.testHandle.assetURL('pagehide.html', config)
await browser.url(url).then(() => browser.waitForAgentLoad())
await $('#btn1').click()
const numTrackedEvents = await browser.execute(getEventsSetSize)
expect(numTrackedEvents).toEqual(0)
})
function getEventsSetSize () {
return Object.values(newrelic.initializedAgents)[0].features.session_trace.featAggregate.prevStoredEvents.size
}

it.withBrowsersMatching(notIE)('are not duplicated for resources', async () => {
const url = await browser.testHandle.assetURL('instrumented.html', config)
await browser.url(url).then(() => browser.waitForAgentLoad())

let { request } = await browser.testHandle.expectResources()
const fetchedScripts = request.body.res.filter(node => node.t === 'resource' && node.n === 'script')
expect(fetchedScripts.length).toEqual(1) // our /build/nr-__.min.js
})

it('are not duplicated for history pushState', async () => {
const url = await browser.testHandle.assetURL('instrumented.html', config)
await browser.url(url).then(() => browser.waitForAgentLoad())

await Promise.all([browser.testHandle.expectResources(), browser.execute(function () {
history.pushState({}, '')
})]).then(([{ request: { body } }]) => {
const hist = body.res.filter(node => node.n === 'history.pushState')
expect(hist.length).toEqual(1)
expect(hist[0].t.endsWith('/instrumented.html')).toBeTruthy()
})
})

it.withBrowsersMatching(notIE)('are created and not duplicated for ajax', async () => {
const url = await browser.testHandle.assetURL('fetch.html', config)
await browser.url(url).then(() => browser.waitForAgentLoad())

await browser.testHandle.expectResources().then(({ request: { body } }) => {
const reqs = body.res.filter(node => node.n === 'Ajax' && node.o.endsWith('/json'))
expect(reqs.length).toEqual(1)
})
})

it('are created and not duplicated for one error', async () => {
const url = await browser.testHandle.assetURL('instrumented.html', config)
await browser.url(url).then(() => browser.waitForAgentLoad())

await Promise.all([browser.testHandle.expectResources(), browser.execute(function () {
newrelic.noticeError('hello session traces i am error')
})]).then(([{ request: { body } }]) => {
const errs = body.res.filter(node => node.n === 'error' && node.o === 'hello session traces i am error')
expect(errs.length).toEqual(1)
})
})

it('are not duplicated for timings', async () => {
const url = await browser.testHandle.assetURL('instrumented.html', config)
let [{ request }] = await Promise.all([
browser.testHandle.expectResources(),
browser.url(url).then(() => browser.waitForAgentLoad())
])
const countTimings = {}
request.body.res.filter(node => node.t === 'timing').forEach(node => (countTimings[node.n] = ++countTimings[node.n] || 1))

;[{ request }] = await Promise.all([browser.testHandle.expectResources(), $('body').click()]) // click to trigger FI & LCP timings
request.body.res.filter(node => node.t === 'timing').forEach(node => (countTimings[node.n] = ++countTimings[node.n] || 1))

expect(Object.values(countTimings).some(count => count > 1)).toBeFalsy()
})
})
15 changes: 0 additions & 15 deletions tests/specs/stn/with-jserror.e2e.js

This file was deleted.

0 comments on commit 44f229e

Please sign in to comment.