Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
240 changes: 240 additions & 0 deletions packages/debugger/src/domain/api.spec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -558,6 +558,246 @@ describe('api', () => {
})
})

describe('snapshot timeout', () => {
function createSnapshotProbe(methodName: string): Probe {
return {
id: `timeout-probe-${methodName}`,
version: 0,
type: 'LOG_PROBE',
where: { typeName: 'TestClass', methodName },
template: 'Test',
captureSnapshot: true,
capture: { maxReferenceDepth: 3 },
sampling: { snapshotsPerSecond: 5000 },
evaluateAt: 'ENTRY',
}
}

it('should drop snapshot when entry capture exceeds timeout', () => {
const probe = createSnapshotProbe('entryTimeout')
addProbe(probe)

let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
// Let the first few calls (start time, deadline creation) use real time,
// then jump past the deadline to simulate slow capture.
if (callCount <= 3) {
return realNow()
}
return realNow() + 20
})

const probes = getProbes('TestClass;entryTimeout')!
const deepObj = { level1: { level2: { level3: { level4: 'deep' } } } }
onEntry(probes, {}, { arg: deepObj })
onReturn(probes, null, {}, { arg: deepObj }, {})

// The entry capture timed out, so onEntry pushed null.
// onReturn still gets an active entry from its own onEntry call, but
// the entry snapshot is dropped. The return capture has its own timeout.
// Since performance.now is still returning future values, the return
// capture also times out and no snapshot is sent.
expect(mockBatchAdd).not.toHaveBeenCalled()
})

it('should drop snapshot when return capture exceeds timeout', () => {
const probe = createSnapshotProbe('returnTimeout')
addProbe(probe)

const probes = getProbes('TestClass;returnTimeout')!

// Let onEntry succeed with real time
onEntry(probes, {}, { x: 1 })

// Now make performance.now jump forward so the return capture times out
let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
if (callCount <= 2) {
return realNow()
}
return realNow() + 20
})

onReturn(probes, null, {}, { x: 1 }, { local: 'value' })

expect(mockBatchAdd).not.toHaveBeenCalled()
})

it('should drop snapshot when throw capture exceeds timeout', () => {
const probe = createSnapshotProbe('throwTimeout')
addProbe(probe)

const probes = getProbes('TestClass;throwTimeout')!

// Let onEntry succeed with real time
onEntry(probes, {}, { x: 1 })

// Now make performance.now jump forward so the throw capture times out
let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
if (callCount <= 2) {
return realNow()
}
return realNow() + 20
})

onThrow(probes, new Error('test'), {}, { x: 1 })

expect(mockBatchAdd).not.toHaveBeenCalled()
})

it('should not affect non-snapshot probes', () => {
const probe: Probe = {
id: 'non-snapshot-timeout',
version: 0,
type: 'LOG_PROBE',
where: { typeName: 'TestClass', methodName: 'nonSnapshot' },
template: 'Test',
captureSnapshot: false,
capture: {},
sampling: { snapshotsPerSecond: 5000 },
evaluateAt: 'ENTRY',
}
addProbe(probe)

// Spike performance.now to simulate slow execution
let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
if (callCount <= 2) {
return realNow()
}
return realNow() + 20
})

const probes = getProbes('TestClass;nonSnapshot')!
onEntry(probes, {}, {})
onReturn(probes, null, {}, {}, {})

expect(mockBatchAdd).toHaveBeenCalledTimes(1)
})

it('should not leak active entries when entry capture times out', () => {
const probe = createSnapshotProbe('entryLeakTest')
addProbe(probe)

let shouldTimeout = true
let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
if (!shouldTimeout || callCount <= 3) {
return realNow()
}
return realNow() + 20
})

const probes = getProbes('TestClass;entryLeakTest')!
// This onEntry will time out and push null
onEntry(probes, {}, { x: 1 })

// onReturn should handle the null entry gracefully (no snapshot sent)
shouldTimeout = false
callCount = 0
onReturn(probes, null, {}, { x: 1 }, {})

expect(mockBatchAdd).not.toHaveBeenCalled()
})

it('should skip subsequent snapshot probes after timeout but still process non-snapshot probes', () => {
const snapshotProbe1: Probe = {
id: 'timeout-shared-1',
version: 0,
type: 'LOG_PROBE',
where: { typeName: 'TestClass', methodName: 'sharedDeadline' },
template: 'Snapshot probe',
captureSnapshot: true,
capture: { maxReferenceDepth: 3 },
sampling: { snapshotsPerSecond: 5000 },
evaluateAt: 'ENTRY',
}
const nonSnapshotProbe: Probe = {
id: 'timeout-shared-2',
version: 0,
type: 'LOG_PROBE',
where: { typeName: 'TestClass', methodName: 'sharedDeadline' },
template: 'Non-snapshot probe',
captureSnapshot: false,
capture: {},
sampling: { snapshotsPerSecond: 5000 },
evaluateAt: 'ENTRY',
}
const snapshotProbe2: Probe = {
id: 'timeout-shared-3',
version: 0,
type: 'LOG_PROBE',
where: { typeName: 'TestClass', methodName: 'sharedDeadline' },
template: 'Second snapshot probe',
captureSnapshot: true,
capture: { maxReferenceDepth: 3 },
sampling: { snapshotsPerSecond: 5000 },
evaluateAt: 'ENTRY',
}
addProbe(snapshotProbe1)
addProbe(nonSnapshotProbe)
addProbe(snapshotProbe2)

let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
if (callCount <= 3) {
return realNow()
}
return realNow() + 20
})

const probes = getProbes('TestClass;sharedDeadline')!
onEntry(probes, {}, { x: 1 })
onReturn(probes, null, {}, { x: 1 }, {})

// The non-snapshot probe should still send, but both snapshot probes should be dropped
const calls = mockBatchAdd.calls.allArgs()
expect(calls.length).toBe(1)
expect(calls[0][0].message).toBe('Non-snapshot probe')
})

it('should share deadline across probes so second snapshot probe exits immediately', () => {
const probe1 = createSnapshotProbe('sharedDeadline1')
const probe2: Probe = {
...createSnapshotProbe('sharedDeadline2'),
id: 'timeout-probe-sharedDeadline2',
where: { typeName: 'TestClass', methodName: 'sharedDeadline1' },
}
addProbe(probe1)
addProbe(probe2)

let callCount = 0
const realNow = performance.now.bind(performance)
spyOn(performance, 'now').and.callFake(() => {
callCount++
if (callCount <= 3) {
return realNow()
}
return realNow() + 20
})

const probes = getProbes('TestClass;sharedDeadline1')!
onEntry(probes, {}, { x: 1 })
onReturn(probes, null, {}, { x: 1 }, {})

// Both snapshot probes share the deadline -- neither should send
expect(mockBatchAdd).not.toHaveBeenCalled()
})
})

describe('error handling', () => {
it('should handle missing DD_RUM gracefully', () => {
delete (window as any).DD_RUM
Expand Down
72 changes: 46 additions & 26 deletions packages/debugger/src/domain/api.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ import type { Batch, Context } from '@datadog/browser-core'
import { timeStampNow, display, buildTag, generateUUID, getGlobalObject } from '@datadog/browser-core'
import type { BrowserWindow, DebuggerInitConfiguration } from '../entries/main'
import { capture, captureFields } from './capture'
import type { CaptureContext } from './capture'
import type { InitializedProbe } from './probes'
import { checkGlobalSnapshotBudget } from './probes'
import type { ActiveEntry } from './activeEntries'
Expand All @@ -15,6 +16,8 @@ const globalObj = getGlobalObject<BrowserWindow>() // eslint-disable-line local-

const threadName = detectThreadName() // eslint-disable-line local-rules/disallow-side-effects

const SNAPSHOT_TIMEOUT_MS = 10

let debuggerBatch: Batch | undefined
let debuggerConfig: DebuggerInitConfiguration | undefined
let cachedDDtags: string | undefined
Expand All @@ -41,6 +44,7 @@ export function resetDebuggerTransport(): void {
*/
export function onEntry(probes: InitializedProbe[], self: any, args: Record<string, any>): void {
const start = performance.now()
const captureCtx: CaptureContext = { deadline: start + SNAPSHOT_TIMEOUT_MS, timedOut: false }
Comment thread
watson marked this conversation as resolved.

// TODO: A lot of repeated work performed for each probe that could be shared between probes
for (const probe of probes) {
Expand Down Expand Up @@ -81,14 +85,19 @@ export function onEntry(probes: InitializedProbe[], self: any, args: Record<stri

// Special case for evaluateAt=EXIT with a condition: we only capture the return snapshot
const shouldCaptureEntrySnapshot = probe.captureSnapshot && (probe.evaluateAt === 'ENTRY' || !probe.condition)
const entry = shouldCaptureEntrySnapshot
? {
arguments: {
...captureFields(args, probe.capture),
this: capture(self, probe.capture),
},
}
: undefined
let entry: { arguments: Record<string, any> } | undefined
if (shouldCaptureEntrySnapshot) {
entry = {
arguments: {
...captureFields(args, probe.capture, captureCtx),
this: capture(self, probe.capture, captureCtx),
},
}
if (captureCtx.timedOut) {
stack.push(null)
continue
}
}

stack.push({
start,
Expand Down Expand Up @@ -118,6 +127,7 @@ export function onReturn(
locals: Record<string, any>
): any {
const end = performance.now()
const captureCtx: CaptureContext = { deadline: performance.now() + SNAPSHOT_TIMEOUT_MS, timedOut: false }

// TODO: A lot of repeated work performed for each probe that could be shared between probes
for (const probe of probes) {
Expand Down Expand Up @@ -153,18 +163,21 @@ export function onReturn(
result.message = evaluateProbeMessage(probe, context)
}

result.return = probe.captureSnapshot
? {
arguments: {
...captureFields(args, probe.capture),
this: capture(self, probe.capture),
},
locals: {
...captureFields(locals, probe.capture),
'@return': capture(value, probe.capture),
},
}
: undefined
if (probe.captureSnapshot) {
result.return = {
arguments: {
...captureFields(args, probe.capture, captureCtx),
this: capture(self, probe.capture, captureCtx),
},
locals: {
...captureFields(locals, probe.capture, captureCtx),
'@return': capture(value, probe.capture, captureCtx),
},
}
if (captureCtx.timedOut) {
continue
}
}

sendDebuggerSnapshot(probe, result)
}
Expand All @@ -182,6 +195,7 @@ export function onReturn(
*/
export function onThrow(probes: InitializedProbe[], error: Error, self: any, args: Record<string, any>): void {
const end = performance.now()
const captureCtx: CaptureContext = { deadline: performance.now() + SNAPSHOT_TIMEOUT_MS, timedOut: false }

// TODO: A lot of repeated work performed for each probe that could be shared between probes
for (const probe of probes) {
Expand Down Expand Up @@ -217,13 +231,19 @@ export function onThrow(probes: InitializedProbe[], error: Error, self: any, arg
result.message = evaluateProbeMessage(probe, context)
}

let throwArguments: Record<string, any> | undefined
if (probe.captureSnapshot) {
throwArguments = {
...captureFields(args, probe.capture, captureCtx),
this: capture(self, probe.capture, captureCtx),
}
if (captureCtx.timedOut) {
continue
}
}

result.return = {
arguments: probe.captureSnapshot
? {
...captureFields(args, probe.capture),
this: capture(self, probe.capture),
}
: undefined,
arguments: throwArguments,
throwable: {
message: error.message,
stacktrace: parseStackTrace(error),
Expand Down
Loading
Loading