diff --git a/README.md b/README.md index 1235e60..3620b79 100644 --- a/README.md +++ b/README.md @@ -177,8 +177,10 @@ new OTLPTraceExporter({ ## Design principles - **Errors are 100%, everything else is sampled or aggregated.** Raw error - occurrences are always kept (14-day TTL); successful traces are expected to - be sampled upstream (0.5–1%); usage is stored as 1-minute rollups (90 days). + occurrences are always kept (14-day TTL); traces containing an error are + retained in full (the Node SDK tail-retains them), so every issue keeps the + trace that explains it; healthy traces are expected to be sampled upstream + (0.5–1%); usage is stored as 1-minute rollups (90 days). - **Per-repo analysis.** Every row is keyed by `org_id` + `repository_id`. - **Privacy by construction.** No cookies, no DOM, no request/response bodies, no emails, no full URLs with query strings. diff --git a/deploy/single-server/docker-compose.yml b/deploy/single-server/docker-compose.yml index 51be7cc..e8831e5 100644 --- a/deploy/single-server/docker-compose.yml +++ b/deploy/single-server/docker-compose.yml @@ -15,7 +15,10 @@ services: # Not published to the host — only the ingester talks to it, over the # internal compose network. Never expose 8123/9000 publicly. healthcheck: - test: ["CMD", "wget", "--spider", "-q", "http://localhost:8123/ping"] + # 127.0.0.1, not localhost: in-container localhost resolves to ::1, but + # ClickHouse's IPv6 bind can silently fail (listen_try), leaving only + # 0.0.0.0 listening and the check refused forever. + test: ["CMD", "wget", "--spider", "-q", "http://127.0.0.1:8123/ping"] interval: 10s timeout: 5s retries: 10 diff --git a/docker-compose.yml b/docker-compose.yml index a8794e9..ea8bd17 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -8,7 +8,10 @@ services: ulimits: nofile: 262144 healthcheck: - test: ["CMD", "wget", "-qO-", "http://localhost:8123/ping"] + # 127.0.0.1, not localhost: in-container localhost resolves to ::1, but + # ClickHouse's IPv6 bind can silently fail (listen_try) — e.g. on Docker + # Desktop for Mac — leaving only 0.0.0.0 listening and the check refused. + test: ["CMD", "wget", "-qO-", "http://127.0.0.1:8123/ping"] interval: 5s retries: 10 diff --git a/docs/GETTING-STARTED.md b/docs/GETTING-STARTED.md index f33f31b..3c1b367 100644 --- a/docs/GETTING-STARTED.md +++ b/docs/GETTING-STARTED.md @@ -41,7 +41,7 @@ you from zero to seeing data in ClickHouse. | Unhandled errors / rejections | ✅ automatic | ✅ automatic | | Handled errors | `captureException(err)` | `captureException(err)` | | Usage | session pings + `trackEvent()` | request counts/durations per route (automatic) | -| Traces | — (by design; no OTel in the browser) | ~1% sampled (configurable) | +| Traces | — (by design; no OTel in the browser) | ~1% sampled, plus **every erroring trace kept in full** | | LLM usage & cost | — | `withLlmCall()` / Vercel AI SDK telemetry / GenAI semconv — always 100% (model, tokens, cost) | **What is never sent:** cookies, DOM content, form values, request/response @@ -58,6 +58,11 @@ cd autter-runtime docker compose up # ClickHouse + ingester on :4318, key "dev-key" ``` +> **That's all the clone is for.** It runs the ingester — you never add +> code to this checkout. Every step from here on (installing packages, +> creating `instrument.cjs`, …) happens in **your application's +> repository**, the app you want to monitor. + For real deployments, configure keys via env (or point `AUTTER_KEY_VALIDATOR_URL` at your own key service): @@ -78,11 +83,15 @@ Full config reference: [`packages/otlp-ingester`](../packages/otlp-ingester). ## 3. Instrument your backend +In **your app's repository** (not the `autter-runtime` checkout from +step 2): + ```bash npm install @autter/runtime-node ``` -Create `instrument.cjs` — it must load **before** your app: +Create `instrument.cjs` in your app's root, next to its entry point — it +must load **before** your app: ```js const { initAutterServer } = require("@autter/runtime-node"); @@ -101,8 +110,10 @@ node --require ./instrument.cjs server.js ``` That alone gives you: every incoming HTTP request traced-and-sampled, -request/error/duration rollups per route, and crashes captured. For -handled errors: +request/error/duration rollups per route, crashes captured, and the full +trace of any request that errors — erroring traces are retained even when +the sampler wouldn't have kept them, so every issue keeps the trace that +explains it. For handled errors: ```js const { captureException } = require("@autter/runtime-node"); @@ -303,7 +314,9 @@ clickhouse-client --password dev`. - [ ] `release` is wired to your git SHA in **both** frontend and backend — it's what powers regression detection ("broke in release X"). - [ ] Keep trace sampling at ~1% (`traceSampleRate`) — errors are always - captured regardless. + captured regardless, and the full trace of an erroring request is + retained (`retainTracesOnError`, on by default), so cheap sampling + doesn't cost you debugging context. - [ ] The relay route keeps its built-in per-IP rate limit (or your WAF covers it: `perIpRateLimit: false`). - [ ] Direct browser ingest: your CSP includes diff --git a/docs/INTEGRATIONS.md b/docs/INTEGRATIONS.md index ba7967b..6f9e9da 100644 --- a/docs/INTEGRATIONS.md +++ b/docs/INTEGRATIONS.md @@ -164,3 +164,15 @@ Errors are always worth sending; keep successful-trace sampling at ~1% (`OTEL_TRACES_SAMPLER_ARG=0.01`). Request/usage metrics are derived server-side from spans and the `http.server.duration` histogram — no extra setup. LLM/GenAI spans are the exception — send them at 100% (see above). + +One consequence of plain head sampling to know about: an error recorded on +an unsampled trace is dropped with it, and even when the error survives +through a separate path, the trace explaining it usually doesn't. +`@autter/runtime-node` handles both automatically — errors ride a dedicated +always-on tracer, and the full trace around an error is tail-retained even +when head sampling said no (`retainTracesOnError`, on by default). On other +stacks, route errors through an always-on tracer provider (same pattern as +the LLM guidance above), and if you want erroring traces kept in full, put +an OTel Collector with the `tail_sampling` processor (a +`status_code = ERROR` policy plus a small `probabilistic` one) in front of +the ingester instead of sampling in the SDK. diff --git a/packages/otlp-ingester/src/normalize-otlp.ts b/packages/otlp-ingester/src/normalize-otlp.ts index 97dafa0..dbcfcaa 100644 --- a/packages/otlp-ingester/src/normalize-otlp.ts +++ b/packages/otlp-ingester/src/normalize-otlp.ts @@ -325,16 +325,12 @@ export function normalizeTraces(request: OtlpTraceRequest): NormalizedTraces { if (llmCall) llmCalls.push(llmCall); // Server spans fold into 1-minute usage rollups so traffic is - // tracked even when the metrics pipeline isn't wired — - // senders that DO export request metrics mark the resource - // with `autter.metrics_wired` and are skipped here, or every - // request they trace would count twice. The rollup key uses - // the normalized route: `http.route` is already a template, - // but the url.path/http.target fallback is a raw path whose - // id segments would explode the SummingMergeTree key space - // (and never line up with the metric-fed rows for the same - // endpoint). - if (kind === "server" && !resource.metricsWired) { + // tracked even when the metrics pipeline isn't wired. Spans + // exported by error-linked tail retention are skipped: the SDK + // ships those at ~100% alongside a metrics pipeline that already + // counts every request, so folding them in would double-count + // erroring routes. + if (kind === "server" && attrs.get("autter.tail_retained") !== "true") { addToRollup(rollups, { service: resource.service, environment: resource.environment, diff --git a/packages/runtime-node/README.md b/packages/runtime-node/README.md index 4cd3361..a13d431 100644 --- a/packages/runtime-node/README.md +++ b/packages/runtime-node/README.md @@ -83,12 +83,23 @@ Defaults (cheap by construction): | Signal | Default | | --- | --- | | Captured/unhandled exceptions | 100% (dedicated always-on tracer) | +| Traces containing an error | 100% (tail retention, `retainTracesOnError`) | | `withProcessSpan` spans | 100% (same always-on tracer) | | LLM/GenAI call spans | 100% (`llmTracing`, on by default) | -| Traces | 1% head sampling (`traceSampleRate`) | +| Healthy traces | 1% head sampling (`traceSampleRate`) | | Request metrics | exported every 60 s | | Logs | not collected | +**Error-linked trace retention.** Errors export at 100% while traces are +head-sampled — on its own that strands a retained error without the trace +that explains it. So unsampled spans are kept briefly in an in-process +buffer, and the moment a trace shows an error — a 5xx response, a recorded +exception, `captureException`, or an error-severity `captureMessage` — the +whole trace is exported, sampling lottery notwithstanding. The buffer is +bounded (256 spans per trace, 5 000 spans total, dropped as soon as the +request ends healthy, 30 s TTL), degrades to plain head sampling on +overflow, and never blocks. Disable with `retainTracesOnError: false`. + Crashes are observed via `process.uncaughtExceptionMonitor`, which does **not** change your process's exit behaviour; the final flush is best-effort. Framework instrumentations are opt-in: @@ -102,6 +113,8 @@ Note on usage rollups: requests are counted from the `http.server.duration` metric (100% accurate) and additionally from sampled server spans. At the default 1% sampling the span contribution is negligible; if you set `traceSampleRate: 1` in development, expect request counts roughly doubled. +Tail-retained error traces don't distort this: their spans carry +`autter.tail_retained` and the ingester keeps them out of span-fed rollups. ## 3. LLM tracing diff --git a/packages/runtime-node/src/server.ts b/packages/runtime-node/src/server.ts index 07426ba..d4b041d 100644 --- a/packages/runtime-node/src/server.ts +++ b/packages/runtime-node/src/server.ts @@ -4,6 +4,7 @@ import { trace, SpanKind, SpanStatusCode, + TraceFlags, type Attributes, type Context, type Link, @@ -27,8 +28,11 @@ import { AlwaysOnSampler, BasicTracerProvider, SamplingDecision, + type ReadableSpan, type Sampler, type SamplingResult, + type Span as SdkSpan, + type SpanProcessor, } from "@opentelemetry/sdk-trace-base"; import { ATTR_SERVICE_NAME, @@ -40,6 +44,10 @@ import { * auto-instrumentation metapackage. Default data-volume policy: * * errors / captured exceptions : 100% (dedicated always-on error tracer) + * traces containing an error : 100% (tail retention — the full trace is + * exported when any of its spans + * errors, so a retained error keeps + * the trace that explains it) * named process spans : 100% (withProcessSpan, always-on tracer) * LLM / GenAI call spans : 100% (withLlmCall/trackLlmCall/ * instrumentLlmClient + an LLM-aware @@ -67,6 +75,17 @@ export interface AutterServerOptions { release?: string; /** Head-sampling ratio for regular traces. Default 0.01 (1%). */ traceSampleRate?: number; + /** + * Keep the FULL trace whenever it contains an error: an ERROR-status + * span (e.g. a 5xx request), a recorded exception, or a + * `captureException` / error-severity `captureMessage` call made inside + * it. Head sampling still decides what is exported for healthy traffic; + * erroring traces are rescued from the unsampled pool by a bounded + * in-process buffer — without this, errors are retained at 100% while + * the trace explaining them survives only `traceSampleRate` of the time. + * Default true. + */ + retainTracesOnError?: boolean; /** Metric export interval. Default 60_000 ms. */ metricIntervalMs?: number; /** Capture crashing exceptions via process.uncaughtExceptionMonitor (default true). */ @@ -242,6 +261,219 @@ class LlmAwareSampler implements Sampler { } } +/** + * Upgrades NOT_RECORD decisions to RECORD so head-unsampled traces still + * materialise in-process: their spans reach the span processors with the + * sampled flag off (the regular batch processor ignores them) where + * ErrorTraceRetentionProcessor can buffer them and promote the whole trace + * to export if an error shows up. The W3C traceparent stays unsampled + * either way, so downstream services behave exactly as before. + */ +class RecordUnsampledSampler implements Sampler { + constructor(private readonly delegate: Sampler) {} + + shouldSample( + ctx: Context, + traceId: string, + spanName: string, + spanKind: SpanKind, + attributes: Attributes, + links: Link[], + ): SamplingResult { + const result = this.delegate.shouldSample( + ctx, + traceId, + spanName, + spanKind, + attributes, + links, + ); + if (result.decision === SamplingDecision.NOT_RECORD) { + return { ...result, decision: SamplingDecision.RECORD }; + } + return result; + } + + toString(): string { + return `RecordUnsampled(${this.delegate.toString()})`; + } +} + +const RETENTION_MAX_SPANS_PER_TRACE = 256; +const RETENTION_MAX_BUFFERED_SPANS = 5_000; +const RETENTION_SWEEP_INTERVAL_MS = 10_000; +const RETENTION_TRACE_TTL_MS = 30_000; + +function spanIndicatesError(span: ReadableSpan): boolean { + if (span.status.code === SpanStatusCode.ERROR) return true; + return span.events.some((event) => event.name === "exception"); +} + +/** Marks spans exported by tail retention rather than head sampling. The + * ingester uses it to keep such spans out of span-fed usage rollups — + * erroring requests are already counted by the metrics pipeline, and at + * ~100% retention the span contribution would double-count them. */ +const TAIL_RETAINED_ATTR = "autter.tail_retained"; + +/** The batch processor only exports spans with the sampled flag, so a + * rescued span is re-wrapped with the flag set — which is also the truth: + * the tail decision sampled it. */ +function withSampledFlag(span: ReadableSpan): ReadableSpan { + const spanContext = { + ...span.spanContext(), + traceFlags: span.spanContext().traceFlags | TraceFlags.SAMPLED, + }; + return { + name: span.name, + kind: span.kind, + spanContext: () => spanContext, + parentSpanId: span.parentSpanId, + startTime: span.startTime, + endTime: span.endTime, + status: span.status, + attributes: { ...span.attributes, [TAIL_RETAINED_ATTR]: true }, + links: span.links, + events: span.events, + duration: span.duration, + ended: span.ended, + resource: span.resource, + instrumentationLibrary: span.instrumentationLibrary, + droppedAttributesCount: span.droppedAttributesCount, + droppedEventsCount: span.droppedEventsCount, + droppedLinksCount: span.droppedLinksCount, + }; +} + +interface RetentionEntry { + spans: ReadableSpan[]; + retained: boolean; + firstSeenAtMs: number; +} + +/** + * Tail retention for erroring traces. Errors export at 100% via the + * always-on tracer while regular traces are head-sampled at ~1% — so the + * trace that explains a retained error would almost always be gone. This + * processor buffers the finished-but-unsampled spans of in-flight traces + * and promotes a whole trace to export the moment it shows an error: an + * ERROR-status span (5xx requests included), an `exception` event, or an + * explicit captureException / captureMessage("…", "error") inside it. + * + * Bounded by construction: per-trace and total span caps, buffers dropped + * as soon as the local root span ends healthy, and a TTL sweep for traces + * whose root is never seen. On overflow it degrades to plain head sampling + * for the evicted traces — it never blocks and never grows unbounded. + * Errors reported after the root span has ended keep their occurrence (the + * always-on pipe) but can no longer rescue the request trace. + */ +class ErrorTraceRetentionProcessor implements SpanProcessor { + private readonly traces = new Map(); + private bufferedSpans = 0; + private readonly sweeper: NodeJS.Timeout; + + constructor(private readonly inner: SpanProcessor) { + this.sweeper = setInterval(() => this.sweep(), RETENTION_SWEEP_INTERVAL_MS); + // Never hold the process open just to babysit the buffer. + this.sweeper.unref?.(); + } + + onStart(_span: SdkSpan, _parentContext: Context): void {} + + onEnd(span: ReadableSpan): void { + const ctx = span.spanContext(); + // Head-sampled spans already export through the regular processor. + if ((ctx.traceFlags & TraceFlags.SAMPLED) !== 0) return; + + const entry = this.entryFor(ctx.traceId); + if (entry.retained) { + this.forward(span); + } else if (spanIndicatesError(span)) { + entry.retained = true; + this.flush(entry); + this.forward(span); + } else if (entry.spans.length < RETENTION_MAX_SPANS_PER_TRACE) { + entry.spans.push(span); + this.bufferedSpans++; + this.evictIfOverBudget(); + } + + // The local root ended: the request is over, and an error inside it + // would have surfaced by now. Drop a healthy trace's buffer; keep + // retained entries so late stragglers still export (sweep cleans up). + if (span.parentSpanId === undefined && !entry.retained) { + this.drop(ctx.traceId); + } + } + + /** Promote the active trace, if any — called on captured errors. */ + retainActiveTrace(): void { + const active = trace.getActiveSpan()?.spanContext(); + // No active trace, or a head-sampled one that exports anyway. + if (!active || (active.traceFlags & TraceFlags.SAMPLED) !== 0) return; + const entry = this.entryFor(active.traceId); + if (entry.retained) return; + entry.retained = true; + this.flush(entry); + } + + forceFlush(): Promise { + return this.inner.forceFlush(); + } + + shutdown(): Promise { + clearInterval(this.sweeper); + this.traces.clear(); + this.bufferedSpans = 0; + return this.inner.shutdown(); + } + + private entryFor(traceId: string): RetentionEntry { + let entry = this.traces.get(traceId); + if (!entry) { + entry = { spans: [], retained: false, firstSeenAtMs: Date.now() }; + this.traces.set(traceId, entry); + } + return entry; + } + + private forward(span: ReadableSpan): void { + this.inner.onEnd(withSampledFlag(span)); + } + + private flush(entry: RetentionEntry): void { + for (const span of entry.spans) this.forward(span); + this.bufferedSpans -= entry.spans.length; + entry.spans = []; + } + + private drop(traceId: string): void { + const entry = this.traces.get(traceId); + if (!entry) return; + this.bufferedSpans -= entry.spans.length; + this.traces.delete(traceId); + } + + private evictIfOverBudget(): void { + if (this.bufferedSpans <= RETENTION_MAX_BUFFERED_SPANS) return; + // Insertion order ≈ oldest trace first; evicting whole traces keeps + // what survives coherent instead of leaving partial traces behind. + // Entries without buffered spans (retained markers, drained traces) + // don't help the budget and keep their rescue semantics. + for (const [traceId, entry] of this.traces) { + if (entry.spans.length === 0) continue; + this.drop(traceId); + if (this.bufferedSpans <= RETENTION_MAX_BUFFERED_SPANS) return; + } + } + + private sweep(): void { + const cutoff = Date.now() - RETENTION_TRACE_TTL_MS; + for (const [traceId, entry] of this.traces) { + if (entry.firstSeenAtMs <= cutoff) this.drop(traceId); + } + } +} + function llmBaseAttributes(info: LlmCallInfo): Attributes { return { "gen_ai.operation.name": info.operation ?? "chat", @@ -447,19 +679,36 @@ export function initAutterServer(options: AutterServerOptions): AutterServer { const headSampler = new ParentBasedSampler({ root: new TraceIdRatioBasedSampler(options.traceSampleRate ?? 0.01), }); + const retainOnError = options.retainTracesOnError !== false; + // Error-linked trace retention (default on): unsampled spans are still + // recorded in-process and briefly buffered, so a trace can be exported in + // full once it turns out to contain an error. Rescued spans ride their + // own batch processor on the errors' 2 s flush cadence. + let sampler: Sampler = retainOnError + ? new RecordUnsampledSampler(headSampler) + : headSampler; + // LLM tracing is on by default: gen_ai/ai.* spans emitted through the + // global provider (Vercel AI SDK, GenAI instrumentations) skip head + // sampling so every model call reaches the ingester. + if (options.llmTracing !== false) sampler = new LlmAwareSampler(sampler); + const errorTraceBuffer = retainOnError + ? new ErrorTraceRetentionProcessor( + new BatchSpanProcessor( + new OTLPTraceExporter({ url: `${endpoint}/v1/traces`, headers }), + { scheduledDelayMillis: 2000 }, + ), + ) + : null; + const sdk = new NodeSDK({ resource, - // LLM tracing is on by default: gen_ai/ai.* spans emitted through the - // global provider (Vercel AI SDK, GenAI instrumentations) skip head - // sampling so every model call reaches the ingester. - sampler: - options.llmTracing === false - ? headSampler - : new LlmAwareSampler(headSampler), - traceExporter: new OTLPTraceExporter({ - url: `${endpoint}/v1/traces`, - headers, - }), + sampler, + spanProcessors: [ + new BatchSpanProcessor( + new OTLPTraceExporter({ url: `${endpoint}/v1/traces`, headers }), + ), + ...(errorTraceBuffer ? [errorTraceBuffer] : []), + ], metricReader: new PeriodicExportingMetricReader({ exporter: new OTLPMetricExporter({ url: `${endpoint}/v1/metrics`, @@ -501,6 +750,8 @@ export function initAutterServer(options: AutterServerOptions): AutterServer { const llmTracer = alwaysOnProvider.getTracer("autter-llm"); function captureException(error: unknown, attributes?: Attributes): void { + // A captured error makes the surrounding trace worth keeping in full. + errorTraceBuffer?.retainActiveTrace(); const isError = error instanceof Error; const message = isError ? error.message : String(error); const span = errorTracer.startSpan(isError ? error.name : "Error", { @@ -532,6 +783,11 @@ export function initAutterServer(options: AutterServerOptions): AutterServer { severity: AutterSeverity = "warning", attributes?: Attributes, ): void { + // Error-severity messages rescue their trace like exceptions do; + // warnings/info are too chatty to justify exporting whole traces. + if (severity === "error" || severity === "fatal") { + errorTraceBuffer?.retainActiveTrace(); + } // Same wire shape as an exception (an event named "exception" with // ERROR status is what the ingester turns into an occurrence), with // autter.severity carrying the level. A synthetic stack (minus this