From c746ce77d9e606aebe4ea63547b154b6bbfaabbe Mon Sep 17 00:00:00 2001 From: AEGIS Date: Sat, 11 Apr 2026 09:48:27 -0500 Subject: [PATCH] feat(tracing): Span.startChild + getActiveSpan + honoTracing helper MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three dogfood-driven ergonomics lifts, all surfaced while instrumenting tarotscript-worker (tarotscript#163). Closes worker-observability#3, #4. What's new 1. Span.startChild(name, attributes?) - Convenience wrapper around `this.tracer.startSpan(name, { parent })` - Saves ~3 lines of mechanical plumbing at every child-span call site - NoOpSpan override returns itself so sampled-out spans are still safe 2. AsyncLocalStorage-backed active span context - Tracer.runWithSpan(span, fn) scopes the span for a code region - getActiveSpan() returns the scoped span anywhere in the call stack, across async boundaries, without threading a parent through every function signature - Import guarded via @ts-expect-error; node:async_hooks is pulled in at runtime by the Workers `nodejs_als` / `nodejs_compat` flag. When ALS is unavailable the storage is null and both runWithSpan and getActiveSpan degrade gracefully (identity wrapper / undefined) - This is the scalability lever for deep instrumentation — library code (interpreters, LLM providers, scaffold materializers) can now create child spans without taking a hard dep on observability 3. honoTracing() — batteries-included Hono middleware - Wraps the full root-span lifecycle pattern every dogfood worker was rewriting: span start, HTTP attributes, recordError on throw, error status on 5xx, publish to c.get('rootSpan'), automatic active-span scope via runWithSpan, and ctx.waitUntil-based flush of tracer+metrics so ingest doesn't block the response - Options: skip predicate, extra attributes callback, custom spanNamer, contextKey override - Accepts a minimal HonoTracingMonitoring shape ({ tracer, metrics }) so it doesn't couple to the full createMonitoring bundle - Leaves the existing tracingMiddleware in place; honoTracing is the replacement for dogfood consumers Tests Added src/__tests__/tracing-ergonomics.test.ts (11 tests): - startChild: trace-id inheritance, parent-span linkage, attributes - runWithSpan/getActiveSpan: synchronous, async, deep-stack scenarios - honoTracing: null-safety, skip predicate, root span publication, active-span scoping, 5xx → error, thrown error → recordError, custom spanNamer + attributes 82/82 tests passing (71 existing redact + 11 new ergonomics). Exports added to src/index.ts: - honoTracing, getActiveSpan - HonoTracingMonitoring, HonoTracingOptions types Closes #3 Closes #4 Co-Authored-By: Claude Opus 4.6 (1M context) --- src/__tests__/tracing-ergonomics.test.ts | 215 +++++++++++++++++++++++ src/index.ts | 8 +- src/tracing.ts | 178 +++++++++++++++++++ 3 files changed, 399 insertions(+), 2 deletions(-) create mode 100644 src/__tests__/tracing-ergonomics.test.ts diff --git a/src/__tests__/tracing-ergonomics.test.ts b/src/__tests__/tracing-ergonomics.test.ts new file mode 100644 index 0000000..ef77b8a --- /dev/null +++ b/src/__tests__/tracing-ergonomics.test.ts @@ -0,0 +1,215 @@ +/** + * Ergonomics tests for worker-observability#3 and #4: + * - Span.startChild() + * - Tracer.runWithSpan + getActiveSpan() + * - honoTracing() middleware (shape + behavior without a real Hono app) + */ + +import { describe, it, expect } from 'vitest'; +import { + Tracer, + Span, + getActiveSpan, + honoTracing, + type SpanExporter, +} from '../tracing'; +import type { TraceSpan } from '../types'; + +class CollectingExporter implements SpanExporter { + public spans: TraceSpan[] = []; + async export(spans: TraceSpan[]): Promise { + this.spans.push(...spans); + } +} + +function makeTracer(exporter: CollectingExporter): Tracer { + return new Tracer({ service: 'test', export: exporter }); +} + +describe('Span.startChild', () => { + it('creates a child span that inherits the parent trace context', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const root = tracer.startTrace('root'); + const child = root.startChild('child', { foo: 'bar' }); + + expect(child.getContext().traceId).toBe(root.getContext().traceId); + expect(child.getContext().spanId).not.toBe(root.getContext().spanId); + + child.end(); + root.end(); + await tracer.flush(); + + expect(exporter.spans).toHaveLength(2); + const recordedChild = exporter.spans.find(s => s.operationName === 'child'); + expect(recordedChild?.parentSpanId).toBe(root.getContext().spanId); + expect(recordedChild?.attributes?.foo).toBe('bar'); + }); +}); + +describe('getActiveSpan + runWithSpan', () => { + it('returns undefined outside a runWithSpan scope', () => { + expect(getActiveSpan()).toBeUndefined(); + }); + + it('exposes the scoped span to synchronous callers', () => { + const tracer = makeTracer(new CollectingExporter()); + const root = tracer.startTrace('root'); + let observed: Span | undefined; + tracer.runWithSpan(root, () => { + observed = getActiveSpan(); + }); + expect(observed).toBe(root); + }); + + it('exposes the scoped span across async boundaries', async () => { + const tracer = makeTracer(new CollectingExporter()); + const root = tracer.startTrace('root'); + let observed: Span | undefined; + await tracer.runWithSpan(root, async () => { + await Promise.resolve(); + await new Promise(r => setTimeout(r, 1)); + observed = getActiveSpan(); + }); + expect(observed).toBe(root); + }); + + it('deep code can create child spans without threading context', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const root = tracer.startTrace('root'); + + async function deeplyNested() { + const child = getActiveSpan()?.startChild('deep'); + child?.setAttributes({ depth: 5 }); + child?.end(); + } + + await tracer.runWithSpan(root, async () => { + await deeplyNested(); + }); + root.end(); + await tracer.flush(); + + const deep = exporter.spans.find(s => s.operationName === 'deep'); + expect(deep).toBeDefined(); + expect(deep?.parentSpanId).toBe(root.getContext().spanId); + expect(deep?.attributes?.depth).toBe(5); + }); +}); + +describe('honoTracing', () => { + function fakeContext(opts: { + method?: string; + path?: string; + status?: number; + throws?: boolean; + } = {}): any { + const stored = new Map(); + const waitUntilPromises: Array> = []; + const headers = new Headers(); + const ctx = { + req: { + method: opts.method ?? 'GET', + url: `https://test.example/${(opts.path ?? '/x').replace(/^\//, '')}`, + raw: { headers }, + header: (name: string) => headers.get(name) ?? undefined, + }, + res: { status: opts.status ?? 200, headers: new Headers() }, + set: (k: string, v: unknown) => stored.set(k, v), + get: (k: string) => stored.get(k), + executionCtx: { + waitUntil: (p: Promise) => { + waitUntilPromises.push(p); + }, + }, + stored, + waitUntilPromises, + }; + return ctx; + } + + it('skips tracing when monitoring.tracer is missing', async () => { + let called = false; + const mw = honoTracing(null); + await mw(fakeContext(), async () => { + called = true; + }); + expect(called).toBe(true); + }); + + it('skip predicate shortcircuits without creating a span', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const mw = honoTracing({ tracer }, { skip: () => true }); + await mw(fakeContext({ path: '/health' }), async () => {}); + expect(exporter.spans).toHaveLength(0); + }); + + it('publishes the root span to c.get(rootSpan) and makes it active', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const mw = honoTracing({ tracer }); + const c = fakeContext({ path: '/run' }); + + let activeInside: Span | undefined; + let rootFromContext: Span | undefined; + await mw(c, async () => { + rootFromContext = c.get('rootSpan') as Span; + activeInside = getActiveSpan(); + }); + + expect(rootFromContext).toBeDefined(); + expect(activeInside).toBe(rootFromContext); + // waitUntil captured the flush + expect(c.waitUntilPromises.length).toBe(1); + await Promise.all(c.waitUntilPromises); + expect(exporter.spans).toHaveLength(1); + expect(exporter.spans[0]!.operationName).toBe('GET /run'); + }); + + it('records errors and sets error status on thrown exceptions', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const mw = honoTracing({ tracer }); + const c = fakeContext(); + + await expect( + mw(c, async () => { + throw new Error('boom'); + }), + ).rejects.toThrow('boom'); + + await Promise.all(c.waitUntilPromises); + expect(exporter.spans[0]!.status).toBe('error'); + const errorEvent = exporter.spans[0]!.events?.find(e => e.name === 'error'); + expect(errorEvent?.attributes?.['error.message']).toBe('boom'); + }); + + it('flags 5xx responses as error status', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const mw = honoTracing({ tracer }); + const c = fakeContext({ status: 503 }); + await mw(c, async () => {}); + await Promise.all(c.waitUntilPromises); + expect(exporter.spans[0]!.status).toBe('error'); + }); + + it('respects custom spanNamer + extra attributes', async () => { + const exporter = new CollectingExporter(); + const tracer = makeTracer(exporter); + const mw = honoTracing( + { tracer }, + { + spanNamer: () => 'custom.name', + attributes: () => ({ 'tenant.id': 't-42' }), + }, + ); + const c = fakeContext(); + await mw(c, async () => {}); + await Promise.all(c.waitUntilPromises); + expect(exporter.spans[0]!.operationName).toBe('custom.name'); + expect(exporter.spans[0]!.attributes?.['tenant.id']).toBe('t-42'); + }); +}); diff --git a/src/index.ts b/src/index.ts index 7672f65..337d4d8 100644 --- a/src/index.ts +++ b/src/index.ts @@ -56,12 +56,16 @@ export { CloudflareTraceExporter, ConsoleTraceExporter, tracingMiddleware, - trace + trace, + honoTracing, + getActiveSpan } from './tracing'; export type { TracerOptions, SpanContext, - SpanExporter + SpanExporter, + HonoTracingMonitoring, + HonoTracingOptions } from './tracing'; // Export error tracking utilities diff --git a/src/tracing.ts b/src/tracing.ts index b31bc47..01fbaa8 100644 --- a/src/tracing.ts +++ b/src/tracing.ts @@ -2,6 +2,13 @@ * Distributed tracing utilities */ +// AsyncLocalStorage comes from node:async_hooks. Cloudflare Workers expose +// it when the `nodejs_als` (or `nodejs_compat`) compat flag is set. We +// import through a narrow ambient declaration instead of pulling @types/node +// into the library — keeps the lib dep-free. +// eslint-disable-next-line @typescript-eslint/ban-ts-comment +// @ts-expect-error — node module types are not part of workers-types +import { AsyncLocalStorage } from 'node:async_hooks'; import type { TraceSpan, SpanStatus, @@ -10,6 +17,29 @@ import type { } from './types'; import type { Redactor } from './redact'; +// ── Active-span context (AsyncLocalStorage) ──────────────────────────────── +// Lets deep code create child spans without threading a parent through every +// function signature. Requires the `nodejs_als` (or `nodejs_compat`) compat +// flag in wrangler.toml — when the flag is off, ALS silently returns +// undefined and getActiveSpan() degrades to a no-op. See worker-observability#4. + +let activeSpanStorage: AsyncLocalStorage | null = null; +try { + activeSpanStorage = new AsyncLocalStorage(); +} catch { + // Runtime without async_hooks — ALS features are no-ops. + activeSpanStorage = null; +} + +/** + * Get the Span associated with the currently-running request, if any. + * Returns undefined outside a `runWithSpan` scope, or when the Workers + * runtime doesn't support AsyncLocalStorage. Safe to call anywhere. + */ +export function getActiveSpan(): Span | undefined { + return activeSpanStorage?.getStore(); +} + export interface TracerOptions { service: string; export?: SpanExporter; @@ -158,6 +188,19 @@ export class Span { spanId: this.span.spanId }; } + + /** + * Start a child span on the same tracer. The child inherits this span's + * trace context as its parent. This is the ergonomic shortcut that saves + * writing `tracer.startSpan(name, { parent: rootSpan.getContext() })` at + * every call site. See worker-observability#3. + */ + startChild(name: string, attributes?: Record): Span { + return this.tracer.startSpan(name, { + parent: this.getContext(), + attributes, + }); + } } export class Tracer { @@ -295,6 +338,17 @@ export class Tracer { } } + /** + * Run a function with the given span as the "active span" for + * AsyncLocalStorage-based context. Calls to getActiveSpan() inside `fn` + * (or async work it starts) will return this span. Falls through as an + * identity wrapper when ALS is unavailable. + */ + runWithSpan(span: Span, fn: () => T): T { + if (!activeSpanStorage) return fn(); + return activeSpanStorage.run(span, fn); + } + private generateTraceId(): string { return crypto.randomUUID().replace(/-/g, ''); } @@ -325,6 +379,9 @@ class NoOpSpan extends Span { getContext(): SpanContext { return { traceId: '', spanId: '' }; } + startChild(): Span { + return this; + } } // Tracing middleware @@ -374,6 +431,127 @@ export function tracingMiddleware(tracer: Tracer) { }; } +// ── Hono-aware tracing helper ────────────────────────────────────────────── +// Batteries-included middleware that centralizes the root-span/child-span +// lifecycle pattern every dogfood worker was rewriting. See #3. + +/** + * Monitoring bundle shape accepted by honoTracing — only the pieces we + * need. Keeps the helper decoupled from the full createMonitoring surface. + */ +export interface HonoTracingMonitoring { + tracer?: Tracer; + metrics?: { flush(): Promise }; +} + +export interface HonoTracingOptions { + /** + * Return true to skip tracing for a request (e.g. health checks, static + * assets). Defaults to tracing everything. + */ + skip?: (c: any) => boolean; + + /** + * Extra attributes to attach to the root span. Called once per request + * with the Hono Context — useful for route patterns, tenant IDs, etc. + */ + attributes?: (c: any) => Record; + + /** + * Override the root-span name. Default: `${method} ${pathname}`. + */ + spanNamer?: (c: any) => string; + + /** + * Hono variable key used to publish the root span to handlers. + * Default: `'rootSpan'`. Handlers can read with `c.get('rootSpan')`. + */ + contextKey?: string; +} + +/** + * Hono-aware tracing middleware. Wraps each request in a root span, + * records HTTP attributes, recordError() on thrown exceptions, setStatus + * on 5xx responses, publishes the root span to `c.get('rootSpan')` and + * makes it the AsyncLocalStorage active span for downstream `getActiveSpan()` + * callers, and flushes tracer+metrics via `ctx.waitUntil` so ingest + * doesn't block the response. + * + * ```ts + * import { honoTracing } from '@stackbilt/worker-observability'; + * + * app.use('*', honoTracing(obs, { skip: (c) => c.req.path === '/health' })); + * + * // Downstream handlers: + * const child = c.get('rootSpan')?.startChild('scaffold.classify'); + * // ...or from deep code without threading: + * const child = getActiveSpan()?.startChild('oracle.inference'); + * ``` + */ +export function honoTracing( + monitoring: HonoTracingMonitoring | null | undefined, + options: HonoTracingOptions = {}, +) { + const contextKey = options.contextKey ?? 'rootSpan'; + + return async (c: any, next: () => Promise) => { + const tracer = monitoring?.tracer; + if (!tracer) return next(); + if (options.skip?.(c)) return next(); + + const url = new URL(c.req.url); + const parentContext = tracer.extract(c.req.raw.headers); + const name = options.spanNamer ? options.spanNamer(c) : `${c.req.method} ${url.pathname}`; + + const baseAttrs: Record = { + 'http.method': c.req.method, + 'http.target': url.pathname, + 'http.host': url.host, + 'http.scheme': url.protocol.replace(':', ''), + 'http.user_agent': c.req.header('user-agent'), + }; + const extraAttrs = options.attributes?.(c) ?? {}; + + const span = tracer.startSpan(name, { + parent: parentContext || undefined, + attributes: { ...baseAttrs, ...extraAttrs }, + }); + + c.set(contextKey, span); + c.set('traceId', span.getContext().traceId); + + try { + await tracer.runWithSpan(span, async () => { + try { + await next(); + span.setAttributes({ 'http.status_code': c.res?.status }); + if (c.res && c.res.status >= 500) { + span.setStatus('error'); + } + } catch (err) { + span.recordError(err as Error); + span.setStatus('error'); + throw err; + } + }); + } finally { + span.end(); + // Fire-and-forget flush — don't block the response. Safe no-op if + // executionCtx isn't present (e.g., direct tests). + const ctx = c.executionCtx as { waitUntil?: (p: Promise) => void } | undefined; + const flushPromise = Promise.allSettled([ + tracer.flush(), + monitoring?.metrics?.flush() ?? Promise.resolve(), + ]); + if (ctx?.waitUntil) { + ctx.waitUntil(flushPromise); + } else { + await flushPromise; + } + } + }; +} + // Helper to trace async operations export async function trace( tracer: Tracer,