diff --git a/packages/chord/CHANGELOG.md b/packages/chord/CHANGELOG.md index d1b3d216e..20b2ac68e 100644 --- a/packages/chord/CHANGELOG.md +++ b/packages/chord/CHANGELOG.md @@ -24,7 +24,7 @@ - Chord v2 gains telemetry across hosts (slice 9): `CHORD_TELEMETRY_SCHEMA` (root export) types every span, event and metric Chord records. With a host adapter (`createHost({ telemetry })`), calls (`chord.call`), methods (`chord.method`, local and remote), relays (`chord.relay`), holds (`chord.hold`), activations (`chord.activate`, ending `live`, `failed`, `parked` or `ended`, with `chord.retry` and `chord.park` events), natives' opens and closes, `load`, `reload` (a `chord.reload.fate` event per object), resolves (a worker start included), revocations, routine calls, job phases (`intent`, `run`, `finish`: a persisted run resumed in a new attempt or process stays under its stored carrier) and HTTP requests (`chord.http`: method, route pattern, status, never the path) are spans; failures carry a fixed category and the message cut at 500 characters, a cancel is no error; commits are `chord.commit { documents, ops, rows, duration }` events of the span they ran under. `hold` and `call` carry the caller's trace carrier (`trace`, at most 8 keys, keys and values of at most 256 characters of printable ASCII, else the message fails the message schema and the link closes; the binary codec's kind byte flag `0x40`), relays forward their own span's, and the provider runs the method under it (an absent or unknown carrier: the adapter's root); a reference's carrier rides on its first hold only, a re-hold after a reconnect being a fresh root linked to it. A hold's `type` and its address's `kind` are bounded at 256 characters by the message schema, and span attributes a peer chose at 256 characters. `ctx.trace(name, attributes, fn)` runs `fn` in a child span with a child ctx. Host-wide metrics: `chord.link.bytes`, `chord.link.state_messages`, `chord.commit.duration`, `chord.calls.in_flight`, `chord.holds.active`, `chord.links.open`, `chord.park.duration`, `chord.backpressure.wait`. Without an adapter nothing is started, built or sent: a call over a link costs what it did before. `createHttp`, `startServer` and `startWorker` take a `telemetry` adapter (`createHttp` continues a W3C `traceparent` only from a request a contributed relay verified: an app's proxy must strip it from browsers). A host with an adapter counts the cost counters of its links' and root scopes' work on it also when the app passed a context without a span. The SQLite telemetry store keeps spans of one microsecond in the order they started. - Chord v2's telemetry closes four gaps found writing the tutorial: `chord.commit` counts the table rows a commit's writes changed (`rows`; a commit writing only rows no longer reads `documents=0 ops=0`); every span Chord starts, `ctx.trace`'s too, carries `chord.host`, the host's address key or `client` without an address (`Host` gains `address`); the SQLite telemetry store keeps span times in whole microseconds from pi-telemetry's `telemetryNow` (store version 2: a recorder migrates a version 1 file in place, its rows kept); and `openTelemetryStore(path)` (new subpath `@earendil-works/chord/telemetry-sqlite/node`) reads a store file read-only, implementing `TelemetryStore` only, refusing a file without a store or with one of another version. `openNodeSqliteDatabase` takes `mode: "read-only"`. -- Chord v2's telemetry is stored in one place, the server (decisions "Telemetry from browser pages", "The server is the one place telemetry is stored", "Who a span was for"). Pages and workers record in memory with Chord's `TelemetryRecorder` (the SQLite store's own recorder too) and send finished spans in batches over their link to the server's `PageTelemetry` and `WorkerTelemetry` (`ingest(batch)`), which the app kit serves when `startServer` has a telemetry store; the store gains `ingest` (never replacing a stored span). `startPage({ telemetry: true })` records the page and sends its spans every 3 s and when hidden; the server checks a page's batch strictly (at most 100 spans, every field bounded, ids printable ASCII, no control characters), keeps only spans under the page's own ids (`browser::`), caps them at 1,200 per page and minute, marks them `chord.host: browser` and stamps them with the principal of their link. A worker sends its spans and metrics every second, stamped with its host. `host.root(fn, ctx, { trace: { name, attributes } })` runs `fn` in a new root span (a click). Method and call spans record whom they were for: `chord.principal` (the principal key) by default, or what the host's new `principalAttributes` hook returns (`createHost`, `startServer`, `startWorker`). `ServeOptions.untraced` serves a type whose calls start no method span. `Host` gains `incarnation` and `principalAttributes`. +- Chord v2's telemetry is stored in one place, the server (decisions "Telemetry from browser pages", "The server is the one place telemetry is stored", "Who a span was for"). Pages and workers record in memory with Chord's `TelemetryRecorder` (the SQLite store's own recorder too) and send finished spans in batches over their link to the server's `PageTelemetry` and `WorkerTelemetry` (`ingest(batch)`), which the app kit serves when `startServer` has a telemetry store; the store gains `ingest` (never replacing a stored span). `startPage({ telemetry: true })` records the page and sends its spans every 3 s and when hidden; the server checks a page's batch strictly (at most 100 spans, every field bounded, ids printable ASCII, no control characters), keeps only spans under the page's own ids (`browser::`), caps them at 1,200 per page and minute, marks them `chord.host: browser` and stamps them with the principal of their link (a page's own `chord.*` attributes are dropped). A worker sends its spans and metrics every second, stamped with its host. `host.root(fn, ctx, { trace: { name, attributes } })` runs `fn` in a new root span (a click). Method and call spans record whom they were for: `chord.principal` (the principal key) by default, or what the host's new `principalAttributes` hook returns (`createHost`, `startServer`, `startWorker`). `ServeOptions.untraced` serves a type whose calls start no method span. `Host` gains `incarnation` and `principalAttributes`. ### Changed diff --git a/packages/chord/docs/design.md b/packages/chord/docs/design.md index a28987f01..29ce38b34 100644 --- a/packages/chord/docs/design.md +++ b/packages/chord/docs/design.md @@ -2837,15 +2837,17 @@ Chord reports traces, events and metrics through `@earendil-works/pi-telemetry`; characters anywhere), a span counts only when its id, trace and parent are under the page's own prefix (`browser::`, so it neither writes into another sender's trace nor poses as a server span), 1,200 spans per page and minute (past it dropped, counted in the answer), each marked `chord.host: browser` and - stamped with the principal attributes of its link, overriding what the page wrote. The store writes ingested spans + stamped with the principal attributes of its link (the hook called per span), the page's own `chord.*` attributes + dropped, so a page never claims a host or a principal. The store writes ingested spans with `INSERT OR IGNORE`: a stored span is never replaced. The ingest objects' calls start no `chord.method` (`ServeOptions.untraced`): a span per batch would be telemetry about telemetry. A trace of a page's own starts with `host.root(fn, ctx, { trace: { name, attributes } })`, a root span of the host's adapter (`trace_failed` on a throw). A viewer clamps a page's spans against the server spans under them (the page's clock may be off). - **Who a span was for:** `chord.method` and `chord.call` record their principal's attributes: by default `chord.principal`, its principal key (capped); a host's `principalAttributes(principal)` hook replaces them (none, - the key, more: a user's name the app resolves). Chord calls it for every span it records with a principal, so it is - synchronous and cheap, its caching its own; the kit passes `startServer`'s and `startWorker`'s to their hosts, and + the key, more: a user's name the app resolves; `{}` records nothing). Chord calls it for every span it records with + a principal and never when nothing records (the NOOP adapter), so it is synchronous and cheap; Chord caches none of + its results, any caching is the hook's own; the kit passes `startServer`'s and `startWorker`'s to their hosts, and the server stamps a page's spans with it for the link's principal. `Host` exposes `principalAttributes`, `incarnation` and `address` for the kit and the page recorder. - **Reading a shared file:** `openTelemetryStore(path)` (`@earendil-works/chord/telemetry-sqlite/node`) implements diff --git a/packages/chord/docs/tutorial/book.md b/packages/chord/docs/tutorial/book.md index 8f86cbd30..b91f8df4d 100644 --- a/packages/chord/docs/tutorial/book.md +++ b/packages/chord/docs/tutorial/book.md @@ -1543,10 +1543,31 @@ with the call under it: `host.root(fn, context, { trace })` runs `fn` in a new root span of the host's adapter, `ctx.telemetry` that span, so the call of `add` starts its `chord.call` under it and puts that span's carrier in the call's header (`useHost` gives a -component its page's host). Without a recording adapter it starts nothing. `screenshots.ts` signs the owner in to the -page in Chromium, types honey and submits, then submits again with nothing typed; it reads the store until the -worker's spans of both clicks are there and prints honey's trace with pi-telemetry's `renderTrace` (ids and lengths of -time masked, which differ at every run): +component its page's host). Without a recording adapter it starts nothing. `screenshots.ts` has the owner signed in +to the real page in Chromium (the app's page from chapter IV, by now in Harbor and French), types honey and submits, +then submits again with nothing typed: + + +```ts + await browser.type("honey"); + await shoot("click-before.png"); + const submit = "document.querySelector('.lists-panel form').requestSubmit()"; + await browser.evaluate(submit); +``` + + +```text +wrote docs/tutorial/screens/click-before.png +wrote docs/tutorial/screens/click-after.png +``` + +:::figure wide | The click, on the real page: honey typed (left), then submitted (right). The list shows honey once the worker's store committed it and its live query reached the page; the page has recorded `page.add` and the `chord.call` under it, and sends them to the server within three seconds. +
The page with honey typedThe page after the click: honey in the list
+::: + +It then reads the store until the worker's spans of both clicks are there and prints honey's trace with pi-telemetry's +`renderTrace` (ids and lengths of time masked, which differ at every run), and opens the owner's trace viewer (the last +section builds it) on the same trace: ```text @@ -1560,6 +1581,10 @@ adding honey from the page: todos.validate chord.host="list|groceries" chars=5 ``` +:::figure wide | The same trace in the owner's trace viewer at `/traces`, in the Harbor theme: the tree `renderTrace` printed above, each span with the host that recorded it (`browser`, `server`, `list|groceries`) and its length as a bar on the trace's time line, all written by the server. Starts are stored to the microsecond, so even bars of a fraction of a millisecond line up. On the left the newest traces: the refused click in red, each with whom it was for; the rest the app's own work (relays, activations, HTTP requests). +![The trace viewer with the click's trace](screens/traces.png) +::: + Three processes recorded these six spans, and the server wrote them all. Each span says which host recorded it: `chord.host` is the host's address key (`server`, `list|groceries`), and `browser` for what a page sent. The page recorded `page.add` and `chord.call`, the consumer's call until its reply. The server recorded `chord.relay`: it @@ -1596,7 +1621,7 @@ ids are `browser::`, and the server takes only spans calling page's own prefix: a page can neither write into another sender's trace nor pose as a server span, and the store never replaces a stored span. A page may send 1,200 spans a minute; past that they are dropped and counted in `ingest`'s answer. The server marks each span `chord.host: browser` and stamps it with the principal of the link it came -over: what a page says about itself counts for nothing. +over, dropping the page's own `chord.*` attributes: what a page says about itself counts for nothing. The trace holds the click and nothing else. Work that serves many requests is its own trace, **linked** to the span that first needed it: a worker's start (`chord.resolve`), an object's activation (`chord.activate`). A link is a reference to @@ -1829,7 +1854,8 @@ styles, which the page's CSP allows only because React sets them through the DOM }; ``` -After the two clicks, `screenshots.ts` opens the viewer on honey's trace, then types `user:u1` into its filter: +After the two clicks, `screenshots.ts` opened the viewer on honey's trace (the figure in "One trace from the browser"), +then types `user:u1` into its filter: ```ts @@ -1846,10 +1872,6 @@ wrote docs/tutorial/screens/traces-ada.png the viewer for user:u1 lists chord.method for ada ``` -:::figure wide | The owner's trace viewer at `/traces`, in the Harbor theme: the newest traces (the refused click marked in red, each with whom it was for; the rest the app's own work: relays, activations, HTTP requests), and honey's trace as a tree across the page (`browser`), the server and the worker (`list|groceries`), all written by the server. Starts are stored to the microsecond, so even bars of a fraction of a millisecond line up. -![The trace viewer](screens/traces.png) -::: - :::figure wide | The traces for Ada (`user:u1`): the coffee `screenshots.ts` adds at its start as her (a root of the server acting as her), recorded by the list's worker; the app's hook named her `ada`. ![The trace viewer filtered by principal](screens/traces-ada.png) ::: diff --git a/packages/chord/docs/tutorial/index.html b/packages/chord/docs/tutorial/index.html index 7b92fdfce..c93633faf 100644 --- a/packages/chord/docs/tutorial/index.html +++ b/packages/chord/docs/tutorial/index.html @@ -1354,10 +1354,21 @@ with the call under it:

void host.root((ctx) => todos.add(text, ctx), context, { trace }).catch(() => {});

host.root(fn, context, { trace }) runs fn in a new root span of the host's adapter, ctx.telemetry that span, so the call of add starts its chord.call under it and puts that span's carrier in the call's header (useHost gives a -component its page's host). Without a recording adapter it starts nothing. screenshots.ts signs the owner in to the -page in Chromium, types honey and submits, then submits again with nothing typed; it reads the store until the -worker's spans of both clicks are there and prints honey's trace with pi-telemetry's renderTrace (ids and lengths of -time masked, which differ at every run):

+component its page's host). Without a recording adapter it starts nothing. screenshots.ts has the owner signed in +to the real page in Chromium (the app's page from chapter IV, by now in Harbor and French), types honey and submits, +then submits again with nothing typed:

+ +
	await browser.type("honey");
+	await shoot("click-before.png");
+	const submit = "document.querySelector('.lists-panel form').requestSubmit()";
+	await browser.evaluate(submit);
+ +
wrote docs/tutorial/screens/click-before.png
+wrote docs/tutorial/screens/click-after.png
+
The page with honey typedThe page after the click: honey in the list
Figure 5. The click, on the real page: honey typed (left), then submitted (right). The list shows honey once the worker's store committed it and its live query reached the page; the page has recorded page.add and the chord.call under it, and sends them to the server within three seconds.
+

It then reads the store until the worker's spans of both clicks are there and prints honey's trace with pi-telemetry's +renderTrace (ids and lengths of time masked, which differ at every run), and opens the owner's trace viewer (the last +section builds it) on the same trace:

adding honey from the page:
    page.add chord.host="browser" chars=5 chord.principal="owner"
@@ -1367,6 +1378,8 @@ time masked, which differ at every run):

            chord.method chord.host="list|groceries" type="todo.store" member="add" object="todo.store" principal.kind="worker" chord.principal="worker:list|groceries" outcome="ok"
              · chord.commit documents=0 ops=0 rows=1 duration=<ms>
              todos.validate chord.host="list|groceries" chars=5
+

The trace viewer with the click's trace

+
Figure 6. The same trace in the owner's trace viewer at /traces, in the Harbor theme: the tree renderTrace printed above, each span with the host that recorded it (browser, server, list|groceries) and its length as a bar on the trace's time line, all written by the server. Starts are stored to the microsecond, so even bars of a fraction of a millisecond line up. On the left the newest traces: the refused click in red, each with whom it was for; the rest the app's own work (relays, activations, HTTP requests).

Three processes recorded these six spans, and the server wrote them all. Each span says which host recorded it: chord.host is the host's address key (server, list|groceries), and browser for what a page sent. The page recorded page.add and chord.call, the consumer's call until its reply. The server recorded chord.relay: it @@ -1376,7 +1389,7 @@ by worker, because the store acts as its host (chapter II). The com under, and the renderer prints a span's events before its children. It counts the documents it changed, their ops and the table rows its writes changed: the store keeps todos in a table, so one row and no documents. chord.principal says whom a span was for (below).

-
pagebrowserserverthe storelist|groceriesworkerpage.add, chord.callcall add, carrier of chord.callchord.relaycall #0, carrier of chord.relaychord.method ×2, todos.validate, commitreplyreplyingest: its spans (every second)ingest: its spans (every 3 s, or hidden)
Figure 5. One click, one trace: each process starts its spans with its own adapter, the carrier in each call's header names the parent span on the other side, and the page and the worker send their spans to the server, which writes them.
+
pagebrowserserverthe storelist|groceriesworkerpage.add, chord.callcall add, carrier of chord.callchord.relaycall #0, carrier of chord.relaychord.method ×2, todos.validate, commitreplyreplyingest: its spans (every second)ingest: its spans (every 3 s, or hidden)
Figure 7. One click, one trace: each process starts its spans with its own adapter, the carrier in each call's header names the parent span on the other side, and the page and the worker send their spans to the server, which writes them.

The carrier is a field of the call and hold headers, at most 8 keys of at most 256 characters each. The receiver reads it with its own adapter; an absent or malformed one gives a new root, never an error. With the NOOP adapter nothing is injected and no span starts: a span site costs one check (§30).

@@ -1387,7 +1400,7 @@ ids are browser:<its host's incarnation>:<n>, and t calling page's own prefix: a page can neither write into another sender's trace nor pose as a server span, and the store never replaces a stored span. A page may send 1,200 spans a minute; past that they are dropped and counted in ingest's answer. The server marks each span chord.host: browser and stamps it with the principal of the link it came -over: what a page says about itself counts for nothing.

+over, dropping the page's own chord.* attributes: what a page says about itself counts for nothing.

The trace holds the click and nothing else. Work that serves many requests is its own trace, linked to the span that first needed it: a worker's start (chord.resolve), an object's activation (chord.activate). A link is a reference to a span of another trace; the renderer prints it and never follows it.

@@ -1570,7 +1583,8 @@ styles, which the page's CSP allows only because React sets them through the left: `${(row.offsetMs / total) * 100}%`, width: `${Math.max((row.durationMs / total) * 100, 0.5)}%`, }; -

After the two clicks, screenshots.ts opens the viewer on honey's trace, then types user:u1 into its filter:

+

After the two clicks, screenshots.ts opened the viewer on honey's trace (the figure in "One trace from the browser"), +then types user:u1 into its filter:

	await browser.open(`${origin}/traces#${encodeURIComponent(trace.traceId)}`);
 	await browser.wait("document.querySelectorAll('.traces-tree li').length === 6");
@@ -1580,10 +1594,8 @@ styles, which the page's CSP allows only because React sets them through the
 the viewer shows page.add: 6 spans on 3 hosts
 wrote docs/tutorial/screens/traces-ada.png
 the viewer for user:u1 lists chord.method for ada
-

The trace viewer

-
Figure 6. The owner's trace viewer at /traces, in the Harbor theme: the newest traces (the refused click marked in red, each with whom it was for; the rest the app's own work: relays, activations, HTTP requests), and honey's trace as a tree across the page (browser), the server and the worker (list|groceries), all written by the server. Starts are stored to the microsecond, so even bars of a fraction of a millisecond line up.

The trace viewer filtered by principal

-
Figure 7. The traces for Ada (user:u1): the coffee screenshots.ts adds at its start as her (a root of the server acting as her), recorded by the list's worker; the app's hook named her ada.
+
Figure 8. The traces for Ada (user:u1): the coffee screenshots.ts adds at its start as her (a root of the server acting as her), recorded by the list's worker; the app's hook named her ada.

The list is mostly the app's own work: each HTTP request, relayed hold and activation is a trace of its own, as the trap above says. A real viewer would filter by name too (findTraces({ name })) or by error (errors: true), both of which the read interface has; this one is about 330 lines of TypeScript in three files and 20 of CSS, on Chord's diff --git a/packages/chord/src/telemetry-ingest/facet.ts b/packages/chord/src/telemetry-ingest/facet.ts index 18e75d485..34d4f0fda 100644 --- a/packages/chord/src/telemetry-ingest/facet.ts +++ b/packages/chord/src/telemetry-ingest/facet.ts @@ -37,14 +37,15 @@ export function telemetryIngestFacet

(options: TelemetryInge host.serve( PageTelemetry, (_params, principal) => { - const stamp = { ...options.principalAttributes(principal), "chord.host": "browser" }; + // Per span, as for every span Chord records with a principal: caching is the hook's own. + const who = () => options.principalAttributes(principal); const budgets = new PageBudgets(); return { variant: "main", members: { ingest: async (batch, ctx) => { const budget = budgets.of(ctx.incarnation, Date.now()); - const accepted = pageSpans(batch, `browser:${ctx.incarnation}:`, stamp, budget); + const accepted = pageSpans(batch, `browser:${ctx.incarnation}:`, who, budget); const written = options.target.ingest({ spans: accepted, metrics: [] }); return { written, dropped: batch.spans.length - written }; }, @@ -101,12 +102,14 @@ class PageBudgets { /** * The spans of a page's `batch` the store takes: its own (ids, trace and parent under `prefix`, so it never writes * into another sender's trace or poses as a server span), ending after they start, within its minute's `budget`; each - * marked with `stamp` (`chord.host: browser`, the link's principal), which no attribute of the page's may override. + * marked `chord.host: browser` and stamped with `who()` (the link's principal's attributes), which no attribute of the + * page's may override: the page's own `chord.*` attributes are dropped (a claimed `chord.principal` too, when the hook + * records none). */ function pageSpans( batch: Static, prefix: string, - stamp: Readonly, + who: () => Readonly, budget: Budget, ): StoredSpan[] { const accepted: StoredSpan[] = []; @@ -118,7 +121,12 @@ function pageSpans( (span.parentId === undefined || span.parentId.startsWith(prefix)); if (!own || span.endedMs < span.startedMs) continue; budget.spans++; - accepted.push({ ...span, attributes: { ...span.attributes, ...stamp } }); + accepted.push({ ...span, attributes: { "chord.host": "browser", ...ownAttributes(span.attributes), ...who() } }); } return accepted; } + +/** A page's attributes without Chord's (`chord.*`): what Chord records about a span, the server stamps itself. */ +function ownAttributes(attributes: SpanAttributes): SpanAttributes { + return Object.fromEntries(Object.entries(attributes).filter(([key]) => !key.startsWith("chord."))); +} diff --git a/packages/chord/test/host/host.test.ts b/packages/chord/test/host/host.test.ts index 6c968aaf5..4a0859b63 100644 --- a/packages/chord/test/host/host.test.ts +++ b/packages/chord/test/host/host.test.ts @@ -1703,18 +1703,68 @@ describe("who a span was for (principalAttributes)", () => { }); }); - it("records the hook's attributes in its place, the hook called per recorded span only", async () => { + it("records the hook's attributes in its place, called once per recorded span", async () => { const hook = vi.fn((principal: { kind: string }) => ({ "chord.principal": principal.kind, "user.name": "Ada" })); const attributes = await host(new InMemoryTelemetryContext(), hook); expect(attributes).toMatchObject({ "chord.principal": "user", "user.name": "Ada" }); expect(hook).toHaveBeenCalledTimes(1); + }); + + it("records nothing of the principal when the hook returns {}", async () => { + const attributes = await host(new InMemoryTelemetryContext(), () => ({})); + expect(Object.keys(attributes).filter((key) => key === "chord.principal" || key === "user.name")).toEqual([]); + expect(attributes).toMatchObject({ "principal.kind": "user" }); + }); + + it("never calls the hook when nothing records (the NOOP adapter)", async () => { + const hook = vi.fn(() => ({ "chord.principal": "x" })); const silent = createHost({ principal: { kind: "user" }, principalAttributes: hook, onError: () => {} }); await silent.load( [{ name: "@test/echo", facet: defineFacet((h) => h.serve(Echo, () => ({ echo: async (text) => text }))) }], context, ); await (await silent.get(Echo, {}, context)).echo("hi", context); - expect(hook).toHaveBeenCalledTimes(1); + expect(hook).not.toHaveBeenCalled(); + }); + + it("records a call span's principal: whom its reference acts for", async () => { + const Greeter = remote("app.greeter", { + version: 1, + params: {}, + hostAddress: () => hostKind("server")(), + variants: { main: { methods: { greet: method(str(), str()) } } }, + }); + const server = createHost<{ kind: string; id?: string }>({ + address: hostKind("server")(), + principal: { kind: "server" }, + onError: () => {}, + }); + await server.load( + [ + { + name: "@test/greeter", + facet: defineFacet((h) => + h.serve(Greeter, () => ({ variant: "main", members: { greet: async (name) => `hi ${name}` } })), + ), + }, + ], + context, + ); + const telemetry = new InMemoryTelemetryContext(); + const client = createHost<{ kind: string; id?: string }>({ + principal: { kind: "user", id: "u1" }, + telemetry, + principalAttributes: (principal) => ({ "chord.principal": `${principal.kind}:${principal.id}` }), + onError: () => {}, + }); + await client.load([], context); + const [a, b] = memoryLinkPair(); + server.accept(a, { principal: { kind: "user", id: "u1" } }, context); + client.connect(b, { principal: { kind: "server" } }, context); + const greeter = await client.get(Greeter, {}, context); + await telemetry.startSpan({ name: "click" }, (span) => greeter.greet("Ada", withTelemetry(span, context))); + const call = telemetry.getSpans().find(({ name }) => name === "chord.call")!; + expect(call.attributes).toMatchObject({ "chord.principal": "user:u1" }); }); }); diff --git a/packages/chord/test/telemetry-ingest/facet.test.ts b/packages/chord/test/telemetry-ingest/facet.test.ts index 60085bdbb..cb18ab9ec 100644 --- a/packages/chord/test/telemetry-ingest/facet.test.ts +++ b/packages/chord/test/telemetry-ingest/facet.test.ts @@ -5,7 +5,7 @@ // gets the worker's `ingest`; the calls record no span of their own. import { InMemoryTelemetryContext, type StoredSpan } from "@earendil-works/pi-telemetry"; -import { describe, expect, it } from "vitest"; +import { describe, expect, it, vi } from "vitest"; import { BACKGROUND_CONTEXT as context } from "../../src/context/index.ts"; import { hostKind } from "../../src/contracts/index.ts"; import { isChordError, type Principal } from "../../src/data/index.ts"; @@ -24,7 +24,14 @@ import { testCodec, transported } from "../support.ts"; const Server = hostKind("server"); /** A server serving the ingest facet (its batches collected), and a client of `principal` linked to it. */ -async function ingesting(principal: Principal, workers: Readonly> = {}) { +async function ingesting( + principal: Principal, + workers: Readonly> = {}, + principalAttributes: (who: Principal) => Readonly> = (who) => ({ + "chord.principal": JSON.stringify(who), + "user.name": "Ada", + }), +) { const batches: TelemetryBatch[] = []; const telemetry = new InMemoryTelemetryContext(); const server = createHost({ address: Server(), principal: { kind: "server" }, telemetry, onError: () => {} }); @@ -36,7 +43,7 @@ async function ingesting(principal: Principal, workers: Readonly workers[JSON.stringify(who)], - principalAttributes: (who) => ({ "chord.principal": JSON.stringify(who), "user.name": "Ada" }), + principalAttributes, }); await server.load([{ name: "chord.telemetry", facet }], context); const client = createHost({ onError: () => {} }); @@ -87,6 +94,21 @@ describe("a page's batches", () => { expect(batches[0]!.metrics).toEqual([]); }); + it("calls the hook once per span it stamps, caching nothing itself", async () => { + const hook = vi.fn(() => ({ "chord.principal": "owner" })); + const { client } = await ingesting({ kind: "owner" }, {}, hook); + await ingest(client, [span(client, 1), span(client, 2)]); + await ingest(client, [span(client, 3)]); + expect(hook).toHaveBeenCalledTimes(3); + }); + + it("never keeps a principal the page claims: with a hook recording none, its spans carry none", async () => { + const { client, batches } = await ingesting({ kind: "owner" }, {}, () => ({})); + const claimed = span(client, 1, { attributes: { "chord.principal": "root", "chord.host": "server", n: 1 } }); + await ingest(client, [claimed]); + expect(batches[0]!.spans[0]!.attributes).toEqual({ n: 1, "chord.host": "browser" }); + }); + it("drops spans posing as another sender's or the server's: ids, traces and parents not under its own prefix", async () => { const { client, batches } = await ingesting({ kind: "owner" }); const server = "0193b2c4-1111-7000-8000-000000000000:7";