Skip to content

Commit 51e639c

Browse files
committed
feat(node): Capture scope when event loop blocked
1 parent fe97d67 commit 51e639c

File tree

11 files changed

+206
-31
lines changed

11 files changed

+206
-31
lines changed
Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,37 @@
1+
import * as Sentry from '@sentry/node';
2+
import { longWork } from './long-work.js';
3+
4+
setTimeout(() => {
5+
process.exit();
6+
}, 10000);
7+
8+
function neverResolve() {
9+
return new Promise(() => {
10+
//
11+
});
12+
}
13+
14+
const fns = [
15+
neverResolve,
16+
neverResolve,
17+
neverResolve,
18+
neverResolve,
19+
neverResolve,
20+
longWork, // [5]
21+
neverResolve,
22+
neverResolve,
23+
neverResolve,
24+
neverResolve,
25+
];
26+
27+
setTimeout(() => {
28+
for (let id = 0; id < 10; id++) {
29+
Sentry.withIsolationScope(async () => {
30+
// eslint-disable-next-line no-console
31+
console.log(`Starting task ${id}`);
32+
Sentry.setUser({ id });
33+
34+
await fns[id]();
35+
});
36+
}
37+
}, 1000);

dev-packages/node-integration-tests/suites/thread-blocked-native/test.ts

Lines changed: 64 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import { join } from 'node:path';
22
import type { Event } from '@sentry/core';
33
import { afterAll, describe, expect, test } from 'vitest';
4+
import { NODE_VERSION } from '../../utils/index';
45
import { cleanupChildProcesses, createRunner } from '../../utils/runner';
56

67
function EXCEPTION(thread_id = '0', fn = 'longWork') {
@@ -34,9 +35,17 @@ function EXCEPTION(thread_id = '0', fn = 'longWork') {
3435
};
3536
}
3637

37-
const ANR_EVENT = {
38+
const ANR_EVENT = (trace: boolean = false) => ({
3839
// Ensure we have context
3940
contexts: {
41+
...(trace
42+
? {
43+
trace: {
44+
span_id: expect.stringMatching(/[a-f0-9]{16}/),
45+
trace_id: expect.stringMatching(/[a-f0-9]{32}/),
46+
},
47+
}
48+
: {}),
4049
device: {
4150
arch: expect.any(String),
4251
},
@@ -63,11 +72,11 @@ const ANR_EVENT = {
6372
},
6473
// and an exception that is our ANR
6574
exception: EXCEPTION(),
66-
};
75+
});
6776

6877
function ANR_EVENT_WITH_DEBUG_META(file: string): Event {
6978
return {
70-
...ANR_EVENT,
79+
...ANR_EVENT(),
7180
debug_meta: {
7281
images: [
7382
{
@@ -103,7 +112,7 @@ describe('Thread Blocked Native', { timeout: 30_000 }, () => {
103112

104113
test('Custom appRootPath', async () => {
105114
const ANR_EVENT_WITH_SPECIFIC_DEBUG_META: Event = {
106-
...ANR_EVENT,
115+
...ANR_EVENT(),
107116
debug_meta: {
108117
images: [
109118
{
@@ -134,7 +143,7 @@ describe('Thread Blocked Native', { timeout: 30_000 }, () => {
134143
test('blocked indefinitely', async () => {
135144
await createRunner(__dirname, 'indefinite.mjs')
136145
.withMockSentryServer()
137-
.expect({ event: ANR_EVENT })
146+
.expect({ event: ANR_EVENT() })
138147
.start()
139148
.completed();
140149
});
@@ -160,7 +169,7 @@ describe('Thread Blocked Native', { timeout: 30_000 }, () => {
160169
.withMockSentryServer()
161170
.expect({
162171
event: {
163-
...ANR_EVENT,
172+
...ANR_EVENT(),
164173
exception: EXCEPTION('0', 'longWorkOther'),
165174
},
166175
})
@@ -179,7 +188,7 @@ describe('Thread Blocked Native', { timeout: 30_000 }, () => {
179188
expect(crashedThread).toBeDefined();
180189

181190
expect(event).toMatchObject({
182-
...ANR_EVENT,
191+
...ANR_EVENT(),
183192
exception: {
184193
...EXCEPTION(crashedThread),
185194
},
@@ -210,4 +219,52 @@ describe('Thread Blocked Native', { timeout: 30_000 }, () => {
210219
.start()
211220
.completed();
212221
});
222+
223+
test('Capture scope via AsyncLocalStorage', async ctx => {
224+
if (NODE_VERSION < 24) {
225+
ctx.skip();
226+
return;
227+
}
228+
229+
const instrument = join(__dirname, 'instrument.mjs');
230+
await createRunner(__dirname, 'isolated.mjs')
231+
.withMockSentryServer()
232+
.withInstrument(instrument)
233+
.expect({
234+
event: event => {
235+
const crashedThread = event.threads?.values?.find(thread => thread.crashed)?.id as string;
236+
expect(crashedThread).toBeDefined();
237+
238+
expect(event).toMatchObject({
239+
...ANR_EVENT(true),
240+
exception: {
241+
...EXCEPTION(crashedThread),
242+
},
243+
breadcrumbs: [
244+
{
245+
timestamp: expect.any(Number),
246+
category: 'console',
247+
data: { arguments: ['Starting task 5'], logger: 'console' },
248+
level: 'log',
249+
message: 'Starting task 5',
250+
},
251+
],
252+
user: { id: 5 },
253+
threads: {
254+
values: [
255+
{
256+
id: '0',
257+
name: 'main',
258+
crashed: true,
259+
current: true,
260+
main: true,
261+
},
262+
],
263+
},
264+
});
265+
},
266+
})
267+
.start()
268+
.completed();
269+
});
213270
});

dev-packages/node-integration-tests/utils/index.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@ import { parseSemver } from '@sentry/core';
33
import type * as http from 'http';
44
import { describe } from 'vitest';
55

6-
const NODE_VERSION = parseSemver(process.versions.node).major;
6+
export const NODE_VERSION = parseSemver(process.versions.node).major || 0;
77

88
export type TestServerConfig = {
99
url: string;

packages/node-core/src/sdk/client.ts

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,7 @@ import { registerInstrumentations } from '@opentelemetry/instrumentation';
55
import type { BasicTracerProvider } from '@opentelemetry/sdk-trace-base';
66
import type { DynamicSamplingContext, Scope, ServerRuntimeClientOptions, TraceContext } from '@sentry/core';
77
import { _INTERNAL_flushLogsBuffer, applySdkMetadata, debug, SDK_VERSION, ServerRuntimeClient } from '@sentry/core';
8-
import { getTraceContextForScope } from '@sentry/opentelemetry';
8+
import { type AsyncLocalStorageLookup, getTraceContextForScope } from '@sentry/opentelemetry';
99
import { isMainThread, threadId } from 'worker_threads';
1010
import { DEBUG_BUILD } from '../debug-build';
1111
import type { NodeClientOptions } from '../types';
@@ -15,6 +15,8 @@ const DEFAULT_CLIENT_REPORT_FLUSH_INTERVAL_MS = 60_000; // 60s was chosen arbitr
1515
/** A client for using Sentry with Node & OpenTelemetry. */
1616
export class NodeClient extends ServerRuntimeClient<NodeClientOptions> {
1717
public traceProvider: BasicTracerProvider | undefined;
18+
public asyncLocalStroageLookup: AsyncLocalStorageLookup | undefined;
19+
1820
private _tracer: Tracer | undefined;
1921
private _clientReportInterval: NodeJS.Timeout | undefined;
2022
private _clientReportOnExitFlushListener: (() => void) | undefined;

packages/node-native/package.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -63,7 +63,7 @@
6363
"build:tarball": "npm pack"
6464
},
6565
"dependencies": {
66-
"@sentry-internal/node-native-stacktrace": "^0.2.2",
66+
"@sentry-internal/node-native-stacktrace": "^0.3.0",
6767
"@sentry/core": "10.22.0",
6868
"@sentry/node": "10.22.0"
6969
},

packages/node-native/src/event-loop-block-integration.ts

Lines changed: 14 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
import { isPromise } from 'node:util/types';
22
import { isMainThread, Worker } from 'node:worker_threads';
33
import type {
4-
Client,
54
ClientOptions,
65
Contexts,
76
DsnComponents,
@@ -47,7 +46,7 @@ function poll(enabled: boolean, clientOptions: ClientOptions): void {
4746
// serialized without making it a SerializedSession
4847
const session = currentSession ? { ...currentSession, toJSON: undefined } : undefined;
4948
// message the worker to tell it the main event loop is still running
50-
threadPoll({ session, debugImages: getFilenameToDebugIdMap(clientOptions.stackParser) }, !enabled);
49+
threadPoll(enabled, { session, debugImages: getFilenameToDebugIdMap(clientOptions.stackParser) });
5150
} catch {
5251
// we ignore all errors
5352
}
@@ -57,10 +56,17 @@ function poll(enabled: boolean, clientOptions: ClientOptions): void {
5756
* Starts polling
5857
*/
5958
function startPolling(
60-
client: Client,
59+
client: NodeClient,
6160
integrationOptions: Partial<ThreadBlockedIntegrationOptions>,
6261
): IntegrationInternal | undefined {
63-
registerThread();
62+
if (client.asyncLocalStroageLookup) {
63+
registerThread({
64+
asyncLocalStorage: client.asyncLocalStroageLookup.asyncLocalStorage,
65+
stateLookup: ['_currentContext', client.asyncLocalStroageLookup.contextSymbol],
66+
});
67+
} else {
68+
registerThread();
69+
}
6470

6571
let enabled = true;
6672

@@ -161,7 +167,10 @@ const _eventLoopBlockIntegration = ((options: Partial<ThreadBlockedIntegrationOp
161167
}
162168

163169
try {
164-
polling = await startPolling(client, options);
170+
// Otel is not setup until after afterAllSetup returns.
171+
setImmediate(() => {
172+
polling = startPolling(client, options);
173+
});
165174

166175
if (isMainThread) {
167176
await startWorker(dsn, client, options);

packages/node-native/src/event-loop-block-watchdog.ts

Lines changed: 39 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,16 @@
11
import { workerData } from 'node:worker_threads';
2-
import type { DebugImage, Event, Session, StackFrame, Thread } from '@sentry/core';
2+
import type { DebugImage, Event, ScopeData, Session, StackFrame, Thread } from '@sentry/core';
33
import {
4+
applyScopeDataToEvent,
45
createEventEnvelope,
56
createSessionEnvelope,
67
filenameIsInApp,
8+
generateSpanId,
79
getEnvelopeEndpointWithUrlEncodedAuth,
810
makeSession,
11+
mergeScopeData,
912
normalizeUrlToBase,
13+
Scope,
1014
stripSentryFramesAndReverse,
1115
updateSession,
1216
uuid4,
@@ -16,6 +20,11 @@ import { captureStackTrace, getThreadsLastSeen } from '@sentry-internal/node-nat
1620
import type { ThreadState, WorkerStartData } from './common';
1721
import { POLL_RATIO } from './common';
1822

23+
type CurrentScopes = {
24+
scope: Scope;
25+
isolationScope: Scope;
26+
};
27+
1928
const {
2029
threshold,
2130
appRootPath,
@@ -178,7 +187,7 @@ function applyDebugMeta(event: Event, debugImages: Record<string, string>): void
178187

179188
function getExceptionAndThreads(
180189
crashedThreadId: string,
181-
threads: ReturnType<typeof captureStackTrace<ThreadState>>,
190+
threads: ReturnType<typeof captureStackTrace<CurrentScopes, ThreadState>>,
182191
): Event {
183192
const crashedThread = threads[crashedThreadId];
184193

@@ -217,12 +226,28 @@ function getExceptionAndThreads(
217226
};
218227
}
219228

229+
function applyScopeToEvent(event: Event, scope: ScopeData): void {
230+
applyScopeDataToEvent(event, scope);
231+
232+
if (!event.contexts?.trace) {
233+
const { traceId, parentSpanId, propagationSpanId } = scope.propagationContext;
234+
event.contexts = {
235+
trace: {
236+
trace_id: traceId,
237+
span_id: propagationSpanId || generateSpanId(),
238+
parent_span_id: parentSpanId,
239+
},
240+
...event.contexts,
241+
};
242+
}
243+
}
244+
220245
async function sendBlockEvent(crashedThreadId: string): Promise<void> {
221246
if (isRateLimited()) {
222247
return;
223248
}
224249

225-
const threads = captureStackTrace<ThreadState>();
250+
const threads = captureStackTrace<CurrentScopes, ThreadState>();
226251
const crashedThread = threads[crashedThreadId];
227252

228253
if (!crashedThread) {
@@ -231,7 +256,7 @@ async function sendBlockEvent(crashedThreadId: string): Promise<void> {
231256
}
232257

233258
try {
234-
await sendAbnormalSession(crashedThread.state?.session);
259+
await sendAbnormalSession(crashedThread.pollState?.session);
235260
} catch (error) {
236261
log(`Failed to send abnormal session for thread '${crashedThreadId}':`, error);
237262
}
@@ -250,8 +275,17 @@ async function sendBlockEvent(crashedThreadId: string): Promise<void> {
250275
...getExceptionAndThreads(crashedThreadId, threads),
251276
};
252277

278+
const asyncState = threads[crashedThreadId]?.asyncState;
279+
if (asyncState) {
280+
// We need to rehydrate the scopes from the serialized objects so we can call getScopeData()
281+
const scope = Object.assign(new Scope(), asyncState.scope).getScopeData();
282+
const isolationScope = Object.assign(new Scope(), asyncState.isolationScope).getScopeData();
283+
mergeScopeData(scope, isolationScope);
284+
applyScopeToEvent(event, scope);
285+
}
286+
253287
const allDebugImages: Record<string, string> = Object.values(threads).reduce((acc, threadState) => {
254-
return { ...acc, ...threadState.state?.debugImages };
288+
return { ...acc, ...threadState.pollState?.debugImages };
255289
}, {});
256290

257291
applyDebugMeta(event, allDebugImages);

0 commit comments

Comments
 (0)