[Debugger] improve snapshot performance (#5419)

The sync code got a tad optimized (dense instead of sparse arrays
and some other minor improvements). The async parts now also run in
parallel.
These changes do not make a big difference effectively due to the
overhead of the inspector calls themselves.

Co-authored-by: Thomas Watson <w@tson.dk>

Author: BridgeAR

integration-tests/debugger/redact.spec.js

@@ -2,48 +2,47 @@
 
 const { assert } = require('chai')
 const { setup } = require('./utils')
+const { once } = require('node:events')
 
 // Default settings is tested in unit tests, so we only need to test the env vars here
 describe('Dynamic Instrumentation snapshot PII redaction', function () {
   describe('DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS=foo,bar', function () {
     const t = setup({ env: { DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS: 'foo,bar' } })
 
-    it('should respect DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS', function (done) {
+    it('should respect DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS', async function () {
       t.triggerBreakpoint()
 
-      t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => {
-        const { locals } = captures.lines[t.breakpoint.line]
+      const promise = once(t.agent, 'debugger-input')
 
-        assert.deepPropertyVal(locals, 'foo', { type: 'string', notCapturedReason: 'redactedIdent' })
-        assert.deepPropertyVal(locals, 'bar', { type: 'string', notCapturedReason: 'redactedIdent' })
-        assert.deepPropertyVal(locals, 'baz', { type: 'string', value: 'c' })
+      t.agent.addRemoteConfig(t.generateRemoteConfig({ captureSnapshot: true }))
 
-        // existing redaction should not be impacted
-        assert.deepPropertyVal(locals, 'secret', { type: 'string', notCapturedReason: 'redactedIdent' })
+      const [{ payload: [{ 'debugger.snapshot': { captures } }] }] = await promise
+      const { locals } = captures.lines[t.breakpoint.line]
 
-        done()
-      })
+      assert.deepPropertyVal(locals, 'foo', { type: 'string', notCapturedReason: 'redactedIdent' })
+      assert.deepPropertyVal(locals, 'bar', { type: 'string', notCapturedReason: 'redactedIdent' })
+      assert.deepPropertyVal(locals, 'baz', { type: 'string', value: 'c' })
 
-      t.agent.addRemoteConfig(t.generateRemoteConfig({ captureSnapshot: true }))
+      // existing redaction should not be impacted
+      assert.deepPropertyVal(locals, 'secret', { type: 'string', notCapturedReason: 'redactedIdent' })
     })
   })
 
   describe('DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS=secret', function () {
     const t = setup({ env: { DD_DYNAMIC_INSTRUMENTATION_REDACTION_EXCLUDED_IDENTIFIERS: 'secret' } })
 
-    it('should respect DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS', function (done) {
+    it('should respect DD_DYNAMIC_INSTRUMENTATION_REDACTED_IDENTIFIERS', async function () {
       t.triggerBreakpoint()
 
-      t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => {
-        const { locals } = captures.lines[t.breakpoint.line]
+      const promise = once(t.agent, 'debugger-input')
 
-        assert.deepPropertyVal(locals, 'secret', { type: 'string', value: 'shh!' })
-        assert.deepPropertyVal(locals, 'password', { type: 'string', notCapturedReason: 'redactedIdent' })
+      t.agent.addRemoteConfig(t.generateRemoteConfig({ captureSnapshot: true }))
 
-        done()
-      })
+      const [{ payload: [{ 'debugger.snapshot': { captures } }] }] = await promise
+      const { locals } = captures.lines[t.breakpoint.line]
 
-      t.agent.addRemoteConfig(t.generateRemoteConfig({ captureSnapshot: true }))
+      assert.deepPropertyVal(locals, 'secret', { type: 'string', value: 'shh!' })
+      assert.deepPropertyVal(locals, 'password', { type: 'string', notCapturedReason: 'redactedIdent' })
     })
   })
 })

integration-tests/debugger/snapshot-global-sample-rate.spec.js

@@ -59,8 +59,8 @@ describe('Dynamic Instrumentation', function () {
               const duration = timestamp - start
               const timeSincePrevTimestamp = timestamp - prevTimestamp
 
-              // Allow for a variance of +50ms (time will tell if this is enough)
-              assert.isAtLeast(duration, 1000)
+              // Allow for a time variance (time will tell if this is enough). Timeouts can vary.
+              assert.isAtLeast(duration, 925)
               assert.isBelow(duration, 1050)
 
               // A sanity check to make sure we're not saturating the event loop. We expect a lot of snapshots to be

integration-tests/debugger/snapshot.spec.js

@@ -208,11 +208,11 @@ describe('Dynamic Instrumentation', function () {
         t.agent.on('debugger-input', ({ payload: [{ 'debugger.snapshot': { captures } }] }) => {
           const { locals } = captures.lines[t.breakpoint.line]
 
-          assert.deepEqual(Object.keys(locals), [
-            // Up to 3 properties from the local scope
-            'request', 'nil', 'undef',
+          assert.deepStrictEqual(Object.keys(locals), [
             // Up to 3 properties from the closure scope
-            'fastify', 'getUndefined'
+            'fastify', 'getUndefined',
+            // Up to 3 properties from the local scope
+            'request', 'nil', 'undef'
           ])
 
           assert.strictEqual(locals.request.type, 'Request')

integration-tests/helpers/fake-agent.js

@@ -10,7 +10,8 @@ const upload = require('multer')()
 
 module.exports = class FakeAgent extends EventEmitter {
   constructor (port = 0) {
-    super()
+    // Redirect rejections to the error event
+    super({ captureRejections: true })
     this.port = port
     this.resetRemoteConfig()
   }

packages/dd-trace/src/debugger/devtools_client/index.js

@@ -35,13 +35,13 @@ session.on('Debugger.paused', async ({ params }) => {
 
   let maxReferenceDepth, maxCollectionSize, maxFieldCount, maxLength
 
-  // V8 doesn't allow seting more than one breakpoint at a specific location, however, it's possible to set two
-  // breakpoints just next to eachother that will "snap" to the same logical location, which in turn will be hit at the
+  // V8 doesn't allow setting more than one breakpoint at a specific location, however, it's possible to set two
+  // breakpoints just next to each other that will "snap" to the same logical location, which in turn will be hit at the
   // same time. E.g. index.js:1:1 and index.js:1:2.
   // TODO: Investigate if it will improve performance to create a fast-path for when there's only a single breakpoint
   let sampled = false
   const length = params.hitBreakpoints.length
-  let probes = new Array(length)
+  const probes = []
   // TODO: Consider reusing this array between pauses and only recreating it if it needs to grow
   const snapshotProbeIndex = new Uint8Array(length) // TODO: Is a limit of 256 probes ever going to be a problem?
   let numberOfProbesWithSnapshots = 0
@@ -65,7 +65,7 @@ session.on('Debugger.paused', async ({ params }) => {
         snapshotsSampledWithinTheLastSecond++
       }
 
-      snapshotProbeIndex[numberOfProbesWithSnapshots++] = i
+      snapshotProbeIndex[numberOfProbesWithSnapshots++] = probes.length
       maxReferenceDepth = highestOrUndefined(probe.capture.maxReferenceDepth, maxReferenceDepth)
       maxCollectionSize = highestOrUndefined(probe.capture.maxCollectionSize, maxCollectionSize)
       maxFieldCount = highestOrUndefined(probe.capture.maxFieldCount, maxFieldCount)
@@ -75,7 +75,7 @@ session.on('Debugger.paused', async ({ params }) => {
     sampled = true
     probe.lastCaptureNs = start
 
-    probes[i] = probe
+    probes.push(probe)
   }
 
   if (sampled === false) {
@@ -108,9 +108,6 @@ session.on('Debugger.paused', async ({ params }) => {
     Number(diff) / 1000000
   )
 
-  // Due to the highly optimized algorithm above, the `probes` array might have gaps
-  probes = probes.filter((probe) => !!probe)
-
   const logger = {
     // We can safely use `location.file` from the first probe in the array, since all probes hit by `hitBreakpoints`
     // must exist in the same file since the debugger can only pause the main thread in one location.

packages/dd-trace/src/debugger/devtools_client/snapshot/collector.js

@@ -10,11 +10,6 @@ module.exports = {
   getRuntimeObject: getObject
 }
 
-// TODO: Can we speed up thread pause time by calling mutiple Runtime.getProperties in parallel when possible?
-// The most simple solution would be to swich from an async/await approach to a callback based approach, in which case
-// each lookup will just finish in its own time and traverse the child nodes when the event loop allows it.
-// Alternatively, use `Promise.all` or something like that, but the code would probably be more complex.
-
 async function getObject (objectId, opts, depth = 0, collection = false) {
   const { result, privateProperties } = await session.post('Runtime.getProperties', {
     objectId,
@@ -27,13 +22,13 @@ async function getObject (objectId, opts, depth = 0, collection = false) {
     removeNonEnumerableProperties(result) // remove the `length` property
     const size = result.length
     if (size > opts.maxCollectionSize) {
-      result.splice(opts.maxCollectionSize)
+      result.length = opts.maxCollectionSize
       result[collectionSizeSym] = size
     }
   } else if (result.length > opts.maxFieldCount) {
     // Trim the number of properties on the object if there's too many.
     const size = result.length
-    result.splice(opts.maxFieldCount)
+    result.length = opts.maxFieldCount
     result[fieldCountSym] = size
   } else if (privateProperties) {
     result.push(...privateProperties)
@@ -48,18 +43,28 @@ async function traverseGetPropertiesResult (props, opts, depth) {
 
   if (depth >= opts.maxReferenceDepth) return props
 
+  const promises = []
+
   for (const prop of props) {
     if (prop.value === undefined) continue
     const { value: { type, objectId, subtype } } = prop
     if (type === 'object') {
       if (objectId === undefined) continue // if `subtype` is "null"
       if (LEAF_SUBTYPES.has(subtype)) continue // don't waste time with these subtypes
-      prop.value.properties = await getObjectProperties(subtype, objectId, opts, depth)
+      promises.push(getObjectProperties(subtype, objectId, opts, depth).then((properties) => {
+        prop.value.properties = properties
+      }))
     } else if (type === 'function') {
-      prop.value.properties = await getFunctionProperties(objectId, opts, depth + 1)
+      promises.push(getFunctionProperties(objectId, opts, depth + 1).then((properties) => {
+        prop.value.properties = properties
+      }))
     }
   }
 
+  if (promises.length) {
+    await Promise.all(promises)
+  }
+
   return props
 }
 
@@ -115,7 +120,7 @@ async function getIterable (objectId, opts, depth) {
   removeNonEnumerableProperties(result) // remove the `length` property
   const size = result.length
   if (size > opts.maxCollectionSize) {
-    result.splice(opts.maxCollectionSize)
+    result.length = opts.maxCollectionSize
     result[collectionSizeSym] = size
   }
 

packages/dd-trace/src/debugger/devtools_client/snapshot/index.js

@@ -24,13 +24,13 @@ async function getLocalStateForCallFrame (
   const rawState = []
   let processedState = null
 
-  for (const scope of callFrame.scopeChain) {
-    if (scope.type === 'global') continue // The global scope is too noisy
+  await Promise.all(callFrame.scopeChain.map(async (scope) => {
+    if (scope.type === 'global') return // The global scope is too noisy
     rawState.push(...await getRuntimeObject(
       scope.object.objectId,
       { maxReferenceDepth, maxCollectionSize, maxFieldCount }
     ))
-  }
+  }))
 
   // Deplay calling `processRawState` so the caller gets a chance to resume the main thread before processing `rawState`
   return () => {