|
| 1 | +/* |
| 2 | + * Copyright (c) 2023-2026 - Restate Software, Inc., Restate GmbH |
| 3 | + * |
| 4 | + * This file is part of the Restate SDK for Node.js/TypeScript, |
| 5 | + * which is released under the MIT license. |
| 6 | + * |
| 7 | + * You can find a copy of the license in file LICENSE in the root |
| 8 | + * directory of this repository or package, or at |
| 9 | + * https://github.com/restatedev/sdk-typescript/blob/main/LICENSE |
| 10 | + */ |
| 11 | + |
| 12 | +import { describe, it, beforeAll, afterAll, afterEach, expect } from "vitest"; |
| 13 | +import { RestateTestEnvironment } from "@restatedev/restate-sdk-testcontainers"; |
| 14 | +import * as clients from "@restatedev/restate-sdk-clients"; |
| 15 | +import { service, TerminalError, type Context } from "@restatedev/restate-sdk"; |
| 16 | +import { context, trace, type Attributes } from "@opentelemetry/api"; |
| 17 | +import { AsyncLocalStorageContextManager } from "@opentelemetry/context-async-hooks"; |
| 18 | +import { |
| 19 | + BasicTracerProvider, |
| 20 | + InMemorySpanExporter, |
| 21 | + SimpleSpanProcessor, |
| 22 | + type ReadableSpan, |
| 23 | +} from "@opentelemetry/sdk-trace-base"; |
| 24 | +import { openTelemetryHook } from "../src/index.js"; |
| 25 | + |
| 26 | +// The Restate SDK is OpenTelemetry-agnostic, so nothing registers a context |
| 27 | +// manager for us (in production `NodeSDK.start()` does it). The hook relies on |
| 28 | +// `context.with()` / `trace.getActiveSpan()`, which are silent no-ops without |
| 29 | +// one - so the replay case's `addEvent` would vanish. Register it once for the |
| 30 | +// whole file. |
| 31 | +const contextManager = new AsyncLocalStorageContextManager(); |
| 32 | + |
| 33 | +beforeAll(() => { |
| 34 | + contextManager.enable(); |
| 35 | + context.setGlobalContextManager(contextManager); |
| 36 | +}); |
| 37 | + |
| 38 | +afterAll(() => { |
| 39 | + context.disable(); |
| 40 | +}); |
| 41 | + |
| 42 | +// --- span normalization ----------------------------------------------------- |
| 43 | + |
| 44 | +interface NormalizedSpan { |
| 45 | + name: string; |
| 46 | + kind: string; |
| 47 | + status: string; |
| 48 | + parent: string; |
| 49 | + attributes: Record<string, unknown>; |
| 50 | + events: Array<{ name: string; attributes?: Record<string, unknown> }>; |
| 51 | +} |
| 52 | + |
| 53 | +const SPAN_KIND = ["INTERNAL", "SERVER", "CLIENT", "PRODUCER", "CONSUMER"]; |
| 54 | +const STATUS = ["UNSET", "OK", "ERROR"]; |
| 55 | + |
| 56 | +function hrToNanos(t: readonly [number, number]): number { |
| 57 | + return t[0] * 1e9 + t[1]; |
| 58 | +} |
| 59 | + |
| 60 | +// Project attributes to a stable, sorted form: redact the per-run invocation id |
| 61 | +// and drop the exception stacktrace (absolute file paths + line numbers). |
| 62 | +function normalizeAttributes(attrs: Attributes): Record<string, unknown> { |
| 63 | + const out: Record<string, unknown> = {}; |
| 64 | + for (const key of Object.keys(attrs).sort()) { |
| 65 | + if (key === "exception.stacktrace") { |
| 66 | + continue; |
| 67 | + } |
| 68 | + out[key] = key === "restate.invocation.id" ? "<redacted>" : attrs[key]; |
| 69 | + } |
| 70 | + return out; |
| 71 | +} |
| 72 | + |
| 73 | +// Reduce finished spans to a deterministic tree: ids/timestamps stripped, the |
| 74 | +// parent expressed relationally (the name of a local span, or "<incoming>" for |
| 75 | +// the runtime's span that lives outside our exporter). |
| 76 | +function normalize(spans: readonly ReadableSpan[]): NormalizedSpan[] { |
| 77 | + const nameBySpanId = new Map<string, string>(); |
| 78 | + for (const span of spans) { |
| 79 | + nameBySpanId.set(span.spanContext().spanId, span.name); |
| 80 | + } |
| 81 | + |
| 82 | + return [...spans] |
| 83 | + .sort((a, b) => hrToNanos(a.startTime) - hrToNanos(b.startTime)) |
| 84 | + .map((span) => { |
| 85 | + const parentId = |
| 86 | + span.parentSpanContext?.spanId ?? |
| 87 | + (span as { parentSpanId?: string }).parentSpanId; |
| 88 | + const parent = parentId |
| 89 | + ? (nameBySpanId.get(parentId) ?? "<incoming>") |
| 90 | + : "<root>"; |
| 91 | + |
| 92 | + const events = span.events.map((event) => { |
| 93 | + const attributes = normalizeAttributes(event.attributes ?? {}); |
| 94 | + return Object.keys(attributes).length > 0 |
| 95 | + ? { name: event.name, attributes } |
| 96 | + : { name: event.name }; |
| 97 | + }); |
| 98 | + |
| 99 | + return { |
| 100 | + name: span.name, |
| 101 | + kind: SPAN_KIND[span.kind] ?? String(span.kind), |
| 102 | + status: STATUS[span.status.code] ?? String(span.status.code), |
| 103 | + parent, |
| 104 | + attributes: normalizeAttributes(span.attributes), |
| 105 | + events, |
| 106 | + }; |
| 107 | + }); |
| 108 | +} |
| 109 | + |
| 110 | +async function collectSpans( |
| 111 | + exporter: InMemorySpanExporter, |
| 112 | + provider: BasicTracerProvider, |
| 113 | + predicate: (spans: readonly ReadableSpan[]) => boolean, |
| 114 | + timeoutMs = 5000 |
| 115 | +): Promise<NormalizedSpan[]> { |
| 116 | + const start = Date.now(); |
| 117 | + for (;;) { |
| 118 | + await provider.forceFlush(); |
| 119 | + const spans = exporter.getFinishedSpans(); |
| 120 | + if (predicate(spans) || Date.now() - start > timeoutMs) { |
| 121 | + return normalize(spans); |
| 122 | + } |
| 123 | + await new Promise((resolve) => setTimeout(resolve, 50)); |
| 124 | + } |
| 125 | +} |
| 126 | + |
| 127 | +function newTracing() { |
| 128 | + const exporter = new InMemorySpanExporter(); |
| 129 | + const provider = new BasicTracerProvider({ |
| 130 | + spanProcessors: [new SimpleSpanProcessor(exporter)], |
| 131 | + }); |
| 132 | + return { exporter, provider, tracer: provider.getTracer("otel-hook-test") }; |
| 133 | +} |
| 134 | + |
| 135 | +// --- happy + error paths (normal runtime) ----------------------------------- |
| 136 | + |
| 137 | +describe("openTelemetryHook spans", { timeout: 60_000 }, () => { |
| 138 | + const { exporter, provider, tracer } = newTracing(); |
| 139 | + |
| 140 | + const greeter = service({ |
| 141 | + name: "Greeter", |
| 142 | + handlers: { |
| 143 | + greet: async (ctx: Context, name: string) => { |
| 144 | + return ctx.run("compute", async () => `Hello, ${name}!`); |
| 145 | + }, |
| 146 | + }, |
| 147 | + options: { hooks: [openTelemetryHook({ tracer })] }, |
| 148 | + }); |
| 149 | + |
| 150 | + const boom = service({ |
| 151 | + name: "Boom", |
| 152 | + handlers: { |
| 153 | + fail: async (_ctx: Context): Promise<never> => { |
| 154 | + throw new TerminalError("handler blew up"); |
| 155 | + }, |
| 156 | + }, |
| 157 | + options: { hooks: [openTelemetryHook({ tracer })] }, |
| 158 | + }); |
| 159 | + |
| 160 | + let env: RestateTestEnvironment; |
| 161 | + let rs: clients.Ingress; |
| 162 | + |
| 163 | + beforeAll(async () => { |
| 164 | + env = await RestateTestEnvironment.start({ services: [greeter, boom] }); |
| 165 | + rs = clients.connect({ url: env.baseUrl() }); |
| 166 | + }, 60_000); |
| 167 | + |
| 168 | + afterAll(async () => { |
| 169 | + await env?.stop(); |
| 170 | + }); |
| 171 | + |
| 172 | + afterEach(() => { |
| 173 | + exporter.reset(); |
| 174 | + }); |
| 175 | + |
| 176 | + it("emits an attempt span with a child run span on success", async () => { |
| 177 | + const result = await rs.serviceClient(greeter).greet("world"); |
| 178 | + expect(result).toBe("Hello, world!"); |
| 179 | + |
| 180 | + const spans = await collectSpans(exporter, provider, (s) => s.length >= 2); |
| 181 | + expect(spans).toMatchInlineSnapshot(` |
| 182 | + [ |
| 183 | + { |
| 184 | + "attributes": { |
| 185 | + "restate.invocation.id": "<redacted>", |
| 186 | + "restate.invocation.target": "Greeter/greet", |
| 187 | + }, |
| 188 | + "events": [], |
| 189 | + "kind": "INTERNAL", |
| 190 | + "name": "attempt Greeter/greet", |
| 191 | + "parent": "<root>", |
| 192 | + "status": "OK", |
| 193 | + }, |
| 194 | + { |
| 195 | + "attributes": { |
| 196 | + "restate.run.name": "compute", |
| 197 | + }, |
| 198 | + "events": [], |
| 199 | + "kind": "INTERNAL", |
| 200 | + "name": "run (compute)", |
| 201 | + "parent": "attempt Greeter/greet", |
| 202 | + "status": "OK", |
| 203 | + }, |
| 204 | + ] |
| 205 | + `); |
| 206 | + }); |
| 207 | + |
| 208 | + it("marks the attempt span as errored and records the exception", async () => { |
| 209 | + await expect(rs.serviceClient(boom).fail()).rejects.toThrow( |
| 210 | + "handler blew up" |
| 211 | + ); |
| 212 | + |
| 213 | + const spans = await collectSpans(exporter, provider, (s) => |
| 214 | + s.some((span) => span.status.code === 2) |
| 215 | + ); |
| 216 | + expect(spans).toMatchInlineSnapshot(` |
| 217 | + [ |
| 218 | + { |
| 219 | + "attributes": { |
| 220 | + "restate.invocation.id": "<redacted>", |
| 221 | + "restate.invocation.target": "Boom/fail", |
| 222 | + }, |
| 223 | + "events": [ |
| 224 | + { |
| 225 | + "attributes": { |
| 226 | + "exception.message": "handler blew up", |
| 227 | + "exception.type": "500", |
| 228 | + }, |
| 229 | + "name": "exception", |
| 230 | + }, |
| 231 | + ], |
| 232 | + "kind": "INTERNAL", |
| 233 | + "name": "attempt Boom/fail", |
| 234 | + "parent": "<root>", |
| 235 | + "status": "ERROR", |
| 236 | + }, |
| 237 | + ] |
| 238 | + `); |
| 239 | + }); |
| 240 | +}); |
| 241 | + |
| 242 | +// --- replay event suppression (alwaysReplay runtime) ------------------------ |
| 243 | + |
| 244 | +describe("openTelemetryHook replay suppression", { timeout: 60_000 }, () => { |
| 245 | + const { exporter, provider, tracer } = newTracing(); |
| 246 | + |
| 247 | + // Adds an event before and after a suspension point. With alwaysReplay the |
| 248 | + // invocation suspends at the sleep and replays: on the replayed attempt the |
| 249 | + // pre-suspension event is re-added while replaying journaled work and must be |
| 250 | + // suppressed, while the post-suspension event (fresh processing) is kept. |
| 251 | + const replayer = service({ |
| 252 | + name: "Replayer", |
| 253 | + handlers: { |
| 254 | + go: async (ctx: Context) => { |
| 255 | + trace.getActiveSpan()?.addEvent("before-suspend"); |
| 256 | + await ctx.sleep(10); |
| 257 | + trace.getActiveSpan()?.addEvent("after-suspend"); |
| 258 | + return "done"; |
| 259 | + }, |
| 260 | + }, |
| 261 | + options: { hooks: [openTelemetryHook({ tracer })] }, |
| 262 | + }); |
| 263 | + |
| 264 | + let env: RestateTestEnvironment; |
| 265 | + let rs: clients.Ingress; |
| 266 | + |
| 267 | + beforeAll(async () => { |
| 268 | + env = await RestateTestEnvironment.start({ |
| 269 | + services: [replayer], |
| 270 | + alwaysReplay: true, |
| 271 | + }); |
| 272 | + rs = clients.connect({ url: env.baseUrl() }); |
| 273 | + }, 60_000); |
| 274 | + |
| 275 | + afterAll(async () => { |
| 276 | + await env?.stop(); |
| 277 | + }); |
| 278 | + |
| 279 | + it("suppresses span events added while replaying journaled work", async () => { |
| 280 | + const result = await rs.serviceClient(replayer).go(); |
| 281 | + expect(result).toBe("done"); |
| 282 | + |
| 283 | + // Two attempts: the original (suspends at sleep) and the replay. |
| 284 | + const spans = await collectSpans(exporter, provider, (s) => s.length >= 2); |
| 285 | + expect(spans).toMatchInlineSnapshot(` |
| 286 | + [ |
| 287 | + { |
| 288 | + "attributes": { |
| 289 | + "restate.invocation.id": "<redacted>", |
| 290 | + "restate.invocation.target": "Replayer/go", |
| 291 | + }, |
| 292 | + "events": [ |
| 293 | + { |
| 294 | + "name": "before-suspend", |
| 295 | + }, |
| 296 | + ], |
| 297 | + "kind": "INTERNAL", |
| 298 | + "name": "attempt Replayer/go", |
| 299 | + "parent": "<root>", |
| 300 | + "status": "UNSET", |
| 301 | + }, |
| 302 | + { |
| 303 | + "attributes": { |
| 304 | + "restate.invocation.id": "<redacted>", |
| 305 | + "restate.invocation.target": "Replayer/go", |
| 306 | + }, |
| 307 | + "events": [ |
| 308 | + { |
| 309 | + "name": "after-suspend", |
| 310 | + }, |
| 311 | + ], |
| 312 | + "kind": "INTERNAL", |
| 313 | + "name": "attempt Replayer/go", |
| 314 | + "parent": "<root>", |
| 315 | + "status": "OK", |
| 316 | + }, |
| 317 | + ] |
| 318 | + `); |
| 319 | + }); |
| 320 | +}); |
0 commit comments