Skip to content

Commit d73f8cb

Browse files
authored
[DI] Add a global max snapshot sample rate of 25/second (#5081)
Each enhanced log probe has a sample rate of one second. However, too many individual probes might still overload the system, so a global snapshot sample rate across all enhanced log probes is required.
1 parent 4886c38 commit d73f8cb

3 files changed

Lines changed: 119 additions & 9 deletions

File tree

Lines changed: 91 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,91 @@
1+
'use strict'
2+
3+
const { assert } = require('chai')
4+
const { setup } = require('./utils')
5+
6+
describe('Dynamic Instrumentation', function () {
7+
const t = setup({
8+
testApp: 'target-app/basic.js'
9+
})
10+
11+
describe('input messages', function () {
12+
describe('with snapshot', function () {
13+
beforeEach(t.triggerBreakpoint)
14+
15+
it('should respect global max snapshot sampling rate', function (_done) {
16+
const MAX_SNAPSHOTS_PER_SECOND_GLOBALLY = 25
17+
const snapshotsPerSecond = MAX_SNAPSHOTS_PER_SECOND_GLOBALLY * 2
18+
const probeConf = { captureSnapshot: true, sampling: { snapshotsPerSecond } }
19+
let start = 0
20+
let hitBreakpoints = 0
21+
let isDone = false
22+
let prevTimestamp
23+
24+
const rcConfig1 = t.breakpoints[0].generateRemoteConfig(probeConf)
25+
const rcConfig2 = t.breakpoints[1].generateRemoteConfig(probeConf)
26+
27+
// Two breakpoints, each triggering a request every 10ms, so we should get 200 requests per second
28+
const state = {
29+
[rcConfig1.config.id]: {
30+
tiggerBreakpointContinuously () {
31+
t.axios.get(t.breakpoints[0].url).catch(done)
32+
this.timer = setTimeout(this.tiggerBreakpointContinuously.bind(this), 10)
33+
}
34+
},
35+
[rcConfig2.config.id]: {
36+
tiggerBreakpointContinuously () {
37+
t.axios.get(t.breakpoints[1].url).catch(done)
38+
this.timer = setTimeout(this.tiggerBreakpointContinuously.bind(this), 10)
39+
}
40+
}
41+
}
42+
43+
t.agent.on('debugger-diagnostics', ({ payload }) => {
44+
payload.forEach((event) => {
45+
const { probeId, status } = event.debugger.diagnostics
46+
if (status === 'INSTALLED') {
47+
state[probeId].tiggerBreakpointContinuously()
48+
}
49+
})
50+
})
51+
52+
t.agent.on('debugger-input', ({ payload }) => {
53+
payload.forEach(({ 'debugger.snapshot': { timestamp } }) => {
54+
if (isDone) return
55+
if (start === 0) start = timestamp
56+
if (++hitBreakpoints <= MAX_SNAPSHOTS_PER_SECOND_GLOBALLY) {
57+
prevTimestamp = timestamp
58+
} else {
59+
const duration = timestamp - start
60+
const timeSincePrevTimestamp = timestamp - prevTimestamp
61+
62+
// Allow for a variance of +50ms (time will tell if this is enough)
63+
assert.isAtLeast(duration, 1000)
64+
assert.isBelow(duration, 1050)
65+
66+
// A sanity check to make sure we're not saturating the event loop. We expect a lot of snapshots to be
67+
// sampled in the beginning of the sample window and then once the threshold is hit, we expect a "quiet"
68+
// period until the end of the window. If there's no "quiet" period, then we're saturating the event loop
69+
// and this test isn't really testing anything.
70+
assert.isAtLeast(timeSincePrevTimestamp, 250)
71+
72+
clearTimeout(state[rcConfig1.config.id].timer)
73+
clearTimeout(state[rcConfig2.config.id].timer)
74+
75+
done()
76+
}
77+
})
78+
})
79+
80+
t.agent.addRemoteConfig(rcConfig1)
81+
t.agent.addRemoteConfig(rcConfig2)
82+
83+
function done (err) {
84+
if (isDone) return
85+
isDone = true
86+
_done(err)
87+
}
88+
})
89+
})
90+
})
91+
})
Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
'use strict'
22

33
module.exports = {
4+
MAX_SNAPSHOTS_PER_SECOND_GLOBALLY: 25,
45
MAX_SNAPSHOTS_PER_SECOND_PER_PROBE: 1,
56
MAX_NON_SNAPSHOTS_PER_SECOND_PER_PROBE: 5_000
67
}

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

Lines changed: 27 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ const send = require('./send')
88
const { getStackFromCallFrames } = require('./state')
99
const { ackEmitting, ackError } = require('./status')
1010
const { parentThreadId } = require('./config')
11+
const { MAX_SNAPSHOTS_PER_SECOND_GLOBALLY } = require('./defaults')
1112
const log = require('../../log')
1213
const { version } = require('../../../../../package.json')
1314

@@ -24,11 +25,14 @@ const expression = `
2425
const threadId = parentThreadId === 0 ? `pid:${process.pid}` : `pid:${process.pid};tid:${parentThreadId}`
2526
const threadName = parentThreadId === 0 ? 'MainThread' : `WorkerThread:${parentThreadId}`
2627

28+
const oneSecondNs = BigInt(1_000_000_000)
29+
let globalSnapshotSamplingRateWindowStart = BigInt(0)
30+
let snapshotsSampledWithinTheLastSecond = 0
31+
2732
// WARNING: The code above the line `await session.post('Debugger.resume')` is highly optimized. Please edit with care!
2833
session.on('Debugger.paused', async ({ params }) => {
2934
const start = process.hrtime.bigint()
3035

31-
let captureSnapshotForProbe = null
3236
let maxReferenceDepth, maxCollectionSize, maxFieldCount, maxLength
3337

3438
// V8 doesn't allow seting more than one breakpoint at a specific location, however, it's possible to set two
@@ -38,6 +42,9 @@ session.on('Debugger.paused', async ({ params }) => {
3842
let sampled = false
3943
const length = params.hitBreakpoints.length
4044
let probes = new Array(length)
45+
// TODO: Consider reusing this array between pauses and only recreating it if it needs to grow
46+
const snapshotProbeIndex = new Uint8Array(length) // TODO: Is a limit of 256 probes ever going to be a problem?
47+
let numberOfProbesWithSnapshots = 0
4148
for (let i = 0; i < length; i++) {
4249
const id = params.hitBreakpoints[i]
4350
const probe = breakpoints.get(id)
@@ -46,17 +53,28 @@ session.on('Debugger.paused', async ({ params }) => {
4653
continue
4754
}
4855

49-
sampled = true
50-
probe.lastCaptureNs = start
51-
5256
if (probe.captureSnapshot === true) {
53-
captureSnapshotForProbe = probe
57+
// This algorithm to calculate number of sampled snapshots within the last second is not perfect, as it's not a
58+
// sliding window. But it's quick and easy :)
59+
if (i === 0 && start - globalSnapshotSamplingRateWindowStart > oneSecondNs) {
60+
snapshotsSampledWithinTheLastSecond = 1
61+
globalSnapshotSamplingRateWindowStart = start
62+
} else if (snapshotsSampledWithinTheLastSecond >= MAX_SNAPSHOTS_PER_SECOND_GLOBALLY) {
63+
continue
64+
} else {
65+
snapshotsSampledWithinTheLastSecond++
66+
}
67+
68+
snapshotProbeIndex[numberOfProbesWithSnapshots++] = i
5469
maxReferenceDepth = highestOrUndefined(probe.capture.maxReferenceDepth, maxReferenceDepth)
5570
maxCollectionSize = highestOrUndefined(probe.capture.maxCollectionSize, maxCollectionSize)
5671
maxFieldCount = highestOrUndefined(probe.capture.maxFieldCount, maxFieldCount)
5772
maxLength = highestOrUndefined(probe.capture.maxLength, maxLength)
5873
}
5974

75+
sampled = true
76+
probe.lastCaptureNs = start
77+
6078
probes[i] = probe
6179
}
6280

@@ -68,17 +86,17 @@ session.on('Debugger.paused', async ({ params }) => {
6886
const dd = await getDD(params.callFrames[0].callFrameId)
6987

7088
let processLocalState
71-
if (captureSnapshotForProbe !== null) {
89+
if (numberOfProbesWithSnapshots !== 0) {
7290
try {
7391
// TODO: Create unique states for each affected probe based on that probes unique `capture` settings (DEBUG-2863)
7492
processLocalState = await getLocalStateForCallFrame(
7593
params.callFrames[0],
7694
{ maxReferenceDepth, maxCollectionSize, maxFieldCount, maxLength }
7795
)
7896
} catch (err) {
79-
// TODO: This error is not tied to a specific probe, but to all probes with `captureSnapshot: true`.
80-
// However, in 99,99% of cases, there will be just a single probe, so I guess this simplification is ok?
81-
ackError(err, captureSnapshotForProbe) // TODO: Ok to continue after sending ackError?
97+
for (let i = 0; i < numberOfProbesWithSnapshots; i++) {
98+
ackError(err, probes[snapshotProbeIndex[i]]) // TODO: Ok to continue after sending ackError?
99+
}
82100
}
83101
}
84102

0 commit comments

Comments
 (0)