Skip to content

Commit a961cde

Browse files
CertainLachbartlomieju
CertainLach
and
bartlomieju
authored
fix: toplevel fetch/cron leak its spans (#36757)
Signed-off-by: Yaroslav Bolyukin <iam@lach.pw> Co-authored-by: Bartek Iwańczuk <biwanczuk@gmail.com>
1 parent c5e973b commit a961cde

8 files changed

Lines changed: 136 additions & 23 deletions

File tree

‎ext/cron/01_cron.ts‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@ const {
1414
builtinTracer,
1515
ContextManager,
1616
enterSpan,
17-
restoreSnapshot,
17+
exitSpan,
1818
} = core.loadExtScript("ext:deno_telemetry/telemetry.ts");
1919
const { updateSpanFromError } = core.loadExtScript(
2020
"ext:deno_telemetry/util.ts",
@@ -202,7 +202,7 @@ function cron(
202202
try {
203203
result = handler();
204204
} finally {
205-
if (snapshot) restoreSnapshot(snapshot);
205+
exitSpan(snapshot);
206206
}
207207
await result;
208208
span.setStatus({ code: 1 });

‎ext/fetch/26_fetch.js‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -77,8 +77,9 @@ if (!internals.__telemetryUtil) {
7777
const {
7878
builtinTracer,
7979
ContextManager,
80+
DID_NOT_ENTER,
8081
enterSpan,
81-
restoreSnapshot,
82+
exitSpan,
8283
} = internals.__telemetry;
8384
const __telemetry = internals.__telemetry;
8485
const {
@@ -829,7 +830,7 @@ function httpRedirectFetch(request, response, terminator, inspectorCtx = null) {
829830
*/
830831
function fetch(input, init = undefined) {
831832
let span;
832-
let snapshot;
833+
let snapshot = DID_NOT_ENTER;
833834
try {
834835
if (__telemetry.TRACING_ENABLED) {
835836
span = builtinTracer().startSpan("fetch", { kind: 2 });
@@ -975,7 +976,7 @@ function fetch(input, init = undefined) {
975976
}
976977
return result;
977978
} finally {
978-
if (snapshot) restoreSnapshot(snapshot);
979+
exitSpan(snapshot);
979980
}
980981
}
981982

‎ext/telemetry/telemetry.ts‎

Lines changed: 30 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -199,22 +199,44 @@ function countAttributes(attributes?: Attributes): number {
199199
return attributes ? ObjectKeys(attributes).length : 0;
200200
}
201201

202+
const currentSnapshot = getAsyncContext;
203+
const restoreSnapshot = setAsyncContext;
204+
202205
interface AsyncContextSnapshot {
203206
__brand: "AsyncContextSnapshot";
204207
}
205208

209+
// A `unique symbol` type requires a direct `Symbol.for()` call, which is what
210+
// makes `SpanSnapshot` below narrowable. This runs during bootstrap, before any
211+
// user code, so reaching for the global here is safe.
212+
// deno-lint-ignore deno-internal/prefer-primordials
213+
const DID_NOT_ENTER: unique symbol = Symbol.for(
214+
"Deno.telemetry.didNotEnterSpan",
215+
);
216+
217+
/**
218+
* The result of {@linkcode enterSpan}: either the async context snapshot taken
219+
* before entering, or `DID_NOT_ENTER` if no context was entered. `undefined` is
220+
* a valid snapshot (it means "no ambient context"), so the two cases cannot be
221+
* told apart by truthiness, so always hand this to {@linkcode exitSpan}.
222+
*/
223+
type SpanSnapshot = AsyncContextSnapshot | typeof DID_NOT_ENTER;
224+
206225
function enterSpan(
207226
span: Span,
208227
context?: Context,
209-
): AsyncContextSnapshot | undefined {
210-
if (!span.isRecording()) return undefined;
228+
): SpanSnapshot {
229+
if (!span.isRecording()) return DID_NOT_ENTER;
230+
const snapshot = currentSnapshot();
211231
context = (context ?? CURRENT.get() ?? ROOT_CONTEXT)
212232
.setValue(SPAN_KEY, span);
213-
return CURRENT.enter(context);
233+
CURRENT.enter(context);
234+
return snapshot;
214235
}
215236

216-
const currentSnapshot = getAsyncContext;
217-
const restoreSnapshot = setAsyncContext;
237+
function exitSpan(snapshot: SpanSnapshot) {
238+
if (snapshot !== DID_NOT_ENTER) restoreSnapshot(snapshot);
239+
}
218240

219241
function isDate(value: unknown): value is Date {
220242
return ObjectPrototypeIsPrototypeOf(DatePrototype, value);
@@ -1927,7 +1949,9 @@ function bootstrap(
19271949
internals.__telemetry = {
19281950
builtinTracer,
19291951
ContextManager,
1952+
DID_NOT_ENTER,
19301953
enterSpan,
1954+
exitSpan,
19311955
get PROPAGATORS() {
19321956
return PROPAGATORS;
19331957
},
@@ -1969,6 +1993,7 @@ function wrappedBootstrap(config: Parameters<typeof bootstrap>[0]) {
19691993
return {
19701994
otelState,
19711995
enterSpan,
1996+
exitSpan,
19721997
currentSnapshot,
19731998
restoreSnapshot,
19741999
SPAN_KEY,

‎tests/specs/cli/otel_basic/cron.out‎

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,61 @@
5454
"message": "",
5555
"code": 0
5656
}
57+
},
58+
{
59+
"traceId": "00000000000000000000000000000002",
60+
"spanId": "0000000000000003",
61+
"traceState": "",
62+
"parentSpanId": "",
63+
"flags": 257,
64+
"name": "deno.cron",
65+
"kind": 1,
66+
"startTimeUnixNano": "[WILDCARD]",
67+
"endTimeUnixNano": "[WILDCARD]",
68+
"attributes": [
69+
{
70+
"key": "deno.cron.name",
71+
"value": {
72+
"stringValue": "test-cron"
73+
}
74+
},
75+
{
76+
"key": "deno.cron.schedule",
77+
"value": {
78+
"stringValue": "*/20 * * * *"
79+
}
80+
}
81+
],
82+
"droppedAttributesCount": 0,
83+
"events": [],
84+
"droppedEventsCount": 0,
85+
"links": [],
86+
"droppedLinksCount": 0,
87+
"status": {
88+
"message": "",
89+
"code": 1
90+
}
91+
},
92+
{
93+
"traceId": "00000000000000000000000000000002",
94+
"spanId": "0000000000000004",
95+
"traceState": "",
96+
"parentSpanId": "0000000000000003",
97+
"flags": 257,
98+
"name": "inner span",
99+
"kind": 1,
100+
"startTimeUnixNano": "[WILDCARD]",
101+
"endTimeUnixNano": "[WILDCARD]",
102+
"attributes": [],
103+
"droppedAttributesCount": 0,
104+
"events": [],
105+
"droppedEventsCount": 0,
106+
"links": [],
107+
"droppedLinksCount": 0,
108+
"status": {
109+
"message": "",
110+
"code": 0
111+
}
57112
}
58113
],
59114
"logs": [],

‎tests/specs/cli/otel_basic/cron.ts‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,10 +10,12 @@ let count = 0;
1010
const { promise, resolve } = Promise.withResolvers<void>();
1111
const ac = new AbortController();
1212

13+
// Runs twice: a handler must not leave its span in the ambient context, so the
14+
// second `deno.cron` span must be a root span rather than a child of the first.
1315
const c = Deno.cron("test-cron", "*/20 * * * *", { signal: ac.signal }, () => {
1416
tracer.startActiveSpan("inner span", (span) => {
1517
count++;
16-
if (count >= 1) {
18+
if (count >= 2) {
1719
resolve();
1820
}
1921
span.end();

‎tests/specs/cli/otel_basic/fetch.out‎

Lines changed: 27 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -59,10 +59,10 @@
5959
}
6060
},
6161
{
62-
"traceId": "00000000000000000000000000000001",
62+
"traceId": "00000000000000000000000000000002",
6363
"spanId": "0000000000000002",
6464
"traceState": "",
65-
"parentSpanId": "0000000000000001",
65+
"parentSpanId": "",
6666
"flags": 257,
6767
"name": "GET",
6868
"kind": 3,
@@ -123,10 +123,10 @@
123123
}
124124
},
125125
{
126-
"traceId": "00000000000000000000000000000001",
126+
"traceId": "00000000000000000000000000000003",
127127
"spanId": "0000000000000003",
128128
"traceState": "",
129-
"parentSpanId": "0000000000000001",
129+
"parentSpanId": "",
130130
"flags": 257,
131131
"name": "GET",
132132
"kind": 3,
@@ -199,10 +199,10 @@
199199
}
200200
},
201201
{
202-
"traceId": "00000000000000000000000000000001",
202+
"traceId": "00000000000000000000000000000004",
203203
"spanId": "0000000000000004",
204204
"traceState": "",
205-
"parentSpanId": "0000000000000001",
205+
"parentSpanId": "",
206206
"flags": 257,
207207
"name": "GET",
208208
"kind": 3,
@@ -273,6 +273,27 @@
273273
"message": "The signal has been aborted",
274274
"code": 2
275275
}
276+
},
277+
{
278+
"traceId": "00000000000000000000000000000005",
279+
"spanId": "0000000000000005",
280+
"traceState": "",
281+
"parentSpanId": "",
282+
"flags": 257,
283+
"name": "after fetch",
284+
"kind": 1,
285+
"startTimeUnixNano": "[WILDCARD]",
286+
"endTimeUnixNano": "[WILDCARD]",
287+
"attributes": [],
288+
"droppedAttributesCount": 0,
289+
"events": [],
290+
"droppedEventsCount": 0,
291+
"links": [],
292+
"droppedLinksCount": 0,
293+
"status": {
294+
"message": "",
295+
"code": 0
296+
}
276297
}
277298
],
278299
"logs": [],

‎tests/specs/cli/otel_basic/fetch.ts‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,5 @@
1+
import { trace } from "npm:@opentelemetry/api@1.9.0";
2+
13
async function request(url: string, options: any) {
24
try {
35
await (await fetch(url, options)).text();
@@ -9,3 +11,10 @@ await request("http://localhost:4545/echo.ts");
911
await request("http://localhost:4545/not-found");
1012
await request("http://unreachable-host.abc/");
1113
await request("http://localhost:4545/echo.ts", { signal: AbortSignal.abort() });
14+
15+
// `fetch()` must not leave its span in the ambient context after it returns:
16+
// this span is created at the top level, so it must be a root span.
17+
trace.getTracer("example-tracer").startActiveSpan(
18+
"after fetch",
19+
(span) => span.end(),
20+
);

‎tests/specs/cli/otel_basic/http_metric.out‎

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -117,10 +117,10 @@
117117
}
118118
},
119119
{
120-
"traceId": "00000000000000000000000000000001",
120+
"traceId": "00000000000000000000000000000002",
121121
"spanId": "0000000000000003",
122122
"traceState": "",
123-
"parentSpanId": "0000000000000001",
123+
"parentSpanId": "",
124124
"flags": 257,
125125
"name": "GET",
126126
"kind": 3,
@@ -175,7 +175,7 @@
175175
}
176176
},
177177
{
178-
"traceId": "00000000000000000000000000000001",
178+
"traceId": "00000000000000000000000000000002",
179179
"spanId": "0000000000000004",
180180
"traceState": "",
181181
"parentSpanId": "0000000000000003",
@@ -233,10 +233,10 @@
233233
}
234234
},
235235
{
236-
"traceId": "00000000000000000000000000000001",
236+
"traceId": "00000000000000000000000000000003",
237237
"spanId": "0000000000000005",
238238
"traceState": "",
239-
"parentSpanId": "0000000000000001",
239+
"parentSpanId": "",
240240
"flags": 257,
241241
"name": "GET",
242242
"kind": 3,
@@ -291,7 +291,7 @@
291291
}
292292
},
293293
{
294-
"traceId": "00000000000000000000000000000001",
294+
"traceId": "00000000000000000000000000000003",
295295
"spanId": "0000000000000006",
296296
"traceState": "",
297297
"parentSpanId": "0000000000000005",

0 commit comments

Comments
 (0)