Skip to content

Commit 5dc601a

Browse files
timfishcadesalaberry
authored andcommitted
fix(node): Send ANR events without scope if event loop blocked indefinitely (getsentry#11578)
When experimenting for getsentry#11525 I found that `Runtime.evaluate` only returns when the event loop becomes unblocked. This means that we are not sending ANR events if the event loop is blocked indefinitely. This PR adds a timeout that sends the ANR event if we have not been able to evaluate the scope within 5 seconds.
1 parent 474ca00 commit 5dc601a

File tree

3 files changed

+65
-16
lines changed

3 files changed

+65
-16
lines changed
Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,31 @@
1+
import * as assert from 'assert';
2+
import * as crypto from 'crypto';
3+
4+
import * as Sentry from '@sentry/node';
5+
6+
setTimeout(() => {
7+
process.exit();
8+
}, 10000);
9+
10+
Sentry.init({
11+
dsn: process.env.SENTRY_DSN,
12+
release: '1.0',
13+
autoSessionTracking: false,
14+
integrations: [Sentry.anrIntegration({ captureStackTrace: true, anrThreshold: 100 })],
15+
});
16+
17+
Sentry.setUser({ email: '[email protected]' });
18+
Sentry.addBreadcrumb({ message: 'important message!' });
19+
20+
function longWork() {
21+
// This loop will run almost indefinitely
22+
for (let i = 0; i < 2000000000; i++) {
23+
const salt = crypto.randomBytes(128).toString('base64');
24+
const hash = crypto.pbkdf2Sync('myPassword', salt, 10000, 512, 'sha512');
25+
assert.ok(hash);
26+
}
27+
}
28+
29+
setTimeout(() => {
30+
longWork();
31+
}, 1000);

dev-packages/node-integration-tests/suites/anr/test.ts

Lines changed: 24 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
import { conditionalTest } from '../../utils';
22
import { cleanupChildProcesses, createRunner } from '../../utils/runner';
33

4-
const EXPECTED_ANR_EVENT = {
4+
const ANR_EVENT = {
55
// Ensure we have context
66
contexts: {
77
trace: {
@@ -21,15 +21,6 @@ const EXPECTED_ANR_EVENT = {
2121
timezone: expect.any(String),
2222
},
2323
},
24-
user: {
25-
26-
},
27-
breadcrumbs: [
28-
{
29-
timestamp: expect.any(Number),
30-
message: 'important message!',
31-
},
32-
],
3324
// and an exception that is our ANR
3425
exception: {
3526
values: [
@@ -60,24 +51,41 @@ const EXPECTED_ANR_EVENT = {
6051
},
6152
};
6253

54+
const ANR_EVENT_WITH_SCOPE = {
55+
...ANR_EVENT,
56+
user: {
57+
58+
},
59+
breadcrumbs: [
60+
{
61+
timestamp: expect.any(Number),
62+
message: 'important message!',
63+
},
64+
],
65+
};
66+
6367
conditionalTest({ min: 16 })('should report ANR when event loop blocked', () => {
6468
afterAll(() => {
6569
cleanupChildProcesses();
6670
});
6771

6872
test('CJS', done => {
69-
createRunner(__dirname, 'basic.js').withMockSentryServer().expect({ event: EXPECTED_ANR_EVENT }).start(done);
73+
createRunner(__dirname, 'basic.js').withMockSentryServer().expect({ event: ANR_EVENT_WITH_SCOPE }).start(done);
7074
});
7175

7276
test('ESM', done => {
73-
createRunner(__dirname, 'basic.mjs').withMockSentryServer().expect({ event: EXPECTED_ANR_EVENT }).start(done);
77+
createRunner(__dirname, 'basic.mjs').withMockSentryServer().expect({ event: ANR_EVENT_WITH_SCOPE }).start(done);
78+
});
79+
80+
test('blocked indefinitely', done => {
81+
createRunner(__dirname, 'indefinite.mjs').withMockSentryServer().expect({ event: ANR_EVENT }).start(done);
7482
});
7583

7684
test('With --inspect', done => {
7785
createRunner(__dirname, 'basic.mjs')
7886
.withMockSentryServer()
7987
.withFlags('--inspect')
80-
.expect({ event: EXPECTED_ANR_EVENT })
88+
.expect({ event: ANR_EVENT_WITH_SCOPE })
8189
.start(done);
8290
});
8391

@@ -108,16 +116,16 @@ conditionalTest({ min: 16 })('should report ANR when event loop blocked', () =>
108116
abnormal_mechanism: 'anr_foreground',
109117
},
110118
})
111-
.expect({ event: EXPECTED_ANR_EVENT })
119+
.expect({ event: ANR_EVENT_WITH_SCOPE })
112120
.start(done);
113121
});
114122

115123
test('from forked process', done => {
116-
createRunner(__dirname, 'forker.js').expect({ event: EXPECTED_ANR_EVENT }).start(done);
124+
createRunner(__dirname, 'forker.js').expect({ event: ANR_EVENT_WITH_SCOPE }).start(done);
117125
});
118126

119127
test('worker can be stopped and restarted', done => {
120-
createRunner(__dirname, 'stop-and-start.js').expect({ event: EXPECTED_ANR_EVENT }).start(done);
128+
createRunner(__dirname, 'stop-and-start.js').expect({ event: ANR_EVENT_WITH_SCOPE }).start(done);
121129
});
122130

123131
const EXPECTED_ISOLATED_EVENT = {

packages/node/src/integrations/anr/worker.ts

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -187,6 +187,14 @@ if (options.captureStackTrace) {
187187
callFrameToStackFrame(frame, scripts.get(frame.location.scriptId), getModuleName),
188188
);
189189

190+
// Runtime.evaluate may never return if the event loop is blocked indefinitely
191+
// In that case, we want to send the event anyway
192+
const getScopeTimeout = setTimeout(() => {
193+
sendAnrEvent(stackFrames).then(null, () => {
194+
log('Sending ANR event failed.');
195+
});
196+
}, 5_000);
197+
190198
// Evaluate a script in the currently paused context
191199
session.post(
192200
'Runtime.evaluate',
@@ -203,6 +211,8 @@ if (options.captureStackTrace) {
203211
log(`Error executing script: '${err.message}'`);
204212
}
205213

214+
clearTimeout(getScopeTimeout);
215+
206216
const scopes = param && param.result ? (param.result.value as ScopeData) : undefined;
207217

208218
session.post('Debugger.resume');

0 commit comments

Comments
 (0)