feat(debugger): add special handling for very large collections/objects

Handle edge cases where an object has a lot of properties, or where
collections (arrays/sets/maps) has a lot of elements.

In those cases, a single Chrome DevTools Protocol
`Debugger.getProperties` request will take a long time to serialize
their properties/elements, which can siginificantly overshoot the time
budget (as ongoing CDP requests are allowed to complete before aborting)

This is dealt with in the following way:

- Skip enumerating large collections (arrays/maps/sets) by parsing size from
  descriptions; mark with notCapturedReason: "collectionSize" and record size.
- Large objects are still collected the first time, but objects with
  >500 properties set a fatalSnapshotError to prevent future snapshot
  attempts for that probe and emits error to the diagnostics endpoint.

Author: watson

integration-tests/debugger/snapshot-time-budget.spec.js

@@ -2,10 +2,14 @@
 
 const assert = require('node:assert')
 const { setup } = require('./utils')
+const {
+  DEFAULT_MAX_COLLECTION_SIZE,
+  LARGE_OBJECT_SKIP_THRESHOLD
+} = require('../../packages/dd-trace/src/debugger/devtools_client/snapshot/constants')
 
 describe('Dynamic Instrumentation', function () {
   describe('input messages', function () {
-    describe('with snapshot under tight time budget', function () {
+    describe('with snapshot under time budget', function () {
       context('1ms time budget', function () {
         // Force a very small time budget in ms to trigger partial snapshots
         const budget = 1
@@ -17,57 +21,191 @@ describe('Dynamic Instrumentation', function () {
         it(
           'should include partial snapshot marked with notCapturedReason: timeout',
           // A tolerance of 15ms is used to avoid flakiness
-          test({ t, maxPausedTime: budget + 15, breakpointIndex: 0, maxReferenceDepth: 5 })
+          test({ t, maxPausedTime: budget + 15, breakpointIndex: 0, maxReferenceDepth: 5 }, (locals) => {
+            assert.strictEqual(
+              containsTimeBudget(locals),
+              true,
+              'expected at least one field/element to be marked with notCapturedReason: "timeout"'
+            )
+          })
         )
       })
 
       context('default time budget', function () {
-        const budget = 15 // default time budget in ms
         const t = setup({ dependencies: ['fastify'] })
 
-        // TODO: Make this pass
-        // eslint-disable-next-line mocha/no-pending-tests
-        it.skip(
-          'should keep budget when state includes an object with 1 million properties',
-          // A tolerance of 5ms is used to avoid flakiness
-          test({ t, maxPausedTime: budget + 5, breakpointIndex: 1, maxReferenceDepth: 1 })
+        it(
+          'should timeout first, then disable subsequent snapshots and emit error diagnostics',
+          async function () {
+            const breakpoint = t.breakpoints[1]
+
+            // Listen for the first snapshot payload (should contain notCapturedReason: "timeout")
+            const firstPayloadReceived = new Promise((resolve) => {
+              t.agent.once('debugger-input', ({ payload: [{ debugger: { snapshot: { captures } } }] }) => {
+                const { locals } = captures.lines[breakpoint.line]
+                resolve(locals)
+              })
+            })
+
+            // Prepare to assert that an ERROR diagnostics event with exception details is emitted
+            const errorDiagnosticsReceived = new Promise((/** @type {(value?: unknown) => void} */ resolve, reject) => {
+              const handler = ({ payload }) => {
+                payload.forEach(({ debugger: { diagnostics } }) => {
+                  if (diagnostics.status !== 'ERROR') return
+                  try {
+                    assert.strictEqual(
+                      diagnostics.exception.message,
+                      'An object with 1000000 properties was detected while collecting a snapshot. This exceeds the ' +
+                      'maximum number of allowed properties of 500. Future snapshots for existing probes in this ' +
+                      'location will be skipped until the Node.js process is restarted'
+                    )
+                    resolve()
+                  } catch (e) {
+                    reject(e)
+                  } finally {
+                    t.agent.off('debugger-diagnostics', handler)
+                  }
+                })
+              }
+              t.agent.on('debugger-diagnostics', handler)
+            })
+
+            // Install probe with snapshot capture enabled
+            t.agent.addRemoteConfig(breakpoint.generateRemoteConfig({
+              captureSnapshot: true,
+              capture: { maxReferenceDepth: 1 }
+            }))
+
+            // Trigger once; this run is expected to be slow and mark fields with "timeout"
+            const result1 = await breakpoint.triggerBreakpoint()
+            assert.ok(
+              result1.data.paused >= 1_000,
+              `expected thread to be paused for at least 1 second, but was paused for ~${result1.data.paused}ms`
+            )
+            const locals = await firstPayloadReceived
+            assert.strictEqual(
+              containsTimeBudget(locals),
+              true,
+              'expected at least one field/element to be marked with notCapturedReason: "timeout"'
+            )
+            await errorDiagnosticsReceived
+
+            // Prepare to assert that no snapshot is produced on a subsequent trigger
+            const noSnapshotAfterSecondTrigger = new Promise((/** @type {(value?: unknown) => void} */ resolve) => {
+              t.agent.once('debugger-input', ({ payload: [{ debugger: { snapshot: { captures } } }] }) => {
+                assert.strictEqual(captures, undefined)
+                resolve()
+              })
+            })
+
+            // Trigger the same breakpoint again directly
+            const result2 = await t.axios.get(breakpoint.url)
+            assert.ok(
+              result2.data.paused <= 5,
+              `expected thread to be paused <=5ms, but was paused for ~${result2.data.paused}ms`
+            )
+
+            await noSnapshotAfterSecondTrigger
+          }
         )
+      })
+
+      context('large object thresholds', function () {
+        // The tests in this group, should take a lot longer than 100ms to capture a snapshot if no thresholds are
+        // applied. But they should take a lot less than the 100ms budget if thresholds are applied. Using 100ms means
+        // that the tests should not be flaky, but still fail if the thresholds are not applied.
+        const budget = 100
+        const t = setup({
+          dependencies: ['fastify'],
+          env: { DD_DYNAMIC_INSTRUMENTATION_CAPTURE_TIMEOUT_MS: String(budget) }
+        })
 
-        // TODO: Make this pass
-        // eslint-disable-next-line mocha/no-pending-tests
-        it.skip(
-          'should keep budget when state includes an array of 1 million primitives',
-          // A tolerance of 5ms is used to avoid flakiness
-          test({ t, maxPausedTime: budget + 5, breakpointIndex: 2, maxReferenceDepth: 1 })
+        it(
+          'should keep budget when state includes collections with 1 million elements',
+          test({ t, maxPausedTime: budget, breakpointIndex: 2, maxReferenceDepth: 1 }, (locals) => {
+            const notCapturedReason = `Large collection with too many elements (skip threshold: ${
+              LARGE_OBJECT_SKIP_THRESHOLD
+            })`
+            assert.strictEqual(locals.arrOfPrimitives.notCapturedReason, notCapturedReason)
+            assert.strictEqual(locals.arrOfPrimitives.size, 1_000_000)
+            assert.strictEqual(locals.arrOfPrimitives.elements.length, 0)
+            assert.strictEqual(locals.arrOfObjects.notCapturedReason, notCapturedReason)
+            assert.strictEqual(locals.arrOfObjects.size, 1_000_000)
+            assert.strictEqual(locals.arrOfObjects.elements.length, 0)
+            assert.strictEqual(locals.map.notCapturedReason, notCapturedReason)
+            assert.strictEqual(locals.map.size, 1_000_000)
+            assert.strictEqual(locals.map.entries.length, 0)
+            assert.strictEqual(locals.set.notCapturedReason, notCapturedReason)
+            assert.strictEqual(locals.set.size, 1_000_000)
+            assert.strictEqual(locals.set.elements.length, 0)
+          })
         )
 
-        // TODO: Make this pass
-        // eslint-disable-next-line mocha/no-pending-tests
-        it.skip(
-          'should keep budget when state includes an array of 1 million objects',
-          // A tolerance of 5ms is used to avoid flakiness
-          test({ t, maxPausedTime: budget + 5, breakpointIndex: 3, maxReferenceDepth: 1 })
+        it(
+          'should keep budget when state includes collections with less than the size threshold',
+          test({ t, maxPausedTime: budget, breakpointIndex: 3, maxReferenceDepth: 1 }, (locals) => {
+            assert.strictEqual(locals.arrOfPrimitives.notCapturedReason, 'collectionSize')
+            assert.strictEqual(locals.arrOfPrimitives.size, LARGE_OBJECT_SKIP_THRESHOLD - 1)
+            assert.strictEqual(locals.arrOfPrimitives.elements.length, DEFAULT_MAX_COLLECTION_SIZE)
+            assert.strictEqual(locals.arrOfObjects.notCapturedReason, 'collectionSize')
+            assert.strictEqual(locals.arrOfObjects.size, LARGE_OBJECT_SKIP_THRESHOLD - 1)
+            assert.strictEqual(locals.arrOfObjects.elements.length, DEFAULT_MAX_COLLECTION_SIZE)
+            assert.strictEqual(locals.map.notCapturedReason, 'collectionSize')
+            assert.strictEqual(locals.map.size, LARGE_OBJECT_SKIP_THRESHOLD - 1)
+            assert.strictEqual(locals.map.entries.length, DEFAULT_MAX_COLLECTION_SIZE)
+            assert.strictEqual(locals.set.notCapturedReason, 'collectionSize')
+            assert.strictEqual(locals.set.size, LARGE_OBJECT_SKIP_THRESHOLD - 1)
+            assert.strictEqual(locals.set.elements.length, DEFAULT_MAX_COLLECTION_SIZE)
+          })
         )
       })
+
+      context('fuzzing', function () {
+        for (let budget = 0; budget < 20; budget++) {
+          context(`graceful handling with time budget of ${budget}ms`, function () {
+            // Anything longer than this, and the debugger worker thread most likely crashed.
+            // Run test with `DD_TRACE_DEBUG=true` to see more.
+            this.timeout(2000)
+
+            const t = setup({
+              dependencies: ['fastify'],
+              env: { DD_DYNAMIC_INSTRUMENTATION_CAPTURE_TIMEOUT_MS: String(budget) }
+            })
+
+            // If this test uncovers any issues, it will show itself as being flaky, as the exact timing of how long it
+            // takes to collect the snapshot is not deterministic.
+            it('should send a probe result to the agent', async function () {
+              t.agent.addRemoteConfig(t.generateRemoteConfig({
+                captureSnapshot: true,
+                capture: { maxReferenceDepth: 5 }
+              }))
+              t.triggerBreakpoint()
+
+              const { captures } = await t.snapshotReceived()
+              // If the snapshot contains a `captures` field, it means it was captured and processes without any issues
+              assert.ok(
+                captures !== null && typeof captures === 'object',
+                'expected snapshot to contain a `captures` object'
+              )
+              // To make this test more future-proof, we also assert that the snapshot contains at least one local
+              // property, though currently this is not necessary.
+              assert.ok(
+                Object.keys(captures.lines[t.breakpoint.line].locals).length > 0,
+                'expected snapshot to contain at least one local property'
+              )
+            })
+          })
+        }
+      })
     })
   })
 })
 
-function test ({ t, maxPausedTime, breakpointIndex, maxReferenceDepth }) {
+function test ({ t, maxPausedTime = 0, breakpointIndex, maxReferenceDepth }, assertFn) {
   const breakpoint = t.breakpoints[breakpointIndex]
 
   return async function () {
-    const payloadReceived = new Promise((/** @type {(value?: unknown) => void} */ resolve) => {
-      t.agent.on('debugger-input', ({ payload: [{ debugger: { snapshot: { captures } } }] }) => {
-        const { locals } = captures.lines[breakpoint.line]
-        assert.strictEqual(
-          containsTimeBudget(locals),
-          true,
-          'expected at least one field/element to be marked with notCapturedReason: "timeout"'
-        )
-        resolve()
-      })
-    })
+    const snapshotPromise = t.snapshotReceived()
 
     t.agent.addRemoteConfig(breakpoint.generateRemoteConfig({
       captureSnapshot: true,
@@ -81,7 +219,8 @@ function test ({ t, maxPausedTime, breakpointIndex, maxReferenceDepth }) {
       `expected thread to be paused <=${maxPausedTime}ms, but was paused for ~${data.paused}ms`
     )
 
-    await payloadReceived
+    const snapshot = await snapshotPromise
+    assertFn?.(snapshot.captures.lines[breakpoint.line].locals)
   }
 }
 

integration-tests/debugger/target-app/snapshot-time-budget.js

@@ -3,6 +3,9 @@
 require('dd-trace/init')
 
 const Fastify = require('fastify')
+const {
+  LARGE_OBJECT_SKIP_THRESHOLD
+} = require('dd-trace/packages/dd-trace/src/debugger/devtools_client/snapshot/constants')
 
 const fastify = Fastify({ logger: { level: 'error' } })
 
@@ -16,24 +19,31 @@ fastify.get('/deeply-nested-large-object', function handler () {
   return { paused: Number(diff) / 1_000_000 }
 })
 
-fastify.get('/large-object-of-primitives', function handler () {
+fastify.get('/object-with-many-properties', function handler () {
   const obj = generateObject(0, 1_000_000) // eslint-disable-line no-unused-vars
   const start = process.hrtime.bigint()
-  const diff = process.hrtime.bigint() - start // BREAKPOINT: /large-object-of-primitives
+  const diff = process.hrtime.bigint() - start // BREAKPOINT: /object-with-many-properties
   return { paused: Number(diff) / 1_000_000 }
 })
 
-fastify.get('/large-array-of-primitives', function handler () {
-  const arr = Array.from({ length: 1_000_000 }, (_, i) => i) // eslint-disable-line no-unused-vars
+fastify.get('/large-collections', function handler () {
+  const arrOfPrimitives = Array.from({ length: 1_000_000 }, (_, i) => i) // eslint-disable-line no-unused-vars
+  const arrOfObjects = Array.from({ length: 1_000_000 }, (_, i) => ({ i }))
+  const map = new Map(arrOfObjects.map((obj, i) => [i, obj])) // eslint-disable-line no-unused-vars
+  const set = new Set(arrOfObjects) // eslint-disable-line no-unused-vars
   const start = process.hrtime.bigint()
-  const diff = process.hrtime.bigint() - start // BREAKPOINT: /large-array-of-primitives
+  const diff = process.hrtime.bigint() - start // BREAKPOINT: /large-collections
   return { paused: Number(diff) / 1_000_000 }
 })
 
-fastify.get('/large-array-of-objects', function handler () {
-  const arr = Array.from({ length: 1_000_000 }, (_, i) => ({ i })) // eslint-disable-line no-unused-vars
+fastify.get('/large-collections-below-size-threshold', function handler () {
+  // eslint-disable-next-line no-unused-vars
+  const arrOfPrimitives = Array.from({ length: LARGE_OBJECT_SKIP_THRESHOLD - 1 }, (_, i) => i)
+  const arrOfObjects = Array.from({ length: LARGE_OBJECT_SKIP_THRESHOLD - 1 }, (_, i) => ({ i }))
+  const map = new Map(arrOfObjects.map((obj, i) => [i, obj])) // eslint-disable-line no-unused-vars
+  const set = new Set(arrOfObjects) // eslint-disable-line no-unused-vars
   const start = process.hrtime.bigint()
-  const diff = process.hrtime.bigint() - start // BREAKPOINT: /large-array-of-objects
+  const diff = process.hrtime.bigint() - start // BREAKPOINT: /large-collections-below-size-threshold
   return { paused: Number(diff) / 1_000_000 }
 })
 

integration-tests/debugger/utils.js

@@ -38,7 +38,15 @@ function setup ({ env, testApp, testAppSource, dependencies, silent, stdioHandle
     rcConfig: null,
     triggerBreakpoint: triggerBreakpoint.bind(null, breakpoints[0].url),
     generateRemoteConfig: generateRemoteConfig.bind(null, breakpoints[0]),
-    generateProbeConfig: generateProbeConfig.bind(null, breakpoints[0])
+    generateProbeConfig: generateProbeConfig.bind(null, breakpoints[0]),
+
+    snapshotReceived () {
+      return new Promise((/** @type {(value?: object) => void} */ resolve) => {
+        t.agent.on('debugger-input', ({ payload: [{ debugger: { snapshot } }] }) => {
+          resolve(snapshot)
+        })
+      })
+    }
   }
 
   // Allow specific access to each breakpoint

packages/dd-trace/src/ci-visibility/dynamic-instrumentation/worker/index.js

@@ -36,7 +36,7 @@ session.on('Debugger.paused', async ({ params: { hitBreakpoints: [hitBreakpoint]
 
   const stack = getStackFromCallFrames(callFrames)
 
-  const getLocalState = await getLocalStateForCallFrame(callFrames[0])
+  const { processLocalState } = await getLocalStateForCallFrame(callFrames[0])
 
   await session.post('Debugger.resume')
 
@@ -48,17 +48,13 @@ session.on('Debugger.paused', async ({ params: { hitBreakpoints: [hitBreakpoint]
       version: '0',
       location: probe.location
     },
+    captures: {
+      lines: { [probe.location.lines[0]]: { locals: processLocalState() } }
+    },
     stack,
     language: 'javascript'
   }
 
-  const state = getLocalState()
-  if (state) {
-    snapshot.captures = {
-      lines: { [probe.location.lines[0]]: { locals: state } }
-    }
-  }
-
   breakpointHitChannel.postMessage({ snapshot })
 })