testTracesWithoutSetup
Traces with nothing set up: tcm start records a span for each server function call, with its table statements
inside and the job it enqueued linked; tcm traces shows them by definition as named now (a rename since
included), a definition's versions side by side, and a trace as a tree; and OTLP gets them where
OpenTelemetry's variables say, the caller's trace kept.
import { okIn, plainEnv, strip, tcmBin, tempDir, withChildren } from "#codebase/tcmts/cli/test/e2e/harness"; import { hashOf } from "#codebase/tcmts/cli/test/e2e/jobs"; import { BOARD } from "#codebase/tcmts/cli/test/e2e/traces"; import assert from "node:assert/strict"; import { spawn } from "node:child_process"; import fs from "node:fs"; import http from "node:http"; import path from "node:path"; export const testTracesWithoutSetup = () => withChildren(async (keep) => { const dir = tempDir("traces"); const tcm = (...args: string[]) => strip(okIn(dir, ...args)); const waitFor = async (cond: () => boolean | Promise<boolean>, what: string, ms = 20000) => { for ( const end = Date.now() + ms; Date.now() < end; await new Promise((r) => setTimeout(r, 200)) ) if (await cond()) return; throw new Error(`timed out waiting for ${what}`); }; // a collector, as Honeycomb's or OpenTelemetry's is: what it was sent const got: { path?: string; key?: string | string[]; body: { resourceSpans: { scopeSpans: { spans: Record<string, unknown>[] }[] }[] }; }[] = []; const collector = http.createServer((req, res) => { let body = ""; req.setEncoding("utf8").on("data", (c: string) => (body += c)); req.on("end", () => { got.push({ path: req.url, key: req.headers["x-key"], body: JSON.parse(body) }); res.writeHead(200, { "content-type": "application/json" }).end("{}"); }); }); await new Promise<void>((r) => collector.listen(0, "127.0.0.1", r)); try { tcm("init"); tcm("lib", "add", "tcm", "server", "--at", "lib.server"); fs.writeFileSync(path.join(dir, "scratch.ts"), BOARD); tcm("add"); const { port } = collector.address() as { port: number }; const child = keep( spawn(process.execPath, [tcmBin(), "start", "board.main", "--port", "0"], { cwd: dir, env: { ...plainEnv(), OTEL_EXPORTER_OTLP_ENDPOINT: `http://127.0.0.1:${port}`, OTEL_EXPORTER_OTLP_HEADERS: "x-key=secret", }, }), ); let out = ""; child.stdout.setEncoding("utf8").on("data", (d: string) => (out += d)); child.stderr.setEncoding("utf8").on("data", (d: string) => (out += d)); await waitFor( () => /traces\s+kept \(tcm traces\) and sent to http:\/\/127\.0\.0\.1/.test(out), "tcm start", ); const url = /url\s+(http:\/\/\S+)/.exec(out)![1]!; const call = async (name: string, args: unknown[], headers: Record<string, string> = {}) => { const init = { method: "POST", headers: { "content-type": "application/json", ...headers }, body: JSON.stringify(args), }; const at = new URL(`/__tcm/rpc/${hashOf(dir, name)}`, url); try { return await fetch(at, init); } catch (e) { if ((e as { cause?: { code?: string } }).cause?.code !== "ECONNRESET") throw e; return fetch(at, init); } }; // the caller's trace is the call's const caller = { trace: "a".repeat(32), id: "b".repeat(16) }; const added = await call("board.add", ["hello"], { traceparent: `00-${caller.trace}-${caller.id}-01`, }); assert.equal(added.status, 200); assert.match( added.headers.get("traceresponse") ?? "", new RegExp(`^00-${caller.trace}-[0-9a-f]{16}-01$`), ); assert.equal((await call("board.list", [])).status, 200); assert.equal((await call("board.crash", [])).status, 500); // by definition, as named now: calls, errors, and the table statements they made await waitFor(() => /board\.welcome\s+job/.test(tcm("traces")), "the job's span"); const overview = tcm("traces"); assert.match(overview, /board\.add\s+call\s+1\s+0\s/); assert.match(overview, /board\.crash\s+call\s+1\s+1\s/); assert.match(overview, /posts INSERT\s+sql\s+1\s/); // a trace as a tree: the call, its statement inside it, and the job it enqueued (a trace of its own) const tree = tcm("traces", "--trace", caller.trace.slice(0, 8)); // (the call at the root, its statements a step in: the table's first row records its row type too) assert.match(tree, /ms call board\.add\n[\s\S]*?ms sql posts INSERT/); assert.match(tree, /enqueued board\.welcome: trace [0-9a-f]{8}/); assert.match(tcm("traces", "board.crash"), /errors, newest first\n.*Error: kaboom/); // renamed, its spans are shown by its name now tcm("mv", "board.add", "board.post"); assert.match(tcm("traces"), /board\.post\s+call\s+1\s/); // where its code is read, it says how it runs assert.match( tcm("view", "board.post"), /\/\/ runs on the server[^\n]*\n\/\/ traced: 1 call\(s\) in the last day, p50 \S+, p95 \S+\n/, ); assert.match( tcm("view", "board.crash"), /\/\/ traced: 1 call\(s\)[^\n]*, 1 failed; 1 error\(s\) thrown in it\n/, ); // a new version: side by side with the one before it const before = hashOf(dir, "board.list"); fs.writeFileSync( path.join(dir, "scratch.ts"), `// tcm: namespace board import { posts } from "#codebase/board"; export async function list(): Promise<string[]> { return (await posts.find()).map((r) => r.value.text.toUpperCase()); } `, ); tcm("update"); const after = hashOf(dir, "board.list"); assert.notEqual(after, before); await waitFor(async () => (await call("board.list", [])).status === 200, "the new build"); await waitFor(() => /\(now\)/.test(tcm("traces", "board.list")), "the new version's span"); const versions = tcm("traces", "board.list"); // (the new version's calls include those answered 410 before its build was served) assert.match(versions, new RegExp(`${after.slice(0, 8)} \\(now\\)\\s+\\d+\\s`)); assert.match(versions, new RegExp(`${before.slice(0, 8)}\\s+1\\s`)); // OTLP got them: the caller's trace, the definition's hash, the key await waitFor(() => got.some((g) => JSON.stringify(g.body).includes('"board.add"')), "OTLP"); assert.equal(got[0]!.path, "/v1/traces"); assert.equal(got[0]!.key, "secret"); const spans = got.flatMap((g) => g.body.resourceSpans.flatMap((r) => r.scopeSpans.flatMap((s) => s.spans)), ); const add = spans.find((s) => s.name === "board.add")!; assert.equal(add.traceId, caller.trace); assert.equal(add.parentSpanId, caller.id); assert.deepEqual( (add.attributes as { key: string; value: unknown }[]).find((a) => a.key === "tcm.hash")! .value, { stringValue: hashOf(dir, "board.post") }, ); } finally { collector.close(); } })