From 3a45a928a458d818c0895673742a0d1b3c9b7f68 Mon Sep 17 00:00:00 2001 From: Michael Arnaldi Date: Tue, 21 May 2024 17:25:39 +0200 Subject: [PATCH] Avoid eager read of the stack when captured by a span --- .changeset/gorgeous-ties-tan.md | 5 ++++ packages/effect/src/Tracer.ts | 3 +- packages/effect/src/internal/cause.ts | 9 ++++-- packages/effect/src/internal/core-effect.ts | 22 ++++++++++---- packages/effect/src/internal/tracer.ts | 22 +++++++++----- packages/effect/test/Tracer.test.ts | 33 ++++++++++++++++----- 6 files changed, 71 insertions(+), 23 deletions(-) create mode 100644 .changeset/gorgeous-ties-tan.md diff --git a/.changeset/gorgeous-ties-tan.md b/.changeset/gorgeous-ties-tan.md new file mode 100644 index 0000000000..8e0b6b48b0 --- /dev/null +++ b/.changeset/gorgeous-ties-tan.md @@ -0,0 +1,5 @@ +--- +"effect": patch +--- + +Avoid eager read of the stack when captured by a span diff --git a/packages/effect/src/Tracer.ts b/packages/effect/src/Tracer.ts index 69a33e4f69..038ddff03f 100644 --- a/packages/effect/src/Tracer.ts +++ b/packages/effect/src/Tracer.ts @@ -5,6 +5,7 @@ import type * as Context from "./Context.js" import type * as Effect from "./Effect.js" import type * as Exit from "./Exit.js" import type * as Fiber from "./Fiber.js" +import type { LazyArg } from "./Function.js" import * as defaultServices from "./internal/defaultServices.js" import * as internal from "./internal/tracer.js" import type * as Option from "./Option.js" @@ -92,7 +93,7 @@ export interface SpanOptions { readonly root?: boolean | undefined readonly context?: Context.Context | undefined readonly kind?: SpanKind | undefined - readonly captureStackTrace?: boolean | string | undefined + readonly captureStackTrace?: boolean | LazyArg | undefined } /** diff --git a/packages/effect/src/internal/cause.ts b/packages/effect/src/internal/cause.ts index d4714d8841..aa91ffffca 100644 --- a/packages/effect/src/internal/cause.ts +++ b/packages/effect/src/internal/cause.ts @@ -5,6 +5,7 @@ import * as Either from "../Either.js" import * as Equal from "../Equal.js" import type * as FiberId from "../FiberId.js" import { constFalse, constTrue, dual, identity, pipe } from "../Function.js" +import { globalValue } from "../GlobalValue.js" import * as Hash from "../Hash.js" import * as HashSet from "../HashSet.js" import { NodeInspectSymbol, toJSON } from "../Inspectable.js" @@ -1052,6 +1053,9 @@ export const prettyErrorMessage = (u: unknown): string => { const locationRegex = /\((.*)\)/ +/** @internal */ +export const spanToTrace = globalValue("effect/Tracer/spanToTrace", () => new WeakMap()) + const prettyErrorStack = (message: string, stack: string, span?: Span | undefined): string => { const out: Array = [message] const lines = stack.split("\n") @@ -1072,8 +1076,9 @@ const prettyErrorStack = (message: string, stack: string, span?: Span | undefine let current: Span | AnySpan | undefined = span let i = 0 while (current && current._tag === "Span" && i < 10) { - const stack = current.attributes.get("code.stacktrace") - if (typeof stack === "string") { + const stackFn = spanToTrace.get(current) + if (typeof stackFn === "function") { + const stack = stackFn() const locationMatch = stack.match(locationRegex) const location = locationMatch ? locationMatch[1] : stack.replace(/^at /, "") out.push(` at ${current.name} (${location})`) diff --git a/packages/effect/src/internal/core-effect.ts b/packages/effect/src/internal/core-effect.ts index d8fed1c20a..630c9a198f 100644 --- a/packages/effect/src/internal/core-effect.ts +++ b/packages/effect/src/internal/core-effect.ts @@ -2054,8 +2054,8 @@ export const unsafeMakeSpan = ( options.kind ?? "internal" ) - if (typeof options.captureStackTrace === "string") { - span.attribute("code.stacktrace", options.captureStackTrace) + if (typeof options.captureStackTrace === "function") { + internalCause.spanToTrace.set(span, options.captureStackTrace) } if (annotationsFromEnv._tag === "Some") { @@ -2112,6 +2112,9 @@ export const useSpan: { if (span.status._tag === "Ended") { return } + if (core.exitIsFailure(exit) && internalCause.spanToTrace.has(span)) { + span.attribute("code.stacktrace", internalCause.spanToTrace.get(span)!()) + } span.end(timingEnabled ? clock.unsafeCurrentTimeNanos() : bigint0, exit) })) }) @@ -2155,15 +2158,22 @@ export const functionWithSpan = , Ret extends Effect.Eff } ): (...args: Args) => Unify => (function(this: any) { - let captureStackTrace: string | boolean = options.captureStackTrace ?? false + let captureStackTrace: LazyArg | boolean = options.captureStackTrace ?? false if (options.captureStackTrace !== false) { const limit = Error.stackTraceLimit Error.stackTraceLimit = 2 const error = new Error() Error.stackTraceLimit = limit - if (error.stack !== undefined) { - const stack = error.stack.trim().split("\n") - captureStackTrace = stack.slice(2).join("\n").trim() + let cache: false | string = false + captureStackTrace = () => { + if (cache !== false) { + return cache + } + if (error.stack) { + const stack = error.stack.trim().split("\n") + cache = stack.slice(2).join("\n").trim() + return cache + } } } // eslint-disable-next-line @typescript-eslint/no-this-alias diff --git a/packages/effect/src/internal/tracer.ts b/packages/effect/src/internal/tracer.ts index a4c8ac4887..6370e6ce96 100644 --- a/packages/effect/src/internal/tracer.ts +++ b/packages/effect/src/internal/tracer.ts @@ -118,12 +118,20 @@ export const addSpanStackTrace = (options: Tracer.SpanOptions | undefined): Trac Error.stackTraceLimit = 3 const traceError = new Error() Error.stackTraceLimit = limit - if (traceError.stack === undefined) { - return { ...options, captureStackTrace: false } - } - const stack = traceError.stack.split("\n") - if (!stack[3]) { - return { ...options, captureStackTrace: false } + let cache: false | string = false + return { + ...options, + captureStackTrace: () => { + if (cache !== false) { + return cache + } + if (traceError.stack !== undefined) { + const stack = traceError.stack.split("\n") + if (stack[3] !== undefined) { + cache = stack[3].trim() + return cache + } + } + } } - return { ...options, captureStackTrace: stack[3].trim() } } diff --git a/packages/effect/test/Tracer.test.ts b/packages/effect/test/Tracer.test.ts index c3c2c4ae2f..d41574e5eb 100644 --- a/packages/effect/test/Tracer.test.ts +++ b/packages/effect/test/Tracer.test.ts @@ -18,7 +18,7 @@ describe("Tracer", () => { const span = yield* Effect.withSpan("A")(Effect.currentSpan) assert.deepEqual(span.name, "A") assert.deepEqual(span.parent, Option.none()) - assert.include(span.attributes.get("code.stacktrace"), "Tracer.test.ts:18") + assert.strictEqual(span.attributes.get("code.stacktrace"), undefined) })) it.effect("parent", () => @@ -139,7 +139,7 @@ describe("Tracer", () => { Effect.gen(function*() { const span = yield* Effect.scoped(Effect.makeSpanScoped("A")) assert.deepEqual(span.status._tag, "Ended") - assert.include(span.attributes.get("code.stacktrace"), "Tracer.test.ts:140") + assert.strictEqual(span.attributes.get("code.stacktrace"), undefined) })) it.effect("annotateCurrentSpan", () => @@ -176,8 +176,8 @@ describe("Tracer", () => { const span = yield* Effect.makeSpan("child") const parent = yield* Option.filter(span.parent, (span): span is Span => span._tag === "Span") assert.deepEqual(parent.name, "parent") - assert.include(span.attributes.get("code.stacktrace"), "Tracer.test.ts:176") - assert.include(parent.attributes.get("code.stacktrace"), "Tracer.test.ts:184") + assert.strictEqual(span.attributes.get("code.stacktrace"), undefined) + assert.strictEqual(parent.attributes.get("code.stacktrace"), undefined) }).pipe( Effect.provide(Layer.unwrapScoped( Effect.map( @@ -195,7 +195,7 @@ describe("Tracer", () => { Option.getOrThrow ) assert.strictEqual(parent.name, "parent") - assert.include(parent.attributes.get("code.stacktrace"), "Tracer.test.ts:200") + assert.strictEqual(parent.attributes.get("code.stacktrace"), undefined) }).pipe( Effect.provide(Layer.span("parent")) )) @@ -238,7 +238,7 @@ describe("Tracer", () => { const layer = Layer.effectDiscard(Effect.gen(function*() { const span = yield* Effect.currentSpan assert.strictEqual(span.name, "span") - assert.include(span.attributes.get("code.stacktrace"), "Tracer.test.ts:243") + assert.strictEqual(span.attributes.get("code.stacktrace"), undefined) })).pipe( Layer.withSpan("span", { onEnd: (span, _exit) => @@ -274,6 +274,25 @@ it.effect("withTracerEnabled", () => assert.deepEqual(spanB.name, "B") })) +it.effect("includes trace when errored", () => + Effect.gen(function*() { + let maybeSpan: undefined | Span + const getSpan = Effect.functionWithSpan({ + body: (_id: string) => + Effect.currentSpan.pipe(Effect.flatMap((span) => { + maybeSpan = span + return Effect.fail("error") + })), + options: (id) => ({ + name: `span-${id}`, + attributes: { id } + }) + }) + yield* Effect.flip(getSpan("fail")) + assert.isDefined(maybeSpan) + assert.include(maybeSpan!.attributes.get("code.stacktrace"), "Tracer.test.ts:291:24") + })) + describe("functionWithSpan", () => { const getSpan = Effect.functionWithSpan({ body: (_id: string) => Effect.currentSpan, @@ -288,7 +307,7 @@ describe("functionWithSpan", () => { const span = yield* getSpan("A") assert.deepEqual(span.name, "span-A") assert.deepEqual(span.parent, Option.none()) - assert.include(span.attributes.get("code.stacktrace"), "Tracer.test.ts:288") + assert.strictEqual(span.attributes.get("code.stacktrace"), undefined) })) it.effect("parent", () =>