From 90776ec8e8671d835b65fc33ead1de6c864b81b9 Mon Sep 17 00:00:00 2001 From: Tim Date: Fri, 12 Apr 2024 13:46:57 +1200 Subject: [PATCH] make tracing spans cheaper to construct (#2502) --- .changeset/nice-phones-attack.md | 5 + packages/effect/src/internal/core-effect.ts | 141 ++++++++++--------- packages/effect/src/internal/fiberRuntime.ts | 26 ++-- 3 files changed, 98 insertions(+), 74 deletions(-) create mode 100644 .changeset/nice-phones-attack.md diff --git a/.changeset/nice-phones-attack.md b/.changeset/nice-phones-attack.md new file mode 100644 index 00000000000..3135b01604b --- /dev/null +++ b/.changeset/nice-phones-attack.md @@ -0,0 +1,5 @@ +--- +"effect": patch +--- + +make tracing spans cheaper to construct diff --git a/packages/effect/src/internal/core-effect.ts b/packages/effect/src/internal/core-effect.ts index 8f4ea22975c..262b9694f5f 100644 --- a/packages/effect/src/internal/core-effect.ts +++ b/packages/effect/src/internal/core-effect.ts @@ -27,9 +27,11 @@ import type * as runtimeFlagsPatch from "../RuntimeFlagsPatch.js" import * as Tracer from "../Tracer.js" import type { MergeRecord, NoInfer } from "../Types.js" import * as internalCause from "./cause.js" +import { clockTag } from "./clock.js" import * as core from "./core.js" import * as defaultServices from "./defaultServices.js" import * as fiberRefsPatch from "./fiberRefs/patch.js" +import type { FiberRuntime } from "./fiberRuntime.js" import * as metricLabel from "./metric/label.js" import * as runtimeFlags from "./runtimeFlags.js" import * as SingleShotGen from "./singleShotGen.js" @@ -2006,13 +2008,6 @@ export const currentSpan: Effect.Effect enabled ? Clock.currentTimeNanos : core.succeed(bigint0) -) - /* @internal */ export const linkSpans = dual< ( @@ -2040,8 +2035,11 @@ export const linkSpans = dual< ) ) +const bigint0 = BigInt(0) + /** @internal */ -export const makeSpan = ( +export const unsafeMakeSpan = ( + fiber: FiberRuntime, name: string, options?: { readonly attributes?: Record | undefined @@ -2050,55 +2048,67 @@ export const makeSpan = ( readonly root?: boolean | undefined readonly context?: Context.Context | undefined } -): Effect.Effect => - core.flatMap(fiberRefs, (fiberRefs) => - core.sync(() => { - const enabled = FiberRefs.getOrDefault(fiberRefs, core.currentTracerEnabled) - if (enabled === false) { - return core.noopSpan(name) - } +) => { + const enabled = fiber.getFiberRef(core.currentTracerEnabled) + if (enabled === false) { + return core.noopSpan(name) + } - const context = FiberRefs.getOrDefault(fiberRefs, core.currentContext) - const services = FiberRefs.getOrDefault(fiberRefs, defaultServices.currentServices) - - const tracer = Context.get(services, internalTracer.tracerTag) - const clock = Context.get(services, Clock.Clock) - const timingEnabled = FiberRefs.getOrDefault(fiberRefs, core.currentTracerTimingEnabled) - const annotationsFromEnv = FiberRefs.get(fiberRefs, core.currentTracerSpanAnnotations) - const linksFromEnv = FiberRefs.get(fiberRefs, core.currentTracerSpanLinks) - - const parent = options?.parent - ? Option.some(options.parent) - : options?.root - ? Option.none() - : Context.getOption(context, internalTracer.spanTag) - - const links = linksFromEnv._tag === "Some" ? - options?.links !== undefined ? - [ - ...Chunk.toReadonlyArray(linksFromEnv.value), - ...(options?.links ?? []) - ] : - Chunk.toReadonlyArray(linksFromEnv.value) : - options?.links ?? ReadonlyArray.empty() - - const span = tracer.span( - name, - parent, - options?.context ?? Context.empty(), - links, - timingEnabled ? clock.unsafeCurrentTimeNanos() : bigint0 - ) + const context = fiber.getFiberRef(core.currentContext) + const services = fiber.getFiberRef(defaultServices.currentServices) + + const tracer = Context.get(services, internalTracer.tracerTag) + const clock = Context.get(services, Clock.Clock) + const timingEnabled = fiber.getFiberRef(core.currentTracerTimingEnabled) + + const fiberRefs = fiber.getFiberRefs() + const annotationsFromEnv = FiberRefs.get(fiberRefs, core.currentTracerSpanAnnotations) + const linksFromEnv = FiberRefs.get(fiberRefs, core.currentTracerSpanLinks) + + const parent = options?.parent + ? Option.some(options.parent) + : options?.root + ? Option.none() + : Context.getOption(context, internalTracer.spanTag) + + const links = linksFromEnv._tag === "Some" ? + options?.links !== undefined ? + [ + ...Chunk.toReadonlyArray(linksFromEnv.value), + ...(options?.links ?? []) + ] : + Chunk.toReadonlyArray(linksFromEnv.value) : + options?.links ?? ReadonlyArray.empty() + + const span = tracer.span( + name, + parent, + options?.context ?? Context.empty(), + links, + timingEnabled ? clock.unsafeCurrentTimeNanos() : bigint0 + ) - if (annotationsFromEnv._tag === "Some") { - HashMap.forEach(annotationsFromEnv.value, (value, key) => span.attribute(key, value)) - } - if (options?.attributes) { - Object.entries(options.attributes).forEach(([k, v]) => span.attribute(k, v)) - } + if (annotationsFromEnv._tag === "Some") { + HashMap.forEach(annotationsFromEnv.value, (value, key) => span.attribute(key, value)) + } + if (options?.attributes !== undefined) { + Object.entries(options.attributes).forEach(([k, v]) => span.attribute(k, v)) + } - return span - })) + return span +} + +/** @internal */ +export const makeSpan = ( + name: string, + options?: { + readonly attributes?: Record | undefined + readonly links?: ReadonlyArray | undefined + readonly parent?: Tracer.ParentSpan | undefined + readonly root?: boolean | undefined + readonly context?: Context.Context | undefined + } +): Effect.Effect => core.withFiberRuntime((fiber) => core.succeed(unsafeMakeSpan(fiber, name, options))) /* @internal */ export const spanAnnotations: Effect.Effect> = core @@ -2134,17 +2144,18 @@ export const useSpan: { } | undefined = args.length === 1 ? undefined : args[0] const evaluate: (span: Tracer.Span) => Effect.Effect = args[args.length - 1] - return core.acquireUseRelease( - makeSpan(name, options), - evaluate, - (span, exit) => - span.status._tag === "Ended" ? - core.unit : - core.flatMap( - currentTimeNanosTracing, - (endTime) => core.sync(() => span.end(endTime, exit)) - ) - ) + return core.withFiberRuntime((fiber) => { + const span = unsafeMakeSpan(fiber, name, options) + const timingEnabled = fiber.getFiberRef(core.currentTracerTimingEnabled) + const clock = Context.get(fiber.getFiberRef(defaultServices.currentServices), clockTag) + return core.onExit(evaluate(span), (exit) => + core.sync(() => { + if (span.status._tag === "Ended") { + return + } + span.end(timingEnabled ? clock.unsafeCurrentTimeNanos() : bigint0, exit) + })) + }) } /** @internal */ diff --git a/packages/effect/src/internal/fiberRuntime.ts b/packages/effect/src/internal/fiberRuntime.ts index 2e559501cf5..dc824aff3af 100644 --- a/packages/effect/src/internal/fiberRuntime.ts +++ b/packages/effect/src/internal/fiberRuntime.ts @@ -3578,15 +3578,23 @@ export const makeSpanScoped = ( readonly context?: Context.Context | undefined } ): Effect.Effect => - acquireRelease( - internalEffect.makeSpan(name, options), - (span, exit) => - span.status._tag === "Ended" ? - core.unit : - core.flatMap( - internalEffect.currentTimeNanosTracing, - (endTime) => core.sync(() => span.end(endTime, exit)) - ) + core.uninterruptible( + core.withFiberRuntime((fiber) => { + const scope = Context.unsafeGet(fiber.getFiberRef(core.currentContext), scopeTag) + const span = internalEffect.unsafeMakeSpan(fiber, name, options) + const timingEnabled = fiber.getFiberRef(core.currentTracerTimingEnabled) + const clock_ = Context.get(fiber.getFiberRef(defaultServices.currentServices), clock.clockTag) + return core.as( + core.scopeAddFinalizerExit(scope, (exit) => + core.sync(() => { + if (span.status._tag === "Ended") { + return + } + span.end(timingEnabled ? clock_.unsafeCurrentTimeNanos() : BigInt(0), exit) + })), + span + ) + }) ) /* @internal */