|
| 1 | +import { createServer } from "node:http"; |
| 2 | +import { setTimeout as sleep } from "node:timers/promises"; |
| 3 | +import { SpanStatusCode, trace } from "@opentelemetry/api"; |
| 4 | +import { |
| 5 | + SemanticInternalAttributes as Attr, |
| 6 | + SessionChannelRouter, |
| 7 | + usage, |
| 8 | + WaitpointTimeoutError, |
| 9 | +} from "@trigger.dev/core/v3"; |
| 10 | +import { TracingSDK, type TracingSDKConfig } from "@trigger.dev/core/v3/otel"; |
| 11 | +import { DevUsageManager } from "@trigger.dev/core/v3/workers"; |
| 12 | +import { afterAll, assert, beforeAll, beforeEach, describe, expect, it } from "vitest"; |
| 13 | +import { traceSessionIdle, traceSessionWait } from "./sessionTracing.js"; |
| 14 | +import { tracer } from "./tracer.js"; |
| 15 | + |
| 16 | +type Exporter = NonNullable<TracingSDKConfig["exporters"]>[number]; |
| 17 | +type ExportedSpan = Parameters<Exporter["export"]>[0][number]; |
| 18 | +type WireSpan = { |
| 19 | + name: string; |
| 20 | + attributes: Array<{ key: string; value: { stringValue?: string; boolValue?: boolean } }>; |
| 21 | +}; |
| 22 | + |
| 23 | +const spans: ExportedSpan[] = []; |
| 24 | +const wireSpans: WireSpan[] = []; |
| 25 | +// A real local OTLP receiver also captures partial spans, which external |
| 26 | +// exporters intentionally omit. No tracer, router, or usage mocks are used. |
| 27 | +const receiver = createServer(async (request, response) => { |
| 28 | + const chunks: Buffer[] = []; |
| 29 | + for await (const chunk of request) chunks.push(Buffer.from(chunk)); |
| 30 | + if (request.url === "/v1/traces") { |
| 31 | + const body = JSON.parse(Buffer.concat(chunks).toString()); |
| 32 | + for (const resource of body.resourceSpans ?? []) { |
| 33 | + for (const scope of resource.scopeSpans ?? []) wireSpans.push(...scope.spans); |
| 34 | + } |
| 35 | + } |
| 36 | + response.writeHead(200, { "Content-Type": "application/json" }).end("{}"); |
| 37 | +}); |
| 38 | +let tracing: TracingSDK; |
| 39 | + |
| 40 | +beforeAll(async () => { |
| 41 | + await new Promise<void>((resolve) => receiver.listen(0, "127.0.0.1", resolve)); |
| 42 | + const address = receiver.address(); |
| 43 | + if (!address || typeof address === "string") throw new Error("Missing OTLP receiver address"); |
| 44 | + tracing = new TracingSDK({ |
| 45 | + url: `http://127.0.0.1:${address.port}`, |
| 46 | + forceFlushTimeoutMillis: 5_000, |
| 47 | + exporters: [ |
| 48 | + { |
| 49 | + export(batch, done) { |
| 50 | + spans.push(...batch); |
| 51 | + done({ code: 0 }); |
| 52 | + }, |
| 53 | + async shutdown() {}, |
| 54 | + }, |
| 55 | + ], |
| 56 | + }); |
| 57 | +}); |
| 58 | + |
| 59 | +beforeEach(async () => { |
| 60 | + await tracing.flush(); |
| 61 | + spans.length = 0; |
| 62 | + wireSpans.length = 0; |
| 63 | + usage.reset(); |
| 64 | + usage.setGlobalUsageManager(new DevUsageManager()); |
| 65 | +}); |
| 66 | + |
| 67 | +afterAll(async () => { |
| 68 | + usage.reset(); |
| 69 | + await tracing?.shutdown(); |
| 70 | + await new Promise<void>((resolve, reject) => |
| 71 | + receiver.close((error) => (error ? reject(error) : resolve())) |
| 72 | + ); |
| 73 | +}); |
| 74 | + |
| 75 | +function messageRouter() { |
| 76 | + return new SessionChannelRouter({ |
| 77 | + kindOf: () => "message", |
| 78 | + routes: [{ name: "messages", delivery: "queue", replayable: true, kinds: ["message"] }], |
| 79 | + }); |
| 80 | +} |
| 81 | + |
| 82 | +describe("session trace phases", () => { |
| 83 | + it.each([30, 10])( |
| 84 | + "shows a message arriving within a %ss idle window without a waitpoint", |
| 85 | + async (seconds) => { |
| 86 | + const router = messageRouter(); |
| 87 | + const message = { id: "m1", seqNum: 1, data: { text: "hello" } }; |
| 88 | + const measurement = usage.start(); |
| 89 | + const result = await tracer.startActiveSpan("next message", async () => { |
| 90 | + const pending = traceSessionIdle("session_test", seconds, () => |
| 91 | + router.next("messages", { timeoutMs: seconds * 1000 }) |
| 92 | + ); |
| 93 | + router.ingest(message); |
| 94 | + return pending; |
| 95 | + }); |
| 96 | + const sample = usage.stop(measurement); |
| 97 | + |
| 98 | + expect(result).toBe(message); |
| 99 | + expect(sample.cpuTime).toBe(sample.wallTime); |
| 100 | + expect(spans.map((span) => span.name)).toEqual(["idle", "next message"]); |
| 101 | + const [idle, parent] = spans; |
| 102 | + assert(idle); |
| 103 | + assert(parent); |
| 104 | + expect(idle.parentSpanContext?.spanId).toBe(parent.spanContext().spanId); |
| 105 | + expect(idle.attributes["wait.idleTimeoutInSeconds"]).toBe(seconds); |
| 106 | + expect(idle.attributes[Attr.ENTITY_TYPE]).toBeUndefined(); |
| 107 | + expect(idle.attributes.session).toBe("session_test"); |
| 108 | + } |
| 109 | + ); |
| 110 | + |
| 111 | + it("exports a linked waitpoint while waiting and keeps idle and durable usage separate", async () => { |
| 112 | + const router = messageRouter(); |
| 113 | + let finish!: () => void; |
| 114 | + const completed = new Promise<void>((resolve) => { |
| 115 | + finish = resolve; |
| 116 | + }); |
| 117 | + let entered!: () => void; |
| 118 | + const waiting = new Promise<void>((resolve) => { |
| 119 | + entered = resolve; |
| 120 | + }); |
| 121 | + const measurement = usage.start(); |
| 122 | + const result = { ok: true as const, waitpointId: "waitpoint_test" }; |
| 123 | + const pending = tracer.startActiveSpan("next message", async () => { |
| 124 | + expect( |
| 125 | + await traceSessionIdle("session_test", 0.01, () => |
| 126 | + router.next("messages", { timeoutMs: 10 }) |
| 127 | + ) |
| 128 | + ).toBeUndefined(); |
| 129 | + return traceSessionWait("session_test", result.waitpointId, () => |
| 130 | + usage.pauseAsync(async () => { |
| 131 | + expect(trace.getActiveSpan()).toBeDefined(); |
| 132 | + entered(); |
| 133 | + await completed; |
| 134 | + return result; |
| 135 | + }) |
| 136 | + ); |
| 137 | + }); |
| 138 | + await waiting; |
| 139 | + try { |
| 140 | + const pausedUsage = measurement.sample().cpuTime; |
| 141 | + await tracing.flush(); |
| 142 | + await sleep(10); |
| 143 | + // Usage rounds to milliseconds, so two samples can differ by 1ms. |
| 144 | + expect(Math.abs(measurement.sample().cpuTime - pausedUsage)).toBeLessThanOrEqual(1); |
| 145 | + const partial = wireSpans.find( |
| 146 | + (span) => |
| 147 | + span.name === "wait.forToken()" && |
| 148 | + span.attributes.some((attr) => attr.key === Attr.SPAN_PARTIAL && attr.value.boolValue) |
| 149 | + ); |
| 150 | + expect(partial?.attributes).toEqual( |
| 151 | + expect.arrayContaining([ |
| 152 | + { key: Attr.ENTITY_TYPE, value: { stringValue: "waitpoint" } }, |
| 153 | + { key: Attr.ENTITY_ID, value: { stringValue: "waitpoint_test" } }, |
| 154 | + ]) |
| 155 | + ); |
| 156 | + } finally { |
| 157 | + finish(); |
| 158 | + await pending; |
| 159 | + } |
| 160 | + expect(await pending).toBe(result); |
| 161 | + const sample = usage.stop(measurement); |
| 162 | + expect(sample.wallTime - sample.cpuTime).toBeGreaterThanOrEqual(10); |
| 163 | + const idle = spans.find((span) => span.name === "idle")!; |
| 164 | + const wait = spans.find((span) => span.name === "wait.forToken()")!; |
| 165 | + const parent = spans.find((span) => span.name === "next message")!; |
| 166 | + expect(idle.parentSpanContext?.spanId).toBe(parent.spanContext().spanId); |
| 167 | + expect(wait.parentSpanContext?.spanId).toBe(parent.spanContext().spanId); |
| 168 | + expect(wait.attributes[Attr.ENTITY_ID]).toBe(result.waitpointId); |
| 169 | + expect(wait.status.code).toBe(SpanStatusCode.UNSET); |
| 170 | + }); |
| 171 | + |
| 172 | + it("retains the waitpoint identity and timeout result on a failed wait", async () => { |
| 173 | + const result = { ok: false as const, error: new WaitpointTimeoutError("Timed out") }; |
| 174 | + expect(await traceSessionWait("session_test", "waitpoint_timeout", async () => result)).toBe( |
| 175 | + result |
| 176 | + ); |
| 177 | + expect(spans).toHaveLength(1); |
| 178 | + const span = spans[0]; |
| 179 | + assert(span); |
| 180 | + expect(span.attributes[Attr.ENTITY_ID]).toBe("waitpoint_timeout"); |
| 181 | + expect(span.status.code).toBe(SpanStatusCode.ERROR); |
| 182 | + expect(span.events[0]?.attributes?.["exception.message"]).toBe("Timed out"); |
| 183 | + }); |
| 184 | + |
| 185 | + it.each(["idle", "wait"])( |
| 186 | + "ends the %s span and propagates an aborted operation", |
| 187 | + async (phase) => { |
| 188 | + const error = new Error("Operation aborted"); |
| 189 | + const fail = async (): Promise<never> => { |
| 190 | + throw error; |
| 191 | + }; |
| 192 | + const pending = |
| 193 | + phase === "idle" |
| 194 | + ? traceSessionIdle("session_test", 30, fail) |
| 195 | + : traceSessionWait("session_test", "waitpoint_aborted", fail); |
| 196 | + await expect(pending).rejects.toBe(error); |
| 197 | + expect(spans).toHaveLength(1); |
| 198 | + const span = spans[0]; |
| 199 | + assert(span); |
| 200 | + expect(span.status.code).toBe(SpanStatusCode.ERROR); |
| 201 | + expect(span.endTime[0]).toBeGreaterThan(0); |
| 202 | + } |
| 203 | + ); |
| 204 | +}); |
0 commit comments