();
try {
diff --git a/packages/chord/src/host/attempt.ts b/packages/chord/src/host/attempt.ts
index 360b2ee18..95ffd9491 100644
--- a/packages/chord/src/host/attempt.ts
+++ b/packages/chord/src/host/attempt.ts
@@ -505,6 +505,7 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
position: this.#natives.length + 1,
context: this.#context,
telemetry: host.telemetry,
+ host: host.spanHost,
report: (error: HostError) => host.report(error),
};
const native = new NativeHandle(open, close, closeTimeout, owner);
@@ -631,7 +632,12 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
#startActivation(link: TelemetryContext): void {
const { host, served, label } = this.#object;
if (untraced(host.telemetry)) return;
- const attributes = { type: served.contract.name, object: capped(label), attempt: this.#trace.attempt };
+ const attributes = {
+ "chord.host": host.spanHost,
+ type: served.contract.name,
+ object: capped(label),
+ attempt: this.#trace.attempt,
+ };
const activation = new OpenSpan(host.telemetry, "chord.activate", attributes);
if (!untraced(link)) activation.span.addLink({ context: link });
this.#activation = activation;
@@ -878,7 +884,7 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
// caller. The caller stays the reference's (presence, §19).
const acting = served.kind === "remote" ? caller : { principal: host.principal, incarnation: host.incarnation };
// Its span only when something records (§30: nothing else is made per call).
- const span = untraced(parent) ? undefined : this.#methodSpan(parent, method, acting);
+ const span = !served.traced || untraced(parent) ? undefined : this.#methodSpan(parent, method, acting, context);
const ctx = new CallContext(
span === undefined ? callContext : withTelemetry(span.span, callContext),
acting,
@@ -908,13 +914,15 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
}
/** The `chord.method` span of a call of `method` acting as `acting`, under `parent`. */
- #methodSpan(parent: TelemetryContext, method: string, acting: Caller): OpenSpan<"chord.method"> {
- const { served, label } = this.#object;
+ #methodSpan(parent: TelemetryContext, method: string, acting: Caller, context: Context): OpenSpan<"chord.method"> {
+ const { host, served, label } = this.#object;
return new OpenSpan(parent, "chord.method", {
+ "chord.host": host.spanHost,
type: served.contract.name,
member: method,
object: capped(label),
"principal.kind": capped(acting.principal?.kind ?? "none"),
+ ...host.principalAttributes(acting.principal, context),
});
}
diff --git a/packages/chord/src/host/ctx.ts b/packages/chord/src/host/ctx.ts
index f144dab67..49c7b8c6a 100644
--- a/packages/chord/src/host/ctx.ts
+++ b/packages/chord/src/host/ctx.ts
@@ -22,10 +22,10 @@ export interface Ctx extends Context {
*/
get(Type: C, params: ParamsOf, options?: GetOptions): Promise>;
/**
- * Runs `fn` in a child span `name` of this ctx's span (`telemetry`) with `attributes`: `fn` gets a child ctx (the same
- * principal, incarnation, signal and `get`, its references this ctx's), so calls inside are parented under it. A
- * throw marks the span failed (`trace_failed`; a cancel keeps it ok) and is rethrown. Without an adapter that
- * records, `fn` gets this ctx.
+ * Runs `fn` in a child span `name` of this ctx's span (`telemetry`) with its host's `chord.host` and `attributes`:
+ * `fn` gets a child ctx (the same principal, incarnation, signal and `get`, its references this ctx's), so calls
+ * inside are parented under it. A throw marks the span failed (`trace_failed`; a cancel keeps it ok) and is rethrown.
+ * Without an adapter that records, `fn` gets this ctx.
*/
trace(name: string, attributes: SpanAttributes, fn: (ctx: Ctx) => Promise): Promise;
}
@@ -67,6 +67,11 @@ export class CallContext implements Ctx {
return `${this.#context}.Ctx`;
}
+ /** Its host's `chord.host`, for its child spans. */
+ get spanHost(): string {
+ return this.#host.spanHost;
+ }
+
async get(Type: C, params: ParamsOf, options: GetOptions = {}): Promise> {
// A settled scope refuses `released` whatever aborted it; an aborted call creates nothing.
if (this.#references === undefined) throw settled(Type);
@@ -111,8 +116,11 @@ export class CallContext implements Ctx {
}
}
-/** A ctx that makes its child under a span (`ctx.trace`): the same kind of ctx (a job's has `jobId` and `state`). */
-type Traceable = Ctx & { traced(span: TelemetrySpan): Ctx };
+/**
+ * A ctx that makes its child under a span (`ctx.trace`): the same kind of ctx (a job's has `jobId` and `state`), and
+ * its host's `chord.host`.
+ */
+type Traceable = Ctx & { readonly spanHost: string; traced(span: TelemetrySpan): Ctx };
/**
* `ctx.trace` of `ctx`: `fn` in a child span with its child ctx; with nothing recorded, `fn` with `ctx` itself. Either
@@ -127,7 +135,7 @@ function traceUnder(
const parent = ctx.telemetry;
// Plugin code: a synchronous throw becomes the rejection.
if (untraced(parent)) return (async () => fn(ctx))();
- return parent.startSpan({ name, attributes }, async (span) => {
+ return parent.startSpan({ name, attributes: { "chord.host": ctx.spanHost, ...attributes } }, async (span) => {
try {
return await fn(ctx.traced(span));
} catch (error) {
@@ -139,14 +147,19 @@ function traceUnder(
/** A ctx under a child span (`ctx.trace`): its parent's caller, signal and references, `telemetry` the span. */
export class SpanCtx implements Ctx {
- readonly #parent: Ctx;
+ readonly #parent: Traceable;
readonly #context: Context;
- constructor(parent: Ctx, span: TelemetrySpan) {
+ constructor(parent: Traceable, span: TelemetrySpan) {
this.#parent = parent;
this.#context = withTelemetry(span, parent);
}
+ /** Its host's `chord.host`, for its child spans. */
+ get spanHost(): string {
+ return this.#parent.spanHost;
+ }
+
get principal(): Principal | undefined {
return this.#parent.principal;
}
diff --git a/packages/chord/src/host/facet.ts b/packages/chord/src/host/facet.ts
index 4ff384f07..75d2d73ea 100644
--- a/packages/chord/src/host/facet.ts
+++ b/packages/chord/src/host/facet.ts
@@ -38,6 +38,11 @@ export type ServeOptions = {
* default): a reference within that time reuses it, with its documents and dependencies.
*/
readonly linger?: number;
+ /**
+ * Its calls start no `chord.method` span (`true`): Chord's telemetry ingest, whose every call would otherwise record
+ * a span about the telemetry it writes. Traced by default.
+ */
+ readonly untraced?: true;
};
/** What a facet's setup declares with besides the host: its contributions to registries (R21). */
diff --git a/packages/chord/src/host/host.ts b/packages/chord/src/host/host.ts
index 8ba34fb56..fbe69a589 100644
--- a/packages/chord/src/host/host.ts
+++ b/packages/chord/src/host/host.ts
@@ -4,7 +4,12 @@
// (slice 7b: staging, the commit, each object's fate, the report), closing; one batch per host, the backoff map and the
// endings new instances wait for.
-import { NOOP_TELEMETRY_CONTEXT, type TelemetryContext, type TelemetrySpan } from "@earendil-works/pi-telemetry";
+import {
+ NOOP_TELEMETRY_CONTEXT,
+ type SpanAttributes,
+ type TelemetryContext,
+ type TelemetrySpan,
+} from "@earendil-works/pi-telemetry";
import {
awaitWithContext,
BACKGROUND_CONTEXT,
@@ -50,6 +55,7 @@ import {
chordSpans,
countingOnly,
ended,
+ hostAttribute,
parentOf,
untraced,
} from "../telemetry.ts";
@@ -100,6 +106,13 @@ export type HostOptions;
/** Everything that fails in the background; every app handles it. */
readonly onError: (error: HostError) => void;
/** How long a native's close, and an ending object's running calls, are waited for; 30 s by default. */
@@ -129,6 +142,9 @@ export type HostOptions
= (principal: P) => Readonly;
+
/** Where a reported part sits on its object: a routine (`on`, `onLive`) or a native, by kind, from 1 in declaration order. */
export type Position = { readonly kind: "on" | "onLive" | "native"; readonly position: number };
@@ -233,6 +249,15 @@ export type AnyHost = Omit {
+ /** This host's address (`HostOptions.address`); `undefined` on a client. */
+ readonly address: Address | undefined;
+ /** This run of the host, sent in every handshake (R20): a link's peer sees it as its calls' `ctx.incarnation`. */
+ readonly incarnation: string;
+ /**
+ * The attributes this host's spans record for `principal`: its `principalAttributes` hook's, else `chord.principal`,
+ * its principal key; none without a principal.
+ */
+ principalAttributes(principal: P | undefined, context: Context): Readonly;
/**
* Runs every facet's setup and publishes what they declared in one batch (the types and registries served, the
* registries composed once, the contributions); holds that waited for the publication are placed after that batch,
@@ -452,6 +477,9 @@ const NO_CHAIN: readonly string[] = [];
/** The params of a type with empty params, as checked: nothing, and the empty key. */
const EMPTY_PARAMS: CheckedParams = { params: {}, key: "" };
+/** What a span records for no principal. */
+const NO_ATTRIBUTES: Readonly = Object.freeze({});
+
/** The host: its served types, its objects by identity, its batch, backoff and endings. */
export class ChordHost implements Host
{
readonly batch: Batch;
@@ -466,12 +494,15 @@ export class ChordHost
| undefined;
+ readonly #principalAttributes: PrincipalAttributes
| undefined;
readonly #revocationKeys: RevocationKeys;
/** The presence list of each type someone asked about (`references`), by type name. */
readonly #references = new Map();
@@ -523,8 +554,10 @@ export class ChordHost {
+ return chordSpans(parent)("chord.load", { "chord.host": this.spanHost, plugins: facets.length }, async (span) => {
try {
const report = await this.#load(facets, withTelemetry(span, context));
span.setAttributes({ failed: report.failed.length });
@@ -649,20 +682,24 @@ export class ChordHost
{
const parent = context.telemetry;
if (untraced(parent)) return this.#reloadSteps(facets, before, context);
- return chordSpans(parent)("chord.reload", { plugins: facets.length }, async (span) => {
- try {
- const report = await this.#reloadSteps(facets, before, withTelemetry(span, context));
- for (const { object, kind } of report.objects)
- span.addEvent("chord.reload.fate", { object: capped(object), fate: kind });
- const { added, changed, removed } = report.plugins;
- const counts = { added: added.length, changed: changed.length, removed: removed.length };
- span.setAttributes({ ...counts, failed: report.failed.length, fates: report.objects.length });
- return report;
- } catch (error) {
- ended(span, "reload_failed", error, context.abortSignal);
- throw error;
- }
- });
+ return chordSpans(parent)(
+ "chord.reload",
+ { "chord.host": this.spanHost, plugins: facets.length },
+ async (span) => {
+ try {
+ const report = await this.#reloadSteps(facets, before, withTelemetry(span, context));
+ for (const { object, kind } of report.objects)
+ span.addEvent("chord.reload.fate", { object: capped(object), fate: kind });
+ const { added, changed, removed } = report.plugins;
+ const counts = { added: added.length, changed: changed.length, removed: removed.length };
+ span.setAttributes({ ...counts, failed: report.failed.length, fates: report.objects.length });
+ return report;
+ } catch (error) {
+ ended(span, "reload_failed", error, context.abortSignal);
+ throw error;
+ }
+ },
+ );
}
/** One reload's steps: staging, the commit, the fates, the report. */
@@ -989,7 +1026,10 @@ export class ChordHost
span.setAttributes({ count }));
+ if (!untraced(parent)) {
+ const attributes = { "chord.host": this.spanHost };
+ void chordSpans(parent)("chord.revoke", attributes, (span) => span.setAttributes({ count }));
+ }
}
/** `revoke`'s work; how many objects it ended and child links it closed. */
@@ -1085,7 +1125,25 @@ export class ChordHost
Promise, principal, this.#counted(context));
+ const run = fn as (ctx: Ctx) => Promise;
+ const trace = options.trace;
+ if (trace === undefined || untraced(this.telemetry))
+ return this.#roots.run(run, principal, this.#counted(context));
+ const attributes = { "chord.host": this.spanHost, ...trace.attributes };
+ return this.telemetry.startSpan({ name: trace.name, attributes }, async (span) => {
+ try {
+ return await this.#roots.run(run, principal, withTelemetry(span, context));
+ } catch (error) {
+ ended(span, "trace_failed", error, context.abortSignal);
+ throw error;
+ }
+ });
+ }
+
+ principalAttributes(principal: P | undefined, context: Context): Readonly {
+ if (principal === undefined) return NO_ATTRIBUTES;
+ if (this.#principalAttributes !== undefined) return this.#principalAttributes(principal);
+ return { "chord.principal": capped(principalKey(principal, context, this.#principalKey)) };
}
/**
diff --git a/packages/chord/src/host/index.ts b/packages/chord/src/host/index.ts
index 20f401729..f067b1537 100644
--- a/packages/chord/src/host/index.ts
+++ b/packages/chord/src/host/index.ts
@@ -17,6 +17,7 @@ export {
type LoadReport,
type PluginFailure,
type Position,
+ type PrincipalAttributes,
type ReloadedObject,
type ReloadOptions,
type ReloadReport,
diff --git a/packages/chord/src/host/native.ts b/packages/chord/src/host/native.ts
index afb9f51d5..3f071a48c 100644
--- a/packages/chord/src/host/native.ts
+++ b/packages/chord/src/host/native.ts
@@ -36,6 +36,8 @@ type NativeOwner = {
readonly position: number;
readonly context: Context;
readonly telemetry: TelemetryContext;
+ /** Its host's `chord.host`. */
+ readonly host: string;
readonly report: (error: HostError) => void;
};
@@ -94,8 +96,8 @@ export class NativeHandle implements Native, NativeSlot {
await this.#opened(await this.#open(context));
return;
}
- const { type, position } = this.#owner;
- await chordSpans(parent)("chord.open", { type, native: position }, async (span) => {
+ const { host, type, position } = this.#owner;
+ await chordSpans(parent)("chord.open", { "chord.host": host, type, native: position }, async (span) => {
let value: T;
try {
value = await this.#open(withTelemetry(span, context));
@@ -132,9 +134,10 @@ export class NativeHandle implements Native, NativeSlot {
* for it up to then; longer is reported.
*/
async #closeValue(value: T, reason: NativeCloseReason): Promise {
- const { telemetry, type, position } = this.#owner;
+ const { telemetry, host, type, position } = this.#owner;
if (untraced(telemetry)) return this.#closeWithin(value, reason, this.#owner.context);
- return chordSpans(telemetry)("chord.close", { type, native: position, reason: reason.kind }, async (span) => {
+ const attributes = { "chord.host": host, type, native: position, reason: reason.kind };
+ return chordSpans(telemetry)("chord.close", attributes, async (span) => {
const failure = await this.#closeWithin(value, reason, withTelemetry(span, this.#owner.context));
if (failure !== undefined) spanFailed(span, "close_failed", failure.error);
return failure;
diff --git a/packages/chord/src/host/object.ts b/packages/chord/src/host/object.ts
index be6b91f2a..59e78131d 100644
--- a/packages/chord/src/host/object.ts
+++ b/packages/chord/src/host/object.ts
@@ -65,6 +65,8 @@ type ServedType = {
readonly provider: Provider;
/** How long a live object stays live after its last reference, in milliseconds (`serve`'s `linger`, 0 by default). */
readonly linger: number;
+ /** Whether its calls start method spans (`serve`'s `untraced`: not). */
+ readonly traced: boolean;
};
/** What holds an object: a reference's binding, or a hold arriving over a link. */
diff --git a/packages/chord/src/host/root.ts b/packages/chord/src/host/root.ts
index 633804f9c..d09efe80a 100644
--- a/packages/chord/src/host/root.ts
+++ b/packages/chord/src/host/root.ts
@@ -2,6 +2,7 @@
// (a Durable tool, a CLI), sealed when `fn` settles, when `context` aborts and when the host closes: its signal aborted,
// its `ctx.get` refused `released`, every reference it took released.
+import type { SpanAttributes } from "@earendil-works/pi-telemetry";
import { awaitWithContext, type Context, withAbortSignal, withoutAbortSignal } from "../context/index.ts";
import { ChordError, type Principal } from "../data/index.ts";
import { CallContext, type Ctx } from "./ctx.ts";
@@ -14,6 +15,12 @@ export type RootOptions = {
* explicit `undefined` anonymous (`ctx.principal` undefined).
*/
readonly principal?: P | undefined;
+ /**
+ * Runs `fn` in a new root span of this host's adapter (a click, a command: a trace of its own), `ctx.telemetry` that
+ * span, with its host's `chord.host` and `attributes`; a throw marks it failed (`trace_failed`, a cancel keeps it
+ * ok). Without an adapter that records, nothing is started.
+ */
+ readonly trace?: { readonly name: string; readonly attributes?: SpanAttributes };
};
/** An open root scope: its seal, and how its caller is rejected when the host closes. */
diff --git a/packages/chord/src/host/route.ts b/packages/chord/src/host/route.ts
index f4c98c38e..1076286f1 100644
--- a/packages/chord/src/host/route.ts
+++ b/packages/chord/src/host/route.ts
@@ -202,7 +202,11 @@ export class Route {
const adapter = this.#host.telemetry;
const span = untraced(adapter)
? undefined
- : new OpenSpan(adapter, "chord.resolve", { kind: this.kind, address: capped(key) });
+ : new OpenSpan(adapter, "chord.resolve", {
+ "chord.host": this.#host.spanHost,
+ kind: this.kind,
+ address: capped(key),
+ });
if (span !== undefined && trigger !== undefined) {
span.span.addLink({ context: trigger });
trigger.addLink({ context: span.span });
diff --git a/packages/chord/src/host/routines.ts b/packages/chord/src/host/routines.ts
index 2ccc350af..46fa16c9d 100644
--- a/packages/chord/src/host/routines.ts
+++ b/packages/chord/src/host/routines.ts
@@ -186,6 +186,7 @@ function call(
const span = untraced(host.telemetry)
? undefined
: new OpenSpan(host.telemetry, "chord.routine", {
+ "chord.host": host.spanHost,
type: owner.type,
object: capped(owner.label),
routine: at.kind,
diff --git a/packages/chord/src/host/staging.ts b/packages/chord/src/host/staging.ts
index f085e394d..563f424cc 100644
--- a/packages/chord/src/host/staging.ts
+++ b/packages/chord/src/host/staging.ts
@@ -150,7 +150,7 @@ function stageEntry(
throw new Error(`${contract.name}: a host without an address serves only local types`);
}
const provider = bindProvider(contract, options.accepts ?? {});
- const common = { plugin, provider, linger: options.linger ?? 0 };
+ const common = { plugin, provider, linger: options.linger ?? 0, traced: options.untraced !== true };
// The contract's kind decides the factory's signature and the contract's shape.
const served: Served =
contract.kind === "local"
diff --git a/packages/chord/src/jobs/job.ts b/packages/chord/src/jobs/job.ts
index 49e72e2a3..c0ab9f0c8 100644
--- a/packages/chord/src/jobs/job.ts
+++ b/packages/chord/src/jobs/job.ts
@@ -152,7 +152,12 @@ export class Job implements JobHandle
const parent = context.telemetry;
if (untraced(parent)) return documents.tx((tx) => this.stage(tx, args, context, options), token, context);
// The intent: the start's transaction, in its span (the run keeps it: its later phases are its children).
- const attributes = { job: this.#definition.name, phase: "intent", object: capped(documents.label) } as const;
+ const attributes = {
+ "chord.host": this.#owner.host.spanHost,
+ job: this.#definition.name,
+ phase: "intent",
+ object: capped(documents.label),
+ } as const;
return chordSpans(parent)("chord.job", attributes, async (span) => {
const traced = withTelemetry(span, context);
try {
@@ -328,6 +333,7 @@ export class Job implements JobHandle
const parent = parentOf(run.trace, host.telemetry);
if (untraced(parent)) return undefined;
return new OpenSpan(parent, "chord.job", {
+ "chord.host": host.spanHost,
job: this.#definition.name,
phase,
object: capped(documents.label),
@@ -533,7 +539,12 @@ class JobSpanContext extends SpanCtx {
readonly jobId: string;
declare readonly state: RunState | undefined;
- constructor(parent: Ctx, span: TelemetrySpan, jobId: string, state: RunState | undefined) {
+ constructor(
+ parent: JobContext | JobSpanContext,
+ span: TelemetrySpan,
+ jobId: string,
+ state: RunState | undefined,
+ ) {
super(parent, span);
this.jobId = jobId;
if (state !== undefined) this.state = state;
diff --git a/packages/chord/src/node/app/app.ts b/packages/chord/src/node/app/app.ts
index 8348c666d..79852d5c2 100644
--- a/packages/chord/src/node/app/app.ts
+++ b/packages/chord/src/node/app/app.ts
@@ -10,11 +10,19 @@ import { type Context, withAbortSignal } from "../../context/index.ts";
import { type Address, type HostKind, hostKind, type KindShape } from "../../contracts/index.ts";
import type { Principal } from "../../data/index.ts";
import { canonicalJson } from "../../data/principal.ts";
-import { createHost, type Facet, type Host, type HostError, type PluginFacet } from "../../host/index.ts";
+import {
+ createHost,
+ type Facet,
+ type Host,
+ type HostError,
+ type PluginFacet,
+ type PrincipalAttributes,
+} from "../../host/index.ts";
import type { JsonValue } from "../../json.ts";
import { openNodeSqliteDatabase } from "../../sqlite/node.ts";
import { openStore, type Store, sqliteBackend } from "../../store/index.ts";
import { localeChoiceFacet, themeChoiceFacet, themesFacet, translationsFacet } from "../../surfaces/index.ts";
+import { type TelemetryIngestTarget, telemetryIngestFacet } from "../../telemetry-ingest/index.ts";
import type { Watchable } from "../../watch.ts";
import { createHttp, type HttpComponent, type HttpError, type ListenAddress } from "../http/index.ts";
import {
@@ -115,10 +123,17 @@ export type AppOptions = {
/** The terminal surface (slice 11): the app's terminal entry; the `tui` facet kind. None: no terminal clients. */
readonly tui?: { readonly entry: string };
/**
- * The server's telemetry adapter (§29): its host's spans and metrics and its HTTP requests'; NOOP by default. Each
- * worker exports to the adapter its own `startWorker` is given; carriers join their spans into one trace.
+ * The app's telemetry store (§29; decision "The server is the one place telemetry is stored"): the server's host,
+ * its HTTP requests and the kit's ingest record to it (`createSqliteTelemetry`'s store). With one, every worker
+ * records in memory and sends its spans and metrics to the server's `WorkerTelemetry`, and pages that record
+ * (`startPage({ telemetry: true })`) theirs to `PageTelemetry`; carriers join them into one trace. None: NOOP.
*/
- readonly telemetry?: TelemetryContext;
+ readonly telemetry?: TelemetryContext & TelemetryIngestTarget;
+ /**
+ * Who a span was for (`createHost`'s `principalAttributes`): the server's hook, also stamped on the spans pages
+ * send (the principal of their link). Each worker's is its `startWorker`'s.
+ */
+ readonly principalAttributes?: PrincipalAttributes
;
readonly onError: (error: AppError) => void;
} & (OwnerPrincipal extends P ? unknown : { readonly "the app's principal type must have { kind: 'owner' }": never });
@@ -191,6 +206,8 @@ export type KitStart = {
readonly principal: JsonValue;
readonly server: JsonValue;
readonly files: { readonly maxFile?: number; readonly maxTotal?: number };
+ /** Whether the server has a telemetry store: the worker then sends what it records to `WorkerTelemetry`. */
+ readonly telemetry: boolean;
/** The cap of uploads under way per `Files` object (`limits.uploads`). */
readonly uploads?: number;
};
@@ -206,12 +223,13 @@ export async function startServer
(options: AppOptions
, c
);
const { onError, api, limits = {} } = options;
const sessions = createSessions
(cookieSecret, { maxEphemeral: limits.ephemeralSessions });
- const { telemetry } = options;
+ const { telemetry, principalAttributes } = options;
const host = createHost
({
address: Server(),
principal: options.principal.server,
store,
telemetry,
+ ...(principalAttributes === undefined ? {} : { principalAttributes }),
onError: (error) => onError({ kind: "host", error }),
});
const http = createHttp(
@@ -241,8 +259,10 @@ export async function startServer
(options: AppOptions
, c
context,
);
const workers = new Map>();
+ // The address key of each worker by its principal's key: the principal its link stamps on its telemetry batches.
+ const workerHosts = new Map();
for (const kind of options.workers ?? []) {
- workers.set(kind.kind.kind, workersOf(host, kind, options, layout.dataDir, plugins, context));
+ workers.set(kind.kind.kind, workersOf(host, kind, options, layout.dataDir, plugins, workerHosts, context));
}
const link = new OwnerLink();
const core: PluginFacet[] = [
@@ -265,6 +285,14 @@ export async function startServer
(options: AppOptions
, c
{ name: "chord.translations", facet: translationsFacet() },
{ name: "chord.locale.choice", facet: localeChoiceFacet() },
];
+ if (telemetry !== undefined) {
+ const facet = telemetryIngestFacet
({
+ target: telemetry,
+ workerHost: (principal) => workerHosts.get(canonicalJson(principal as unknown as JsonValue, context)),
+ principalAttributes: (principal) => host.principalAttributes(principal, context),
+ });
+ core.push({ name: "chord.telemetry", facet });
+ }
const surfaces: Surface
[] = [];
const app = new RunningApp(host, http, workers, plugins, surfaces, { store, lock }, layout, options);
try {
@@ -353,6 +381,7 @@ function workersOf
(
options: AppOptions
,
dataDir: string,
plugins: Plugins,
+ workerHosts: Map,
context: Context,
): Workers {
const facet = kind.facet ?? "worker";
@@ -371,13 +400,16 @@ function workersOf(
authorize: (principal, address) => isServer(principal) || kind.authorize(principal, address),
principal: options.principal.worker,
start: async (address, ctx) => {
+ // Principals are JSON (they cross links).
+ const principal = options.principal.worker(address) as unknown as JsonValue;
+ workerHosts.set(canonicalJson(principal, ctx), address.key);
const kit: KitStart = {
dir: workerDirectory(dataDir, address),
facet,
- // Principals are JSON (they cross links).
- principal: options.principal.worker(address) as unknown as JsonValue,
+ principal,
server: options.principal.server as unknown as JsonValue,
files: { ...options.files },
+ telemetry: options.telemetry !== undefined,
...(options.limits?.uploads === undefined ? {} : { uploads: options.limits.uploads }),
};
return { kit, app: await kind.start(address, ctx) };
diff --git a/packages/chord/src/node/app/worker.ts b/packages/chord/src/node/app/worker.ts
index ae5239d9f..94f5b3fe7 100644
--- a/packages/chord/src/node/app/worker.ts
+++ b/packages/chord/src/node/app/worker.ts
@@ -1,16 +1,19 @@
// `startWorker` (slice 13 §1): a worker of an app built with the kit, in its entry module. `workerMain` plus the kit's
// part: the worker's directory under its kind and address with its store, the host at the worker's address acting as
// the principal the server gave it, connected to the server first, its plugins loaded with the kit's worker facets
-// (`WorkerInfo`, `Files`, `Translations` for a worker that renders final text).
+// (`WorkerInfo`, `Files`, `Translations` for a worker that renders final text); when the server has a telemetry store,
+// the host records in memory and sends its spans and metrics to the server every second (decision "The server is the
+// one place telemetry is stored").
import { join } from "node:path";
-import type { TelemetryContext } from "@earendil-works/pi-telemetry";
+import { setTimeout as sleep } from "node:timers/promises";
import type { Principal } from "../../data/index.ts";
-import { createHost } from "../../host/index.ts";
+import { createHost, type PrincipalAttributes } from "../../host/index.ts";
import type { JsonValue } from "../../json.ts";
import { openNodeSqliteDatabase } from "../../sqlite/node.ts";
import { openStore, sqliteBackend } from "../../store/index.ts";
import { translationsFacet } from "../../surfaces/index.ts";
+import { sendWorkerTelemetry, TelemetryRecorder } from "../../telemetry-ingest/index.ts";
import type { Watchable } from "../../watch.ts";
import { workerMain } from "../workers/index.ts";
import type { AppApi, AppKind, KitStart } from "./app.ts";
@@ -20,23 +23,25 @@ import { workerInfoFacet } from "./info.ts";
import { privateDirectory, privateStore } from "./layout.ts";
/** What `startWorker` takes: the app's API and kinds as the server's `startServer` has them, this process's modules. */
-export type WorkerOptions = {
+export type WorkerOptions
= {
readonly api: AppApi;
readonly kinds: Readonly>;
/** Extra keep-alive counts of the app (a record of numbers, all zero when idle). */
readonly busy?: Watchable>>;
- /**
- * This worker's telemetry adapter (§29): its host's spans and metrics; NOOP by default. Its methods called through
- * the server continue the caller's trace by the carriers on the wire; where the spans are stored is the app's (a
- * SQLite telemetry store per process, or one file the processes share).
- */
- readonly telemetry?: TelemetryContext;
+ /** Who a span was for (`createHost`'s `principalAttributes`): this worker's hook, as the server's is its own. */
+ readonly principalAttributes?: PrincipalAttributes;
/** The worker host's errors (`HostError`) and a failed start's. */
readonly onError: (error: unknown) => void;
};
+/** How many finished spans a worker keeps while it cannot send (past it new ones are dropped). */
+const WORKER_QUEUE = 10_000;
+
+/** How often a worker sends what it recorded. */
+const WORKER_SEND_MS = 1000;
+
/** Runs this process as a worker of the app: once the start message arrived, its host is up and its plugins loaded. */
-export function startWorker
(options: WorkerOptions): void {
+export function startWorker
(options: WorkerOptions
): void {
// The worker's facet kind comes with the start message: every kind's packages are offered, its own are imported.
const packages = Object.assign({}, ...Object.values(options.kinds).map((kind) => kind.packages ?? {}));
workerMain(
@@ -50,12 +55,16 @@ export function startWorker
(options: WorkerOptions): void {
context,
);
onClose((ctx) => store.close(ctx));
+ const scope = crypto.randomUUID();
+ const recorder = kit.telemetry ? new TelemetryRecorder(() => scope, WORKER_QUEUE) : undefined;
+ const { principalAttributes } = options;
// Principals are the app's: the server made these with its `principal` options.
const host = createHost
({
address,
principal: kit.principal as unknown as P,
store,
- telemetry: options.telemetry,
+ telemetry: recorder,
+ ...(principalAttributes === undefined ? {} : { principalAttributes }),
onError: options.onError,
});
onClose((ctx) => host.close(ctx));
@@ -75,6 +84,18 @@ export function startWorker
(options: WorkerOptions): void {
{ name: "chord.translations", facet: translationsFacet
() },
];
await plugins.load(host, { kind: kit.facet, core }, context);
+ if (recorder !== undefined) {
+ const sender = sendWorkerTelemetry(host, recorder, context);
+ const timer = setInterval(() => void sender.send(false), WORKER_SEND_MS);
+ timer.unref();
+ // Held after the load (a host holds nothing before). Closers run in reverse: this one before the host
+ // closes, the last spans and partial metrics sent while the link is up, for at most a second.
+ onClose(async () => {
+ clearInterval(timer);
+ await Promise.race([sender.send(true), sleep(WORKER_SEND_MS, undefined, { ref: false })]);
+ sender.stop();
+ });
+ }
return options.busy === undefined ? {} : { busy: options.busy };
},
{
diff --git a/packages/chord/src/node/http/http.ts b/packages/chord/src/node/http/http.ts
index 09066e293..8b217de88 100644
--- a/packages/chord/src/node/http/http.ts
+++ b/packages/chord/src/node/http/http.ts
@@ -21,7 +21,7 @@ import { local } from "../../contracts/index.ts";
import { isChordError, type Principal } from "../../data/index.ts";
import { type Ctx, defineFacet, type Facet, type Host } from "../../host/index.ts";
import type { RegistryValue } from "../../registries/index.ts";
-import { OpenSpan, parentOf, spanFailed, untraced } from "../../telemetry.ts";
+import { hostAttribute, OpenSpan, parentOf, spanFailed, untraced } from "../../telemetry.ts";
import {
type Admitted,
admit,
@@ -137,6 +137,8 @@ class Component
implements HttpComponent
, Handler {
readonly upgrade: (message: IncomingMessage, socket: Duplex, head: Buffer) => void;
readonly #host: Host
;
readonly #options: HttpOptions;
+ /** The `chord.host` of its `chord.http` spans: its host's. */
+ readonly #spanHost: string;
readonly #onError: (error: HttpError) => void;
readonly #context: Context;
/** The component's context without its cancellation: each request's scope adds its own signal. */
@@ -156,6 +158,7 @@ class Component
implements HttpComponent
, Handler {
constructor(host: Host
, options: HttpOptions, context: Context) {
this.#host = host;
this.#options = options;
+ this.#spanHost = hostAttribute(host.address);
this.#onError = options.onError;
this.#context = context;
this.#base = withoutAbortSignal(context);
@@ -311,12 +314,12 @@ class Component
implements HttpComponent
, Handler {
#span(request: Incoming, match: RouteMatch, admission: Admitted): OpenSpan<"chord.http"> | undefined {
const adapter = this.#options.telemetry;
if (adapter === undefined || untraced(adapter)) return undefined;
+ const attributes = { "chord.host": this.#spanHost, method: request.method, route: match.pattern };
const traceparent = admission.provenance.kind === "relayed" ? traceHeader(request, "traceparent") : undefined;
- if (traceparent === undefined)
- return new OpenSpan(adapter, "chord.http", { method: request.method, route: match.pattern });
+ if (traceparent === undefined) return new OpenSpan(adapter, "chord.http", attributes);
const tracestate = traceHeader(request, "tracestate");
const carrier: TelemetryCarrier = tracestate === undefined ? { traceparent } : { traceparent, tracestate };
- return new OpenSpan(parentOf(carrier, adapter), "chord.http", { method: request.method, route: match.pattern });
+ return new OpenSpan(parentOf(carrier, adapter), "chord.http", attributes);
}
/** Runs the wraps and the route in the request's scope `ctx`, and makes its answer (a failure: a reported 500). */
diff --git a/packages/chord/src/remote/relay.ts b/packages/chord/src/remote/relay.ts
index 038cf86bc..6da71db21 100644
--- a/packages/chord/src/remote/relay.ts
+++ b/packages/chord/src/remote/relay.ts
@@ -110,10 +110,18 @@ export class RelayedHold {
return carrier;
}
- /** A relay span's attributes: names from the wire, bounded by the message schema (untrusted links) and capped here. */
- #attributes(member: string): { type: string; member: string; "upstream.kind": string } {
+ /**
+ * A relay span's attributes: its host's `chord.host` (the downstream link's host), and names from the wire, bounded
+ * by the message schema (untrusted links) and capped here.
+ */
+ #attributes(member: string): { "chord.host": string; type: string; member: string; "upstream.kind": string } {
const { type, address } = this.#request;
- return { type: capped(type), member, "upstream.kind": capped(address.kind) };
+ return {
+ "chord.host": this.#downstream.link.host.spanHost,
+ type: capped(type),
+ member,
+ "upstream.kind": capped(address.kind),
+ };
}
/** The upstream link dropped: downstream its calls fail and the hold goes loading until the path's next link. */
diff --git a/packages/chord/src/remote/remote-object.ts b/packages/chord/src/remote/remote-object.ts
index 4fb300a89..b5ffb8a24 100644
--- a/packages/chord/src/remote/remote-object.ts
+++ b/packages/chord/src/remote/remote-object.ts
@@ -108,6 +108,7 @@ export class RemoteObject implements Target {
// Its first hold carries the carrier of its `chord.hold` span, under its holder's span (`#holdTrace`).
if (!untraced(holder)) {
this.#holding = new OpenSpan(holder, "chord.hold", {
+ "chord.host": host.spanHost,
type,
object: capped(this.label),
"address.kind": address.kind,
@@ -183,6 +184,7 @@ export class RemoteObject implements Target {
// A hold that dropped before it was bound ends here.
this.#held("ended");
const attributes = {
+ "chord.host": this.#host.spanHost,
type: this.contract.name,
object: capped(this.label),
"address.kind": this.request.address.kind,
@@ -225,10 +227,12 @@ export class RemoteObject implements Target {
const parent = context.telemetry;
if (untraced(parent)) return hold.side.call(hold.id, index, data, args, context);
const attributes = {
+ "chord.host": this.#host.spanHost,
type: this.contract.name,
member: method,
object: capped(this.label),
"address.kind": this.request.address.kind,
+ ...this.#host.principalAttributes(this.caller.principal, context),
};
return chordSpans(parent)("chord.call", attributes, async (span) => {
try {
diff --git a/packages/chord/src/sqlite/node.ts b/packages/chord/src/sqlite/node.ts
index 269249027..94e3eed77 100644
--- a/packages/chord/src/sqlite/node.ts
+++ b/packages/chord/src/sqlite/node.ts
@@ -6,12 +6,20 @@ import type { SqliteDatabase, SqliteExecutor, SqliteValue } from "./database.ts"
/** Node SQLite connection settings for a database file. */
export type NodeSqliteDatabaseOptions = {
+ /**
+ * `read-only` opens an existing file for reads (another process may write it): no directory is made, nothing is
+ * configured or checkpointed, and transactions are deferred (`BEGIN`), reading one snapshot. `read-write` by default.
+ */
+ readonly mode?: NodeSqliteMode;
/** SQLite WAL auto-checkpoint threshold. SQLite and this adapter default to 1,000 pages; 0 disables it. */
readonly walAutoCheckpointPages?: number;
/** Time SQLite waits for a competing file lock. SQLite defaults to 0; this adapter defaults to 5,000 ms. */
readonly busyTimeoutMs?: number;
};
+/** How a connection opens its file. */
+export type NodeSqliteMode = "read-write" | "read-only";
+
const DEFAULT_WAL_AUTO_CHECKPOINT_PAGES = 1_000;
const DEFAULT_BUSY_TIMEOUT_MS = 5_000;
@@ -148,15 +156,18 @@ class NodeSqliteTransaction extends NodeSqliteExecutor {
/** `SqliteDatabase` adapter backed by Node's built-in `node:sqlite`. */
export class NodeSqliteDatabase extends NodeSqliteExecutor implements SqliteDatabase {
private readonly access = new SerialOperationQueue();
+ private readonly mode: NodeSqliteMode;
private closed = false;
- constructor(database: DatabaseSync) {
+ constructor(database: DatabaseSync, mode: NodeSqliteMode = "read-write") {
super(database, new Map());
+ this.mode = mode;
}
transaction(callback: (transaction: SqliteExecutor) => Promise): Promise {
return this.access.runAsync(async () => {
- this.database.exec("BEGIN IMMEDIATE");
+ // A writer takes the write lock at once; a read-only connection cannot, and reads one snapshot.
+ this.database.exec(this.mode === "read-only" ? "BEGIN" : "BEGIN IMMEDIATE");
const scope = { active: true };
try {
const result = await callback(new NodeSqliteTransaction(this.database, this.statements, scope));
@@ -181,7 +192,7 @@ export class NodeSqliteDatabase extends NodeSqliteExecutor implements SqliteData
this.closed = true;
this.statements.clear();
try {
- this.database.exec("PRAGMA wal_checkpoint(TRUNCATE)");
+ if (this.mode === "read-write") this.database.exec("PRAGMA wal_checkpoint(TRUNCATE)");
} finally {
this.database.close();
}
@@ -200,6 +211,8 @@ export async function openNodeSqliteDatabase(
): Promise {
const checkpointPages = options.walAutoCheckpointPages ?? DEFAULT_WAL_AUTO_CHECKPOINT_PAGES;
const timeout = options.busyTimeoutMs ?? DEFAULT_BUSY_TIMEOUT_MS;
+ if (options.mode === "read-only")
+ return new NodeSqliteDatabase(new DatabaseSync(path, { timeout, readOnly: true }), "read-only");
if (path !== ":memory:") await mkdir(dirname(path), { recursive: true });
const database = new DatabaseSync(path, { timeout });
const adapter = new NodeSqliteDatabase(database);
diff --git a/packages/chord/src/store/step.ts b/packages/chord/src/store/step.ts
index 30bd604f7..51fab53a0 100644
--- a/packages/chord/src/store/step.ts
+++ b/packages/chord/src/store/step.ts
@@ -26,8 +26,8 @@ export type StagedWrite = {
/**
* One commit step: its backend transaction, its seq, the store's id allocator (D3: ids are taken from it as the
* writes apply, never copied), the ids of the documents it created, the table records it changed (the store's catalog
- * takes them after `COMMIT`) and the statements it ran (`chord.store.statements`). Its reads are the step reader of
- * adapters: they see the step's own writes.
+ * takes them after `COMMIT`), the statements it ran (`chord.store.statements`) and the table rows its writes changed
+ * (`chord.commit`'s `rows`). Its reads are the step reader of adapters: they see the step's own writes.
*/
export class Step {
readonly executor: SqliteExecutor;
@@ -39,6 +39,8 @@ export class Step {
readonly tables = new Map();
readonly #catalog: ReadonlyMap;
statements = 0;
+ /** Table rows its writes changed: a `put` one, the others the count their statement returned. */
+ rows = 0;
constructor(executor: SqliteExecutor, seq: number, ids: IdAllocator, catalog: ReadonlyMap) {
this.executor = executor;
diff --git a/packages/chord/src/store/store.ts b/packages/chord/src/store/store.ts
index 0325d61dd..8350d0dcf 100644
--- a/packages/chord/src/store/store.ts
+++ b/packages/chord/src/store/store.ts
@@ -84,8 +84,11 @@ async function switchOutbox(db: SqliteDatabase, meta: MetaRow, outbox: boolean |
export type CommitFence = {
/** At the step's entry: `false` rejects the commit `released` and writes nothing. */
admit(): boolean;
- /** After `COMMIT`: adopts the commit, `ids` being its created documents' ids in the order of their writes. */
- adopt(seq: number, ids: readonly number[]): void;
+ /**
+ * After `COMMIT`: adopts the commit, `ids` being its created documents' ids in the order of their writes, `rows` the
+ * table rows its writes changed.
+ */
+ adopt(seq: number, ids: readonly number[], rows: number): void;
};
/**
@@ -421,7 +424,7 @@ export class ChordStore implements Store {
if (writes.length === 0) {
// An empty commit takes no seq; a throwing `adopt` stops the store as for any commit.
try {
- fence.adopt(this.#lastSeq, []);
+ fence.adopt(this.#lastSeq, [], 0);
} catch (error) {
throw this.#fail(error);
}
@@ -458,7 +461,7 @@ export class ChordStore implements Store {
metrics.counter("chord.store.commits").add(1);
metrics.counter("chord.store.statements").add(step.statements);
try {
- fence.adopt(seq, step.created);
+ fence.adopt(seq, step.created, step.rows);
} catch (error) {
throw this.#fail(error);
}
diff --git a/packages/chord/src/store/table-writes.ts b/packages/chord/src/store/table-writes.ts
index b517b166b..6540754ef 100644
--- a/packages/chord/src/store/table-writes.ts
+++ b/packages/chord/src/store/table-writes.ts
@@ -117,6 +117,7 @@ export function stagePut(sql: string, table: string, row: EncodedRow, version: n
order: "write",
apply: async (step) => {
await step.run(sql, ...row.params);
+ step.rows++;
return [write];
},
};
@@ -167,7 +168,11 @@ export function stageDeleteWhere(statement: Statement, table: string, where: Whe
function counted(statement: Statement, record: (count: number) => TableWrite): StagedWrite {
return {
order: "write",
- apply: async (step) => [record(await step.runCounted(statement.sql, ...statement.params))],
+ apply: async (step) => {
+ const count = await step.runCounted(statement.sql, ...statement.params);
+ step.rows += count;
+ return [record(count)];
+ },
};
}
diff --git a/packages/chord/src/surfaces/client.ts b/packages/chord/src/surfaces/client.ts
index 279999c7d..39c089b82 100644
--- a/packages/chord/src/surfaces/client.ts
+++ b/packages/chord/src/surfaces/client.ts
@@ -5,6 +5,7 @@
// client's code is outdated, which the app answers by starting over (a page reloads). The surface specifics (how a
// socket opens, how a script is fetched, what is outdated) are given.
+import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import { BACKGROUND_CONTEXT, type Context, withAbortSignal } from "../context/index.ts";
import type { Principal } from "../data/index.ts";
import { createHost, type Host, type HostError, type PluginFacet, type PluginFailure } from "../host/index.ts";
@@ -52,6 +53,11 @@ export type ClientOptions = {
/** A new set was applied (its scripts loaded or kept old): the page swaps the plugins' stylesheets. */
readonly applied?: (set: ScriptSet) => void;
readonly environment: LoopEnvironment;
+ /**
+ * Makes the host's telemetry adapter (none: NOOP); `incarnation` names the host's run (it is read at the adapter's
+ * first span, after the host was made).
+ */
+ readonly telemetry?: (incarnation: () => string) => TelemetryContext;
readonly onError: (error: ClientError) => void;
};
@@ -61,7 +67,11 @@ export type Client
= { readonly host: Host
; stop(context
/** Starts a client: its host loaded with the initial scripts, its link kept, its plugins kept current. */
export async function startClient
(options: ClientOptions
): Promise> {
const context = BACKGROUND_CONTEXT;
- const host = createHost({ onError: (error) => options.onError({ kind: "host", error }) });
+ let made: Host
| undefined;
+ // Read at the first span, which starts once the host exists (in its load at the earliest).
+ const telemetry = options.telemetry?.(() => made!.incarnation);
+ const host = createHost
({ telemetry, onError: (error) => options.onError({ kind: "host", error }) });
+ made = host;
const entries = options.initial.map((script) => entryOf(script, options.modules));
const { loaded, report } = await LoadedFacets.load(host, options.core, entries, context);
if (report.failed.length > 0) options.onError({ kind: "plugins", failed: report.failed });
diff --git a/packages/chord/src/telemetry-ingest/batch.ts b/packages/chord/src/telemetry-ingest/batch.ts
new file mode 100644
index 000000000..74de25f0e
--- /dev/null
+++ b/packages/chord/src/telemetry-ingest/batch.ts
@@ -0,0 +1,136 @@
+// What pages and workers send the server's telemetry objects (decisions "Telemetry from browser pages", "The server is
+// the one place telemetry is stored"): a batch of finished spans (a worker's with its metric aggregates), its schemas
+// (a page's strict: every field bounded, ids printable ASCII, no control characters; a worker's, the server's own
+// child, generous), and the two remote objects on the server that take them, `PageTelemetry` and `WorkerTelemetry`.
+
+import type { AttributeValue, StoredMetric, StoredSpan } from "@earendil-works/pi-telemetry";
+import { arr, hostKind, int, lit, method, num, obj, opt, remote, type Schema, str, union } from "../contracts/index.ts";
+
+/** At most this many spans in a page's batch. */
+export const PAGE_BATCH_SPANS = 100;
+
+/** At most this many spans and metric rows in a worker's batch. */
+export const WORKER_BATCH_ROWS = 1000;
+
+/** An id: printable ASCII, no spaces (a page's are `browser::`). */
+function id(max: number): Schema {
+ return str({ min: 1, max, pattern: "^[\\x21-\\x7e]+$" });
+}
+
+/** Text: no control characters (C0, DEL, C1), at most `max` characters. */
+function text(max: number, min = 0): Schema {
+ return str({ min, max, pattern: "^[^\\u0000-\\u001f\\u007f-\\u009f]*$" });
+}
+
+/** A record of attributes: at most `count` keys of 1 to 64 characters of text (other keys refused), values of `value`. */
+function attributes(count: number, value: Schema): Schema> {
+ return {
+ type: "object",
+ maxProperties: count,
+ patternProperties: { "^[^\\u0000-\\u001f\\u007f-\\u009f]{1,64}$": value },
+ additionalProperties: false,
+ };
+}
+
+/** A finished span as `span`'s fields allow: ids, a name, times, attributes, events, links and a status. */
+function spanSchema(limits: SpanLimits): Schema {
+ const record = attributes(limits.attributes, limits.value);
+ const span = obj({
+ id: id(limits.id),
+ traceId: id(limits.id),
+ parentId: opt(id(limits.id)),
+ name: text(limits.name, 1),
+ startedMs: num({ min: 0 }),
+ endedMs: num({ min: 0 }),
+ attributes: record,
+ events: arr(obj({ name: text(limits.name, 1), timeMs: num({ min: 0 }), attributes: record }), {
+ max: limits.events,
+ }),
+ links: arr(obj({ traceId: id(limits.id), spanId: id(limits.id), attributes: opt(record) }), {
+ max: limits.links,
+ }),
+ status: union([
+ obj({ status: lit("ok") }),
+ obj({ status: lit("error"), error: opt(obj({ name: text(64), message: text(500) })) }),
+ ]),
+ });
+ // The object schema's static type is StoredSpan's shape: the same fields, optional ones `opt`.
+ return span as unknown as Schema;
+}
+
+/** The bounds of one span's fields. */
+type SpanLimits = {
+ readonly id: number;
+ readonly name: number;
+ readonly attributes: number;
+ readonly value: Schema;
+ readonly events: number;
+ readonly links: number;
+};
+
+/** A page's spans: what a recorded click needs, little more (decision "Telemetry from browser pages"). */
+const PAGE_SPAN = spanSchema({
+ id: 128,
+ name: 128,
+ attributes: 32,
+ value: union([text(256), num(), { type: "boolean" } as Schema]),
+ events: 16,
+ links: 8,
+});
+
+/** A worker's spans: bounded generously (its spans are Chord's and its plugins'). */
+const WORKER_SPAN = spanSchema({
+ id: 256,
+ name: 1024,
+ attributes: 256,
+ value: union([str({ max: 65_536 }), num(), { type: "boolean" } as Schema, arr(union([str(), num()]))]),
+ events: 1024,
+ links: 256,
+});
+
+/** A worker's metric row: one series' aggregate of one 10 s interval. */
+const METRIC = obj({
+ intervalMs: int({ min: 0 }),
+ name: text(256, 1),
+ kind: union([lit("counter"), lit("upDownCounter"), lit("histogram")]),
+ unit: opt(text(64)),
+ attributes: attributes(64, union([str({ max: 4096 }), num(), { type: "boolean" } as Schema])),
+ count: int({ min: 0 }),
+ sum: num(),
+ min: num(),
+ max: num(),
+}) as unknown as Schema;
+
+/** What `ingest` answers: the spans the store queued and the ones it dropped (refused, over the rate, over its bound). */
+const RECEIPT = obj({ written: int(), dropped: int() });
+
+/** A page's batch (spans only: a page sends no metrics). */
+export const PageBatch = obj({ spans: arr(PAGE_SPAN, { max: PAGE_BATCH_SPANS }) });
+
+/** A worker's batch: its spans and its metric rows. */
+export const WorkerBatch = obj({
+ spans: arr(WORKER_SPAN, { max: WORKER_BATCH_ROWS }),
+ metrics: arr(METRIC, { max: WORKER_BATCH_ROWS }),
+});
+
+/** The server's host kind as the app kit names it. */
+const Server = hostKind("server");
+
+/** The server's telemetry object for pages: any principal's page sends its batches to it, untrusted. */
+export const PageTelemetry = remote("chord.telemetry.page", {
+ version: 1,
+ params: {},
+ hostAddress: () => Server(),
+ variants: { main: { methods: { ingest: method(PageBatch, RECEIPT) } } },
+});
+
+/**
+ * The server's telemetry object for workers: `worker` for a worker's principal (its batches written as they are),
+ * `other` for everyone else (nothing to call).
+ */
+export const WorkerTelemetry = remote("chord.telemetry.worker", {
+ version: 1,
+ params: {},
+ hostAddress: () => Server(),
+ variants: { worker: { methods: { ingest: method(WorkerBatch, RECEIPT) } }, other: {} },
+});
diff --git a/packages/chord/src/telemetry-ingest/facet.ts b/packages/chord/src/telemetry-ingest/facet.ts
new file mode 100644
index 000000000..18e75d485
--- /dev/null
+++ b/packages/chord/src/telemetry-ingest/facet.ts
@@ -0,0 +1,124 @@
+// The server's telemetry ingest (decisions "Telemetry from browser pages", "The server is the one place telemetry is
+// stored", "Who a span was for"): a facet serving `PageTelemetry` and `WorkerTelemetry`, whose `ingest(batch)` writes
+// what pages and workers recorded to the server's store. A page is untrusted: its spans must carry its own ids
+// (`browser::...`), are capped per page and minute, marked `chord.host: browser` and stamped with the
+// principal of the link they came over; a worker's are written as they are, stamped with its host.
+
+import type { SpanAttributes, StoredSpan } from "@earendil-works/pi-telemetry";
+import type { Static } from "../contracts/index.ts";
+import type { Principal } from "../data/index.ts";
+import { defineFacet, type Facet } from "../host/index.ts";
+import { type PageBatch, PageTelemetry, WorkerTelemetry } from "./batch.ts";
+import type { TelemetryBatch } from "./recorder.ts";
+
+/** Where ingested batches go: the server's store (`SqliteTelemetry`), which queues them; how many spans it queued. */
+export type TelemetryIngestTarget = { ingest(batch: TelemetryBatch): number };
+
+/** What the ingest facet takes. */
+export type TelemetryIngestOptions = {
+ readonly target: TelemetryIngestTarget;
+ /** The address key of the worker whose link stamps `principal`; `undefined` for any other principal. */
+ readonly workerHost: (principal: P) => string | undefined;
+ /** The attributes a page's spans record for the principal of their link (the server host's `principalAttributes`). */
+ readonly principalAttributes: (principal: P) => Readonly;
+};
+
+/** How many spans one page may send per minute; past it they are dropped (and counted in its receipts). */
+export const PAGE_SPANS_PER_MINUTE = 1200;
+
+/** How many pages' minute counts one principal's object keeps (the earliest goes first). */
+const PAGES = 1000;
+
+const MINUTE_MS = 60_000;
+
+/** The ingest facet: `PageTelemetry` and `WorkerTelemetry` on the server, writing to `options.target`. */
+export function telemetryIngestFacet(options: TelemetryIngestOptions
): Facet
{
+ return defineFacet
((host) => {
+ host.serve(
+ PageTelemetry,
+ (_params, principal) => {
+ const stamp = { ...options.principalAttributes(principal), "chord.host": "browser" };
+ 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 written = options.target.ingest({ spans: accepted, metrics: [] });
+ return { written, dropped: batch.spans.length - written };
+ },
+ },
+ };
+ },
+ // A span per batch would be telemetry about telemetry, written back with the next batch.
+ { untraced: true },
+ );
+ host.serve(
+ WorkerTelemetry,
+ (_params, principal) => {
+ const worker = options.workerHost(principal);
+ if (worker === undefined) return { variant: "other", members: {} };
+ return {
+ variant: "worker",
+ members: {
+ ingest: async ({ spans, metrics }, _ctx) => {
+ const stamped = spans.map((span) => ({
+ ...span,
+ attributes: { ...span.attributes, "chord.host": worker },
+ }));
+ const written = options.target.ingest({ spans: stamped, metrics });
+ return { written, dropped: spans.length - written };
+ },
+ },
+ };
+ },
+ { untraced: true },
+ );
+ });
+}
+
+/** One page's spans of the current minute. */
+type Budget = { readonly start: number; spans: number };
+
+/** The minute budgets of one principal's pages, by incarnation, bounded (the earliest page goes first). */
+class PageBudgets {
+ readonly #budgets = new Map();
+
+ /** The budget of the page `incarnation` at `now`: a new minute starts a new one. */
+ of(incarnation: string, now: number): Budget {
+ let budget = this.#budgets.get(incarnation);
+ if (budget === undefined || now - budget.start >= MINUTE_MS) {
+ this.#budgets.delete(incarnation);
+ if (this.#budgets.size >= PAGES) this.#budgets.delete(this.#budgets.keys().next().value!);
+ budget = { start: now, spans: 0 };
+ this.#budgets.set(incarnation, budget);
+ }
+ return budget;
+ }
+}
+
+/**
+ * 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.
+ */
+function pageSpans(
+ batch: Static,
+ prefix: string,
+ stamp: Readonly,
+ budget: Budget,
+): StoredSpan[] {
+ const accepted: StoredSpan[] = [];
+ for (const span of batch.spans) {
+ if (budget.spans >= PAGE_SPANS_PER_MINUTE) break;
+ const own =
+ span.id.startsWith(prefix) &&
+ span.traceId.startsWith(prefix) &&
+ (span.parentId === undefined || span.parentId.startsWith(prefix));
+ if (!own || span.endedMs < span.startedMs) continue;
+ budget.spans++;
+ accepted.push({ ...span, attributes: { ...span.attributes, ...stamp } });
+ }
+ return accepted;
+}
diff --git a/packages/chord/src/telemetry-ingest/index.ts b/packages/chord/src/telemetry-ingest/index.ts
new file mode 100644
index 000000000..6342b6ab9
--- /dev/null
+++ b/packages/chord/src/telemetry-ingest/index.ts
@@ -0,0 +1,20 @@
+// Telemetry from pages and workers to the server's store (decisions "Telemetry from browser pages", "The server is
+// the one place telemetry is stored"): the recorder pages and workers keep their spans in, the batches and the
+// server's objects that take them, the facet serving those, and the senders.
+
+export {
+ PAGE_BATCH_SPANS,
+ PageBatch,
+ PageTelemetry,
+ WORKER_BATCH_ROWS,
+ WorkerBatch,
+ WorkerTelemetry,
+} from "./batch.ts";
+export {
+ PAGE_SPANS_PER_MINUTE,
+ type TelemetryIngestOptions,
+ type TelemetryIngestTarget,
+ telemetryIngestFacet,
+} from "./facet.ts";
+export { type TelemetryBatch, TelemetryRecorder } from "./recorder.ts";
+export { sendPageTelemetry, sendWorkerTelemetry, type TelemetrySender } from "./sender.ts";
diff --git a/packages/chord/src/telemetry-ingest/recorder.ts b/packages/chord/src/telemetry-ingest/recorder.ts
new file mode 100644
index 000000000..4425b55cd
--- /dev/null
+++ b/packages/chord/src/telemetry-ingest/recorder.ts
@@ -0,0 +1,348 @@
+// Chord's telemetry recorder (§29): an adapter keeping settled spans and metric aggregates (per series per 10 s) in a
+// bounded queue (past it dropped and counted), until its owner takes them as a batch: the SQLite store writes its
+// batches to its file, a page or a worker sends them to the server's telemetry object (`TelemetryIngest`). Its
+// carriers name a span by id and trace id; every recorder of a process reads every other's (one carrier format).
+
+import {
+ type InstrumentOptions,
+ NOOP_TELEMETRY_CONTEXT,
+ type SpanAttributes,
+ type SpanLink,
+ type SpanOptions,
+ type SpanStatus,
+ type StoredMetric,
+ type StoredSpan,
+ type TelemetryCarrier,
+ type TelemetryContext,
+ type TelemetryMetrics,
+ type TelemetryPropagation,
+ type TelemetrySpan,
+ telemetryNow,
+} from "@earendil-works/pi-telemetry";
+
+/** What a recorder hands its owner at once: settled spans and metric aggregates. */
+export type TelemetryBatch = { readonly spans: StoredSpan[]; readonly metrics: StoredMetric[] };
+
+/** A span's identity in carriers and links: its id and its trace's. */
+type Identity = { readonly id: string; readonly traceId: string };
+
+type Metric = StoredMetric & { readonly key: string };
+
+/** The identities of every recorder's spans and extracted parents in this process: links and carriers read them. */
+const identities = new WeakMap();
+
+/** The carrier's keys: a span's id and its trace's (the SQLite store's since slice 9: stored job carriers use them). */
+const SPAN_KEY = "pi-sqlite-span";
+const TRACE_KEY = "pi-sqlite-trace";
+
+/** The metric interval. */
+export const INTERVAL_MS = 10_000;
+
+/**
+ * Records spans and metrics in memory for its owner, who takes them in batches (`take`, then `release` once they are
+ * written or given up). Span ids are `:`, `scope` read at the first span (a page's names its host's
+ * incarnation, made after the recorder). `capacity` bounds the queued spans, a taken batch's included, and separately
+ * the pending metric series.
+ */
+export class TelemetryRecorder implements TelemetryContext, TelemetryPropagation {
+ readonly propagation: TelemetryPropagation = this;
+ readonly metrics: TelemetryMetrics = {
+ counter: (name, options) => ({ add: this.#measurement("counter", name, options) }),
+ upDownCounter: (name, options) => ({ add: this.#measurement("upDownCounter", name, options) }),
+ histogram: (name, options) => ({ record: this.#measurement("histogram", name, options) }),
+ };
+ droppedSpans = 0;
+ droppedMeasurements = 0;
+ readonly #scope: () => string;
+ #prefix: string | undefined;
+ readonly #capacity: number;
+ #sequence = 0;
+ #spans: StoredSpan[] = [];
+ #inFlight = 0;
+ readonly #measurements = new Map();
+ #inFlightMeasurements = 0;
+ #stopped = false;
+
+ constructor(scope: () => string, capacity: number) {
+ this.#scope = scope;
+ this.#capacity = capacity;
+ }
+
+ /** Whether it stopped: later spans are inert, later measurements ignored. */
+ get stopped(): boolean {
+ return this.#stopped;
+ }
+
+ startSpan(options: SpanOptions, callback: (span: TelemetrySpan) => T | Promise): Promise {
+ return this.#start(undefined, options, callback);
+ }
+
+ inject(context: TelemetryContext): TelemetryCarrier | undefined {
+ const identity = identities.get(context);
+ return identity ? { [SPAN_KEY]: identity.id, [TRACE_KEY]: identity.traceId } : undefined;
+ }
+
+ extract(carrier: TelemetryCarrier | undefined): TelemetryContext {
+ const id = carrier?.[SPAN_KEY];
+ const traceId = carrier?.[TRACE_KEY];
+ // Carriers come from other processes: only their two strings are read, else the root.
+ if (typeof id !== "string" || typeof traceId !== "string") return this;
+ const identity = { id, traceId };
+ const parent: TelemetryContext = {
+ metrics: this.metrics,
+ propagation: this,
+ startSpan: (options, callback) => this.#start(identity, options, callback),
+ };
+ identities.set(parent, identity);
+ return parent;
+ }
+
+ /**
+ * Takes the queued spans (at most `limit`, the oldest) and the metric intervals that are over (every one with
+ * `partial`); the spans keep counting against the capacity until `release`.
+ */
+ take(partial: boolean, limit = Number.POSITIVE_INFINITY): TelemetryBatch {
+ const spans = this.#spans.length <= limit ? this.#spans : this.#spans.slice(0, limit);
+ this.#spans = spans === this.#spans ? [] : this.#spans.slice(limit);
+ this.#inFlight = spans.length;
+ const metrics: StoredMetric[] = [];
+ const current = intervalOf(Date.now());
+ for (const [key, { key: _series, ...metric }] of this.#measurements) {
+ if (!partial && metric.intervalMs >= current) continue;
+ metrics.push(metric);
+ this.#measurements.delete(key);
+ }
+ this.#inFlightMeasurements = metrics.length;
+ return { spans, metrics };
+ }
+
+ /** The batch taken last was written or given up: its capacity is free again. */
+ release(): void {
+ this.#inFlight = 0;
+ this.#inFlightMeasurements = 0;
+ }
+
+ /** How many settled spans wait to be taken. */
+ get queuedSpans(): number {
+ return this.#spans.length;
+ }
+
+ /** Whether spans, or metric intervals that are over (all of them with `partial`), wait to be taken. */
+ pending(partial: boolean): boolean {
+ if (this.#spans.length > 0) return true;
+ const current = intervalOf(Date.now());
+ for (const metric of this.#measurements.values()) if (partial || metric.intervalMs < current) return true;
+ return false;
+ }
+
+ /**
+ * Queues spans and metric rows another process recorded (an ingest), within the capacity; returns how many spans
+ * it queued (the rest dropped and counted).
+ */
+ ingest(batch: TelemetryBatch): number {
+ if (this.#stopped) return 0;
+ let queued = 0;
+ for (const span of batch.spans) {
+ if (this.#spans.length + this.#inFlight >= this.#capacity) this.droppedSpans++;
+ else {
+ this.#spans.push(span);
+ queued++;
+ }
+ }
+ for (const metric of batch.metrics) this.#merge(metric);
+ return queued;
+ }
+
+ /** Stops recording; with `discard`, what waits is dropped too (a failed store). */
+ stop(discard: "keep" | "discard"): void {
+ this.#stopped = true;
+ if (discard === "discard") {
+ this.#spans = [];
+ this.#measurements.clear();
+ }
+ }
+
+ #inert(options: SpanOptions, callback: (span: TelemetrySpan) => T | Promise): Promise {
+ return NOOP_TELEMETRY_CONTEXT.startSpan(options, (noop) =>
+ callback({
+ ...noop,
+ metrics: this.metrics,
+ propagation: this,
+ startSpan: (options, callback) => this.#inert(options, callback),
+ }),
+ );
+ }
+
+ async #start(
+ parent: Identity | undefined,
+ options: SpanOptions,
+ callback: (span: TelemetrySpan) => T | Promise,
+ ): Promise {
+ if (this.#stopped) return this.#inert(options, callback);
+ let attributes = copyAttributes(options.attributes);
+ const links: { traceId: string; spanId: string; attributes: SpanAttributes }[] = [];
+ for (const link of options.links ?? []) {
+ const copied = copyLink(link);
+ if (copied) links.push(copied);
+ }
+ this.#prefix ??= this.#scope();
+ const id = `${this.#prefix}:${++this.#sequence}`;
+ const identity = { id, traceId: parent?.traceId ?? id };
+ // The start on the clock pi-telemetry's adapters share; the end and events by the monotonic clock from it.
+ const started = telemetryNow();
+ const clock = performance.now();
+ const events: { name: string; timeMs: number; attributes: SpanAttributes }[] = [];
+ let status: SpanStatus = { status: "ok" };
+ let explicit = false;
+ let settled = false;
+ const record = (action: () => void): void => {
+ if (!settled && !this.#stopped) action();
+ };
+ const span: TelemetrySpan = {
+ metrics: this.metrics,
+ propagation: this,
+ startSpan: (options, callback) =>
+ settled ? this.#inert(options, callback) : this.#start(identity, options, callback),
+ addLink: (link) =>
+ record(() => {
+ const copied = copyLink(link);
+ if (copied) links.push(copied);
+ }),
+ addEvent: (name, attrs) =>
+ record(() => {
+ events.push({
+ name,
+ timeMs: microseconds(performance.now() - clock),
+ attributes: copyAttributes(attrs),
+ });
+ }),
+ setAttributes: (attrs) =>
+ record(() => {
+ attributes = { ...attributes, ...copyAttributes(attrs) };
+ }),
+ setStatus: (value) =>
+ record(() => {
+ status =
+ value.status === "error" && value.error
+ ? { status: "error", error: { ...value.error } }
+ : { status: value.status };
+ explicit = true;
+ }),
+ };
+ identities.set(span, identity);
+ try {
+ return await callback(span);
+ } catch (error) {
+ if (!explicit)
+ status =
+ error instanceof Error
+ ? { status: "error", error: { name: error.name, message: error.message } }
+ : { status: "error" };
+ throw error;
+ } finally {
+ settled = true;
+ if (!this.#stopped) {
+ if (this.#spans.length + this.#inFlight >= this.#capacity) this.droppedSpans++;
+ else
+ this.#spans.push({
+ id,
+ traceId: identity.traceId,
+ ...(parent === undefined ? {} : { parentId: parent.id }),
+ name: options.name,
+ startedMs: started,
+ endedMs: microseconds(started + performance.now() - clock),
+ attributes,
+ events,
+ links,
+ status,
+ });
+ }
+ }
+ }
+
+ #measurement(
+ kind: StoredMetric["kind"],
+ name: string,
+ options?: InstrumentOptions,
+ ): (value: number, attributes?: SpanAttributes) => void {
+ const unit = options?.unit;
+ return (value, attributes) => {
+ if (this.#stopped) return;
+ this.#merge({
+ intervalMs: intervalOf(Date.now()),
+ name,
+ kind,
+ ...(unit === undefined ? {} : { unit }),
+ attributes: sortedAttributes(copyAttributes(attributes)),
+ count: 1,
+ sum: value,
+ min: value,
+ max: value,
+ });
+ };
+ }
+
+ /** Adds `metric` to its series' pending interval (a new series within the capacity, else dropped and counted). */
+ #merge(metric: StoredMetric): void {
+ if (this.#stopped) return;
+ const key = seriesKey(metric);
+ const pendingKey = `${metric.intervalMs}:${key}`;
+ const previous = this.#measurements.get(pendingKey);
+ if (!previous && this.#measurements.size + this.#inFlightMeasurements >= this.#capacity) {
+ this.droppedMeasurements++;
+ return;
+ }
+ this.#measurements.set(pendingKey, {
+ ...metric,
+ key,
+ count: (previous?.count ?? 0) + metric.count,
+ sum: (previous?.sum ?? 0) + metric.sum,
+ min: Math.min(previous?.min ?? metric.min, metric.min),
+ max: Math.max(previous?.max ?? metric.max, metric.max),
+ });
+ }
+}
+
+/** A metric's series: its name, kind, unit and attributes (sorted by key), as JSON. */
+export function seriesKey(metric: StoredMetric): string {
+ return JSON.stringify([
+ metric.name,
+ metric.kind,
+ metric.unit ?? null,
+ JSON.stringify(sortedAttributes(metric.attributes)),
+ ]);
+}
+
+/** The start of the metric interval `time` falls in. */
+function intervalOf(time: number): number {
+ return Math.floor(time / INTERVAL_MS) * INTERVAL_MS;
+}
+
+/** `attributes` with their keys in order (a series' attributes as stored). */
+export function sortedAttributes(attributes: SpanAttributes): SpanAttributes {
+ return Object.fromEntries(
+ Object.keys(attributes)
+ .sort()
+ .map((key) => [key, attributes[key]]),
+ );
+}
+
+/** `ms` rounded to the microsecond, as span times are. */
+function microseconds(ms: number): number {
+ return Math.round(ms * 1000) / 1000;
+}
+
+function copyAttributes(attributes?: SpanAttributes): SpanAttributes {
+ return Object.fromEntries(
+ Object.entries(attributes ?? {})
+ .filter(([, value]) => value !== undefined)
+ .map(([key, value]) => [key, Array.isArray(value) ? [...value] : value]),
+ );
+}
+
+function copyLink(link: SpanLink): { traceId: string; spanId: string; attributes: SpanAttributes } | undefined {
+ const identity = identities.get(link.context);
+ return identity
+ ? { traceId: identity.traceId, spanId: identity.id, attributes: copyAttributes(link.attributes) }
+ : undefined;
+}
diff --git a/packages/chord/src/telemetry-ingest/sender.ts b/packages/chord/src/telemetry-ingest/sender.ts
new file mode 100644
index 000000000..244eca388
--- /dev/null
+++ b/packages/chord/src/telemetry-ingest/sender.ts
@@ -0,0 +1,101 @@
+// How a page and a worker send what their recorder kept (decisions "Telemetry from browser pages", "The server is the
+// one place telemetry is stored"): their host holds the server's telemetry object over the link it has, and each send
+// takes one batch from the recorder and calls `ingest` with it; a batch that cannot be sent (no link, a refusal) is
+// given up, best effort. One send at a time; nothing is sent while the object is not bound.
+
+import { BACKGROUND_CONTEXT, type Context } from "../context/index.ts";
+import type { Principal } from "../data/index.ts";
+import type { Host } from "../host/index.ts";
+import { PAGE_BATCH_SPANS, PageTelemetry, WORKER_BATCH_ROWS, WorkerTelemetry } from "./batch.ts";
+import type { TelemetryBatch, TelemetryRecorder } from "./recorder.ts";
+
+/** A running sender: `send` sends one batch now (with `partial`, the metric intervals not over too), `stop` stops. */
+export type TelemetrySender = {
+ send(partial: boolean): Promise;
+ stop(): void;
+};
+
+/** Sends a page's spans (never its metrics) to the server's `PageTelemetry`, at most `PAGE_BATCH_SPANS` a batch. */
+export function sendPageTelemetry(
+ host: Host
,
+ recorder: TelemetryRecorder,
+ context: Context,
+): TelemetrySender {
+ const held = host.hold(PageTelemetry, {}, context);
+ // Spans only: its metrics are taken with them and dropped.
+ const waiting = (_partial: boolean) => recorder.queuedSpans > 0;
+ return sender(
+ recorder,
+ PAGE_BATCH_SPANS,
+ waiting,
+ () => held.release(),
+ (batch) => {
+ if (held.state.value.kind !== "live") return undefined;
+ return held.ingest({ spans: batch.spans }, BACKGROUND_CONTEXT);
+ },
+ );
+}
+
+/** Sends a worker's spans and metrics to the server's `WorkerTelemetry`, at most `WORKER_BATCH_ROWS` spans a batch. */
+export function sendWorkerTelemetry
(
+ host: Host
,
+ recorder: TelemetryRecorder,
+ context: Context,
+): TelemetrySender {
+ const held = host.hold(WorkerTelemetry, {}, context);
+ return sender(
+ recorder,
+ WORKER_BATCH_ROWS,
+ (partial) => recorder.pending(partial),
+ () => held.release(),
+ (batch) => {
+ if (held.state.value.kind !== "live" || held.variant !== "worker") return undefined;
+ // A batch takes at most `WORKER_BATCH_ROWS` metric rows; more series in one interval are dropped.
+ return held.ingest(
+ { spans: batch.spans, metrics: batch.metrics.slice(0, WORKER_BATCH_ROWS) },
+ BACKGROUND_CONTEXT,
+ );
+ },
+ );
+}
+
+/**
+ * The send loop over `call`, which sends a batch, or answers `undefined` when it cannot now (the batch then waits); a
+ * send does nothing while `waiting` says nothing waits.
+ */
+function sender(
+ recorder: TelemetryRecorder,
+ limit: number,
+ waiting: (partial: boolean) => boolean,
+ release: () => void,
+ call: (batch: TelemetryBatch) => Promise | undefined,
+): TelemetrySender {
+ let sending: Promise | undefined;
+ let stopped = false;
+ const once = async (partial: boolean): Promise => {
+ if (!waiting(partial)) return;
+ const batch = recorder.take(partial, limit);
+ const sent = call(batch);
+ if (sent === undefined) {
+ // Not bound now: the batch is queued again (at the back), within the recorder's bound.
+ recorder.release();
+ recorder.ingest(batch);
+ return;
+ }
+ // Best effort: a refused or lost batch is given up.
+ await sent.catch(() => {});
+ recorder.release();
+ };
+ return {
+ send: (partial) => {
+ if (stopped) return Promise.resolve();
+ const next = (sending ?? Promise.resolve()).then(() => once(partial));
+ sending = next;
+ return next;
+ },
+ stop: () => {
+ stopped = true;
+ release();
+ },
+ };
+}
diff --git a/packages/chord/src/telemetry-sqlite/index.ts b/packages/chord/src/telemetry-sqlite/index.ts
index a589b635a..80a883389 100644
--- a/packages/chord/src/telemetry-sqlite/index.ts
+++ b/packages/chord/src/telemetry-sqlite/index.ts
@@ -1,24 +1,23 @@
-// The SQLite telemetry store (`@earendil-works/chord/telemetry-sqlite`, decision "Telemetry store", §29): an adapter
-// recording settled spans one row each (events and links inline) and metrics per series per 10 s, flushed in a batch
-// every second with retention, its queue bounded (dropped and counted); and the `TelemetryStore` reads over it.
+// The SQLite telemetry store (`@earendil-works/chord/telemetry-sqlite`, decision "Telemetry store", §29): a recorder
+// (`TelemetryRecorder`) whose batches are written every second, settled spans one row each (events and links inline,
+// times in microseconds) and metrics per series per 10 s, with retention; spans and metrics other processes recorded
+// join the same batches (`ingest`, never overwriting a stored span); and the `TelemetryStore` reads over it.
-import {
- type InstrumentOptions,
- NOOP_TELEMETRY_CONTEXT,
- type SpanAttributes,
- type SpanLink,
- type SpanOptions,
- type SpanStatus,
- type TelemetryCarrier,
- type TelemetryContext,
- type TelemetryMetrics,
- type TelemetryPropagation,
- type TelemetrySpan,
- type TelemetryStore,
+import type {
+ StoredMetric,
+ StoredSpan,
+ TelemetryContext,
+ TelemetryMetrics,
+ TelemetryPropagation,
+ TelemetryStore,
} from "@earendil-works/pi-telemetry";
-import { applySqliteMigrations, type SqliteDatabase, type SqliteValue } from "../sqlite/index.ts";
+import type { SqliteDatabase, SqliteExecutor } from "../sqlite/index.ts";
+import { seriesKey, sortedAttributes, type TelemetryBatch, TelemetryRecorder } from "../telemetry-ingest/recorder.ts";
+import { migrateTelemetryStore } from "./schema.ts";
import { findMetrics, findTraces, getTrace } from "./store.ts";
+export type { TelemetryBatch } from "../telemetry-ingest/recorder.ts";
+
export interface SqliteTelemetryOptions {
/** Retain seven days by default. Cleanup runs in the flush transaction. */
readonly retentionMs?: number;
@@ -32,336 +31,162 @@ export interface SqliteTelemetry extends TelemetryContext, TelemetryStore {
readonly propagation: TelemetryPropagation;
readonly droppedSpans: number;
readonly droppedMeasurements: number;
+ /**
+ * Queues finished spans and metric rows another process recorded, written with the next flush (a span whose id is
+ * stored already is kept as it was); within the queue's bound, the rest dropped and counted. Returns how many
+ * spans it queued. Callers check what they pass: the store writes it as it is.
+ */
+ ingest(batch: TelemetryBatch): number;
/** Persist settled spans and completed ten-second metric intervals. */
flush(): Promise;
/** Stop recording and drain, including partial metric intervals. Does not close the database. */
close(): Promise;
}
-type Identity = { id: string; traceId: string };
-type Link = { trace_id: string; span_id: string; attributes?: SpanAttributes };
-type Metric = {
- interval: number;
- key: string;
- name: string;
- kind: "counter" | "upDownCounter" | "histogram";
- unit: string | null;
- attributes: string;
- count: number;
- sum: number;
- min: number;
- max: number;
-};
-const identities = new WeakMap();
-const carrierKey = "pi-sqlite-span";
-const traceKey = "pi-sqlite-trace";
-const intervalMs = 10_000;
-
-function copyAttributes(attributes?: SpanAttributes): SpanAttributes {
- return Object.fromEntries(
- Object.entries(attributes ?? {})
- .filter(([, value]) => value !== undefined)
- .map(([key, value]) => [key, Array.isArray(value) ? [...value] : value]),
- );
+/** `ms` in whole microseconds, as the store keeps span times. */
+function micros(ms: number): number {
+ return Math.round(ms * 1000);
}
-function copyLink(link: SpanLink): Link | undefined {
- const identity = identities.get(link.context);
- return identity
- ? { trace_id: identity.traceId, span_id: identity.id, attributes: copyAttributes(link.attributes) }
- : undefined;
-}
-
-class Recorder implements SqliteTelemetry, TelemetryPropagation {
- readonly propagation: TelemetryPropagation = this;
- readonly metrics: TelemetryMetrics = {
- counter: (name, options) => ({ add: this.measurement("counter", name, options) }),
- upDownCounter: (name, options) => ({ add: this.measurement("upDownCounter", name, options) }),
- histogram: (name, options) => ({ record: this.measurement("histogram", name, options) }),
- };
- droppedSpans = 0;
- droppedMeasurements = 0;
- private readonly db: SqliteDatabase;
- private readonly retention: number;
- private readonly capacity: number;
- private readonly scope = crypto.randomUUID();
- private sequence = 0;
- private readonly spans: SqliteValue[][] = [];
- private readonly measurements = new Map();
- private inFlightMeasurements = 0;
- private readonly timer: ReturnType;
- private stopped = false;
- private failed = false;
- private failure: unknown;
- private writing?: Promise;
- private closing?: Promise;
+class Store implements SqliteTelemetry {
+ readonly #recorder: TelemetryRecorder;
+ readonly #db: SqliteDatabase;
+ readonly #retention: number;
+ readonly #timer: ReturnType;
+ #failed = false;
+ #failure: unknown;
+ #writing?: Promise;
+ #closing?: Promise;
constructor(db: SqliteDatabase, retention: number, capacity: number) {
- this.db = db;
- this.retention = retention;
- this.capacity = capacity;
- this.timer = setInterval(() => {
- if (!this.writing) void this.flush().catch(() => {});
+ this.#db = db;
+ this.#retention = retention;
+ const scope = crypto.randomUUID();
+ this.#recorder = new TelemetryRecorder(() => scope, capacity);
+ this.#timer = setInterval(() => {
+ if (!this.#writing) void this.flush().catch(() => {});
}, 1000);
- this.timer.unref?.();
+ this.#timer.unref?.();
}
- startSpan(options: SpanOptions, callback: (span: TelemetrySpan) => T | Promise): Promise {
- return this.start(undefined, options, callback);
+ get metrics(): TelemetryMetrics {
+ return this.#recorder.metrics;
}
- inject(context: TelemetryContext): TelemetryCarrier | undefined {
- const identity = identities.get(context);
- return identity ? { [carrierKey]: identity.id, [traceKey]: identity.traceId } : undefined;
+ get propagation(): TelemetryPropagation {
+ return this.#recorder;
}
- extract(carrier: TelemetryCarrier | undefined): TelemetryContext {
- const id = carrier?.[carrierKey];
- const traceId = carrier?.[traceKey];
- if (typeof id !== "string" || typeof traceId !== "string") return this;
- const identity = { id, traceId };
- const parent: TelemetryContext = {
- metrics: this.metrics,
- propagation: this,
- startSpan: (options, callback) => this.start(identity, options, callback),
- };
- identities.set(parent, identity);
- return parent;
+ get droppedSpans(): number {
+ return this.#recorder.droppedSpans;
}
- private inert(options: SpanOptions, callback: (span: TelemetrySpan) => T | Promise): Promise {
- return NOOP_TELEMETRY_CONTEXT.startSpan(options, (noop) =>
- callback({
- ...noop,
- metrics: this.metrics,
- propagation: this,
- startSpan: (options, callback) => this.inert(options, callback),
- }),
- );
+ get droppedMeasurements(): number {
+ return this.#recorder.droppedMeasurements;
}
- private async start(
- parent: Identity | undefined,
- options: SpanOptions,
- callback: (span: TelemetrySpan) => T | Promise,
- ): Promise {
- if (this.stopped) return this.inert(options, callback);
- const name = options.name;
- let attributes = copyAttributes(options.attributes);
- const links: Link[] = [];
- for (const link of options.links ?? []) {
- const copied = copyLink(link);
- if (copied) links.push(copied);
- }
- const id = `${this.scope}:${++this.sequence}`;
- const identity = { id, traceId: parent?.traceId ?? id };
- const started = Date.now();
- const clock = performance.now();
- const events: { name: string; time_ms: number; attributes: SpanAttributes }[] = [];
- let status: SpanStatus = { status: "ok" };
- let explicit = false;
- let settled = false;
- const record = (action: () => void): void => {
- if (!settled && !this.stopped) action();
- };
- const span: TelemetrySpan = {
- metrics: this.metrics,
- propagation: this,
- startSpan: (options, callback) =>
- settled ? this.inert(options, callback) : this.start(identity, options, callback),
- addLink: (link) =>
- record(() => {
- const copied = copyLink(link);
- if (copied) links.push(copied);
- }),
- addEvent: (name, attrs) =>
- record(() => {
- events.push({ name, time_ms: performance.now() - clock, attributes: copyAttributes(attrs) });
- }),
- setAttributes: (attrs) =>
- record(() => {
- attributes = { ...attributes, ...copyAttributes(attrs) };
- }),
- setStatus: (value) =>
- record(() => {
- status =
- value.status === "error" && value.error
- ? { status: "error", error: { ...value.error } }
- : { status: value.status };
- explicit = true;
- }),
- };
- identities.set(span, identity);
- try {
- return await callback(span);
- } catch (error) {
- if (!explicit)
- status =
- error instanceof Error
- ? { status: "error", error: { name: error.name, message: error.message } }
- : { status: "error" };
- throw error;
- } finally {
- settled = true;
- if (!this.stopped) {
- if (this.spans.length >= this.capacity) this.droppedSpans++;
- else
- this.spans.push([
- id,
- identity.traceId,
- parent?.id ?? null,
- name,
- started,
- started + performance.now() - clock,
- JSON.stringify(attributes),
- JSON.stringify(events),
- JSON.stringify(links),
- JSON.stringify(status),
- ]);
- }
- }
- }
+ readonly startSpan: TelemetryContext["startSpan"] = (options, callback) =>
+ this.#recorder.startSpan(options, callback);
- private measurement(
- kind: Metric["kind"],
- name: string,
- options?: InstrumentOptions,
- ): (value: number, attributes?: SpanAttributes) => void {
- const unit = options?.unit ?? null;
- return (value, attributes) => {
- if (this.stopped) return;
- const copied = copyAttributes(attributes);
- const encoded = JSON.stringify(
- Object.fromEntries(
- Object.keys(copied)
- .sort()
- .map((key) => [key, copied[key]]),
- ),
- );
- const key = JSON.stringify([name, kind, unit, encoded]);
- const interval = Math.floor(Date.now() / intervalMs) * intervalMs;
- const pendingKey = `${interval}:${key}`;
- const previous = this.measurements.get(pendingKey);
- if (!previous && this.measurements.size + this.inFlightMeasurements >= this.capacity) {
- this.droppedMeasurements++;
- return;
- }
- this.measurements.set(pendingKey, {
- interval,
- key,
- name,
- kind,
- unit,
- attributes: encoded,
- count: (previous?.count ?? 0) + 1,
- sum: (previous?.sum ?? 0) + value,
- min: Math.min(previous?.min ?? value, value),
- max: Math.max(previous?.max ?? value, value),
- });
- };
+ ingest(batch: TelemetryBatch): number {
+ return this.#recorder.ingest(batch);
}
/** Readers use committed rows only; flush first to include newly settled spans. */
- readonly getTrace: TelemetryStore["getTrace"] = (traceId) => getTrace(this.db, traceId);
- readonly findTraces: TelemetryStore["findTraces"] = (query) => findTraces(this.db, query);
- readonly findMetrics: TelemetryStore["findMetrics"] = (query) => findMetrics(this.db, query);
+ readonly getTrace: TelemetryStore["getTrace"] = (traceId) => getTrace(this.#db, traceId);
+ readonly findTraces: TelemetryStore["findTraces"] = (query) => findTraces(this.#db, query);
+ readonly findMetrics: TelemetryStore["findMetrics"] = (query) => findMetrics(this.#db, query);
flush(): Promise {
- return this.closing ?? this.drain(false);
+ return this.#closing ?? this.#drain(false);
}
close(): Promise {
- if (!this.closing) {
- this.stopped = true;
- clearInterval(this.timer);
- this.closing = this.drain(true);
+ if (!this.#closing) {
+ this.#recorder.stop("keep");
+ clearInterval(this.#timer);
+ this.#closing = this.#drain(true);
}
- return this.closing;
+ return this.#closing;
}
- private async drain(partial: boolean): Promise {
- while (this.writing) await this.writing;
- if (this.failed) throw this.failure;
- const spans = this.spans.slice();
- const metrics: Metric[] = [];
- const completed = Math.floor(Date.now() / intervalMs) * intervalMs;
- for (const [key, metric] of this.measurements) {
- if (!partial && metric.interval >= completed) continue;
- metrics.push(metric);
- this.measurements.delete(key);
- }
- this.inFlightMeasurements = metrics.length;
- this.writing = Promise.resolve()
+ async #drain(partial: boolean): Promise {
+ while (this.#writing) await this.#writing;
+ if (this.#failed) throw this.#failure;
+ const batch = this.#recorder.take(partial);
+ this.#writing = Promise.resolve()
.then(() =>
- this.db.transaction(async (tx) => {
- for (const span of spans)
- await tx.run("INSERT INTO telemetry_spans VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)", ...span);
- for (const metric of metrics)
- await tx.run(
- `INSERT INTO telemetry_metrics VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
- ON CONFLICT(interval_ms, series_key) DO UPDATE SET count = count + excluded.count,
- sum = sum + excluded.sum, min = min(min, excluded.min), max = max(max, excluded.max)`,
- metric.interval,
- metric.key,
- metric.name,
- metric.kind,
- metric.unit,
- metric.attributes,
- metric.count,
- metric.sum,
- metric.min,
- metric.max,
- );
- const cutoff = Date.now() - this.retention;
- await tx.run("DELETE FROM telemetry_spans WHERE ended_ms < ?", cutoff);
+ this.#db.transaction(async (tx) => {
+ for (const span of batch.spans) await writeSpan(tx, span);
+ for (const metric of batch.metrics) await writeMetric(tx, metric);
+ const cutoff = Date.now() - this.#retention;
+ await tx.run("DELETE FROM telemetry_spans WHERE ended_us < ?", cutoff * 1000);
await tx.run("DELETE FROM telemetry_metrics WHERE interval_ms < ?", cutoff);
}),
)
- .then(() => {
- this.spans.splice(0, spans.length);
- })
.catch((error: unknown) => {
- this.failed = this.stopped = true;
- this.failure = error;
- this.spans.length = 0;
- this.measurements.clear();
- clearInterval(this.timer);
+ this.#failed = true;
+ this.#failure = error;
+ this.#recorder.stop("discard");
+ clearInterval(this.#timer);
throw error;
})
.finally(() => {
- this.writing = undefined;
- this.inFlightMeasurements = 0;
+ this.#writing = undefined;
+ this.#recorder.release();
});
- await this.writing;
+ await this.#writing;
}
}
+/** Writes `span`, unless a span of its id is stored already (an ingested span never replaces one). */
+function writeSpan(tx: SqliteExecutor, span: StoredSpan): Promise {
+ return tx.run(
+ "INSERT OR IGNORE INTO telemetry_spans VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)",
+ span.id,
+ span.traceId,
+ span.parentId ?? null,
+ span.name,
+ micros(span.startedMs),
+ micros(span.endedMs),
+ JSON.stringify(span.attributes),
+ JSON.stringify(span.events.map(({ name, timeMs, attributes }) => ({ name, time_ms: timeMs, attributes }))),
+ JSON.stringify(
+ span.links.map(({ traceId, spanId, attributes }) => ({ trace_id: traceId, span_id: spanId, attributes })),
+ ),
+ JSON.stringify(span.status),
+ );
+}
+
+/** Adds `metric` to its series' row of its interval. */
+function writeMetric(tx: SqliteExecutor, metric: StoredMetric): Promise {
+ return tx.run(
+ `INSERT INTO telemetry_metrics VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
+ ON CONFLICT(interval_ms, series_key) DO UPDATE SET count = count + excluded.count,
+ sum = sum + excluded.sum, min = min(min, excluded.min), max = max(max, excluded.max)`,
+ metric.intervalMs,
+ seriesKey(metric),
+ metric.name,
+ metric.kind,
+ metric.unit ?? null,
+ JSON.stringify(sortedAttributes(metric.attributes)),
+ metric.count,
+ metric.sum,
+ metric.min,
+ metric.max,
+ );
+}
+
/** Portable, buffered SQLite recorder. Recording never performs SQL; flush runs every second.
- * Only settled spans are stored. Metrics aggregate count/sum/min/max per ten-second interval.
- * A write failure permanently stops recording and is reported by flush and close. */
+ * Only settled spans are stored, their times in microseconds (`telemetryNow`). Metrics aggregate count/sum/min/max per
+ * ten-second interval. A store of an older version in `db` is migrated (version 2: span times from milliseconds to
+ * microseconds, rows kept). A write failure permanently stops recording and is reported by flush and close. */
export async function createSqliteTelemetry(
db: SqliteDatabase,
options: SqliteTelemetryOptions = {},
): Promise {
const retention = options.retentionMs ?? 7 * 24 * 60 * 60 * 1000;
const capacity = options.maxQueuedSpans ?? 10_000;
- await applySqliteMigrations(
- db,
- [
- {
- version: 1,
- statements: [
- `CREATE TABLE telemetry_spans (id TEXT PRIMARY KEY, trace_id TEXT NOT NULL, parent_id TEXT, name TEXT, started_ms REAL,
- ended_ms REAL NOT NULL, attributes TEXT, events TEXT, links TEXT, status TEXT)`,
- "CREATE INDEX telemetry_spans_ended_ms ON telemetry_spans(ended_ms)",
- "CREATE INDEX telemetry_spans_trace_started ON telemetry_spans(trace_id, started_ms)",
- "CREATE INDEX telemetry_spans_started_ms ON telemetry_spans(started_ms)",
- `CREATE TABLE telemetry_metrics (interval_ms INTEGER, series_key TEXT, name TEXT, kind TEXT,
- unit TEXT, attributes TEXT, count INTEGER, sum REAL, min REAL, max REAL, PRIMARY KEY(interval_ms, series_key))`,
- ],
- },
- ],
- { table: "telemetry_schema" },
- );
- return new Recorder(db, retention, capacity);
+ await migrateTelemetryStore(db);
+ return new Store(db, retention, capacity);
}
diff --git a/packages/chord/src/telemetry-sqlite/node.ts b/packages/chord/src/telemetry-sqlite/node.ts
new file mode 100644
index 000000000..812f60ecc
--- /dev/null
+++ b/packages/chord/src/telemetry-sqlite/node.ts
@@ -0,0 +1,34 @@
+// The SQLite telemetry store read-only, on Node (`@earendil-works/chord/telemetry-sqlite/node`): a store file that
+// recorders of other processes write, opened for its reads (`TelemetryStore`) only.
+
+import type { TelemetryStore } from "@earendil-works/pi-telemetry";
+import { openNodeSqliteDatabase } from "../sqlite/node.ts";
+import { assertTelemetryStore } from "./schema.ts";
+import { findMetrics, findTraces, getTrace } from "./store.ts";
+
+/** A telemetry store opened for reads: the store's reads, and the close of its file. */
+export interface SqliteTelemetryStore extends TelemetryStore {
+ /** Closes the file; reads after it reject. */
+ close(): Promise;
+}
+
+/**
+ * Opens the telemetry store at `path` read-only (SQLite's read-only mode: it never writes the file, never migrates it,
+ * never creates it), while recorders of other processes write it or after. Rejects for a file that holds no store or
+ * a store of another version (a recorder, `createSqliteTelemetry`, migrates an older one).
+ */
+export async function openTelemetryStore(path: string): Promise {
+ const db = await openNodeSqliteDatabase(path, { mode: "read-only" });
+ try {
+ await assertTelemetryStore(db);
+ } catch (error) {
+ await db.close();
+ throw error;
+ }
+ return {
+ getTrace: (traceId) => getTrace(db, traceId),
+ findTraces: (query) => findTraces(db, query),
+ findMetrics: (query) => findMetrics(db, query),
+ close: () => db.close(),
+ };
+}
diff --git a/packages/chord/src/telemetry-sqlite/schema.ts b/packages/chord/src/telemetry-sqlite/schema.ts
new file mode 100644
index 000000000..53b226f4c
--- /dev/null
+++ b/packages/chord/src/telemetry-sqlite/schema.ts
@@ -0,0 +1,69 @@
+// The SQLite telemetry store's tables and their versions: the migrations a recorder applies, and the check a reader
+// makes that a file holds a store of this version.
+
+import { applySqliteMigrations, type SqliteDatabase, type SqliteMigration } from "../sqlite/index.ts";
+
+/** The table that records the store's version. */
+const VERSION_TABLE = "telemetry_schema";
+
+/**
+ * The store's versions. 1: spans with their start and end in milliseconds (`started_ms`, `ended_ms`, whole
+ * milliseconds at the start); 2: in whole microseconds (`started_us`, `ended_us`, integers), the rows of 1 kept,
+ * their times multiplied.
+ */
+const MIGRATIONS: readonly SqliteMigration[] = [
+ {
+ version: 1,
+ statements: [
+ `CREATE TABLE telemetry_spans (id TEXT PRIMARY KEY, trace_id TEXT NOT NULL, parent_id TEXT, name TEXT, started_ms REAL,
+ ended_ms REAL NOT NULL, attributes TEXT, events TEXT, links TEXT, status TEXT)`,
+ "CREATE INDEX telemetry_spans_ended_ms ON telemetry_spans(ended_ms)",
+ "CREATE INDEX telemetry_spans_trace_started ON telemetry_spans(trace_id, started_ms)",
+ "CREATE INDEX telemetry_spans_started_ms ON telemetry_spans(started_ms)",
+ `CREATE TABLE telemetry_metrics (interval_ms INTEGER, series_key TEXT, name TEXT, kind TEXT,
+ unit TEXT, attributes TEXT, count INTEGER, sum REAL, min REAL, max REAL, PRIMARY KEY(interval_ms, series_key))`,
+ ],
+ },
+ {
+ version: 2,
+ statements: [
+ `CREATE TABLE telemetry_spans_us (id TEXT PRIMARY KEY, trace_id TEXT NOT NULL, parent_id TEXT, name TEXT,
+ started_us INTEGER, ended_us INTEGER NOT NULL, attributes TEXT, events TEXT, links TEXT, status TEXT)`,
+ `INSERT INTO telemetry_spans_us SELECT id, trace_id, parent_id, name, CAST(round(started_ms * 1000) AS INTEGER),
+ CAST(round(ended_ms * 1000) AS INTEGER), attributes, events, links, status FROM telemetry_spans`,
+ "DROP TABLE telemetry_spans",
+ "ALTER TABLE telemetry_spans_us RENAME TO telemetry_spans",
+ "CREATE INDEX telemetry_spans_ended_us ON telemetry_spans(ended_us)",
+ "CREATE INDEX telemetry_spans_trace_started ON telemetry_spans(trace_id, started_us)",
+ "CREATE INDEX telemetry_spans_started_us ON telemetry_spans(started_us)",
+ ],
+ },
+];
+
+/** Brings the store in `db` to this version (made when absent; one of an older version migrated, its rows kept). */
+export function migrateTelemetryStore(db: SqliteDatabase): Promise {
+ return applySqliteMigrations(db, MIGRATIONS, { table: VERSION_TABLE });
+}
+
+/**
+ * Throws unless `db` holds a store of this version: a reader cannot migrate (a recorder of this version, opened on the
+ * file once, does).
+ */
+export async function assertTelemetryStore(db: SqliteDatabase): Promise {
+ const expected = MIGRATIONS.at(-1)!.version;
+ // The file is the trust boundary here: any file may be named, a store or not.
+ const tables = await db.all<{ name: string }>(
+ "SELECT name FROM sqlite_master WHERE type = 'table' AND name = ?",
+ VERSION_TABLE,
+ );
+ if (tables.length === 0) throw new Error("not a telemetry store: no telemetry_schema table");
+ const row = await db.get<{ version: number }>(`SELECT version FROM ${VERSION_TABLE} WHERE singleton = 1`);
+ const version = row?.version ?? 0;
+ if (version > expected)
+ throw new Error(`telemetry store version ${version} is newer than this reader's ${expected}`);
+ if (version < expected) {
+ throw new Error(
+ `telemetry store version ${version}, not ${expected}: a recorder (createSqliteTelemetry) migrates it`,
+ );
+ }
+}
diff --git a/packages/chord/src/telemetry-sqlite/store.ts b/packages/chord/src/telemetry-sqlite/store.ts
index 562af3570..ee8dfb0a9 100644
--- a/packages/chord/src/telemetry-sqlite/store.ts
+++ b/packages/chord/src/telemetry-sqlite/store.ts
@@ -1,4 +1,5 @@
-// The reads of the SQLite telemetry store (`TelemetryStore`): complete traces by query or id, metric rows by query.
+// The reads of the SQLite telemetry store (`TelemetryStore`): complete traces by query or id, metric rows by query; span
+// times read from microseconds as milliseconds.
import type {
MetricQuery,
@@ -16,8 +17,8 @@ type SpanRow = {
trace_id: string;
parent_id: string | null;
name: string;
- started_ms: number;
- ended_ms: number;
+ started_us: number;
+ ended_us: number;
attributes: string;
events: string;
links: string;
@@ -30,8 +31,8 @@ function storedSpan(row: SpanRow): StoredSpan {
traceId: row.trace_id,
...(row.parent_id === null ? {} : { parentId: row.parent_id }),
name: row.name,
- startedMs: row.started_ms,
- endedMs: row.ended_ms,
+ startedMs: row.started_us / 1000,
+ endedMs: row.ended_us / 1000,
attributes: JSON.parse(row.attributes) as SpanAttributes,
events: (JSON.parse(row.events) as { name: string; time_ms: number; attributes: SpanAttributes }[]).map(
(event) => ({ name: event.name, timeMs: event.time_ms, attributes: event.attributes }),
@@ -66,10 +67,11 @@ function attributesSql(attributes: TraceQuery["attributes"], column: string, par
}
/**
- * Spans in start order: by start time, then as each recorder started them (an id is its recorder's scope and a counter:
- * by length, then text, the counter compares as a number), so spans of one millisecond keep their order (slice 9).
+ * Spans in start order: by start time (to the microsecond), then as each recorder started them (an id is its
+ * recorder's scope and a counter: by length, then text, the counter compares as a number), so spans of one
+ * microsecond keep their order (slice 9).
*/
-const SPAN_ORDER = "started_ms, length(id), id";
+const SPAN_ORDER = "started_us, length(id), id";
/** The spans of trace `traceId` in start order; `undefined` when none is stored. */
export async function getTrace(db: SqliteDatabase, traceId: string): Promise {
@@ -95,12 +97,12 @@ export async function findTraces(
params.push(query.name);
}
if (query.startMin !== undefined) {
- conditions.push("started_ms >= ?");
- params.push(query.startMin);
+ conditions.push("started_us >= ?");
+ params.push(query.startMin * 1000);
}
if (query.startMax !== undefined) {
- conditions.push("started_ms <= ?");
- params.push(query.startMax);
+ conditions.push("started_us <= ?");
+ params.push(query.startMax * 1000);
}
if (query.errors)
conditions.push(
@@ -112,14 +114,14 @@ export async function findTraces(
);
if (query.cursor !== undefined) {
const cursor = JSON.parse(query.cursor) as [number, string];
- conditions.push("(started_ms < ? OR (started_ms = ? AND trace_id > ?))");
+ conditions.push("(started_us < ? OR (started_us = ? AND trace_id > ?))");
params.push(cursor[0], cursor[0], cursor[1]);
}
return db.transaction(async (tx) => {
- const heads = await tx.all<{ trace_id: string; started_ms: number }>(
+ const heads = await tx.all<{ trace_id: string; started_us: number }>(
`WITH heads AS (
- SELECT trace_id, min(started_ms) started_ms FROM telemetry_spans GROUP BY trace_id
- ) SELECT * FROM heads WHERE ${conditions.join(" AND ") || "1"} ORDER BY started_ms DESC, trace_id LIMIT ?`,
+ SELECT trace_id, min(started_us) started_us FROM telemetry_spans GROUP BY trace_id
+ ) SELECT * FROM heads WHERE ${conditions.join(" AND ") || "1"} ORDER BY started_us DESC, trace_id LIMIT ?`,
...params,
limit + 1,
);
@@ -139,7 +141,7 @@ export async function findTraces(
const last = heads.at(-1)!;
return {
traces: heads.map((head) => ({ traceId: head.trace_id, spans: grouped.get(head.trace_id)! })),
- ...(more ? { cursor: JSON.stringify([last.started_ms, last.trace_id]) } : {}),
+ ...(more ? { cursor: JSON.stringify([last.started_us, last.trace_id]) } : {}),
};
});
}
diff --git a/packages/chord/src/telemetry.ts b/packages/chord/src/telemetry.ts
index 9216e2df5..5945e4418 100644
--- a/packages/chord/src/telemetry.ts
+++ b/packages/chord/src/telemetry.ts
@@ -20,6 +20,7 @@ import {
type TypedSpanStarter,
type TypedTelemetryMetrics,
} from "@earendil-works/pi-telemetry";
+import type { Address } from "./contracts/index.ts";
import { isChordError } from "./data/index.ts";
/** A span of Chord's schema, its end attributes and events typed. */
@@ -38,6 +39,21 @@ export type ChordCounter ATTRIBUTE_LENGTH ? text.slice(0, ATTRIBUTE_LENGTH) : text;
}
+/** The `chord.host` attribute of the spans of a host at `address`: its key, `client` without one; capped. */
+export function hostAttribute(address: Address | undefined): string {
+ return capped(address?.key ?? "client");
+}
+
/** The longest message a span's error or event carries (decision "Errors in telemetry"). */
export const MAX_MESSAGE = 500;
diff --git a/packages/chord/src/web/README.md b/packages/chord/src/web/README.md
index 8c82a79f1..e1b4a310b 100644
--- a/packages/chord/src/web/README.md
+++ b/packages/chord/src/web/README.md
@@ -11,6 +11,7 @@ startPage({
canRetry: async () => true, // false: stop reconnecting (a guest's ended share)
onConnection: (state) => setBanner(state), // connecting | connected | waiting
render: (host) => createRoot(root).render(),
+ telemetry: true, // record: spans sent to the server's PageTelemetry
});
```
@@ -23,6 +24,9 @@ startPage
({
`navigator.languages`, followed on `languagechange`) is the host's language for `useMessages`, and `lang` and `dir`
on the root element (`language.ts`, `followLanguage`); reports reach `onError` as `{ kind: "messages", report }`.
- A new set's plugin stylesheets replace the old ones (`syncStylesheets`); an outdated page reloads.
+- With `telemetry: true` the page's host records in memory (`TelemetryRecorder`, span ids `browser::`)
+ and sends finished spans to the server's `PageTelemetry` every 3 s and when the page is hidden; a click is a trace of
+ its own with `host.root(fn, ctx, { trace: { name } })`. The kit's server serves the object when it has a store.
- Wakes (`environment.ts`): visible again, `online`, `pageshow` from the back/forward cache, Chromium's network change.
Tests in a real browser: `test/node/web/` (Chromium: `CHROMIUM_BIN`, else `chromium-docker`; skipped without).
diff --git a/packages/chord/src/web/page.ts b/packages/chord/src/web/page.ts
index 8fd69ff4c..a9cc8b5f8 100644
--- a/packages/chord/src/web/page.ts
+++ b/packages/chord/src/web/page.ts
@@ -2,7 +2,8 @@
// app's web entry (the base bundle). It takes the plugin scripts the page's combined file registered, loads them with
// the app's core facets and the kit's themes and translations, follows the theme and the language, keeps its link to
// the server (the connection loop), follows `WebScripts` to apply new plugin scripts in place, reloads the page when
-// the server's base bundle changed, and hands the host to the app's render.
+// the server's base bundle changed, records its telemetry when asked (sent to the server's `PageTelemetry`), and hands
+// the host to the app's render.
import { BACKGROUND_CONTEXT } from "../context/index.ts";
import type { Principal } from "../data/index.ts";
@@ -18,6 +19,7 @@ import {
translationsFacet,
WebScripts,
} from "../surfaces/index.ts";
+import { sendPageTelemetry, TelemetryRecorder, type TelemetrySender } from "../telemetry-ingest/index.ts";
import { pageEnvironment } from "./environment.ts";
import { followLanguage } from "./language.ts";
import { type PageBootstrap, PageScripts, syncStylesheets } from "./scripts.ts";
@@ -36,6 +38,12 @@ export type PageOptions = {
readonly onConnection?: (state: ConnectionState) => void;
/** Renders the app with its host, once the plugins are loaded. */
readonly render: (host: Client
["host"]) => void;
+ /**
+ * Records the page's telemetry (decision "Telemetry from browser pages"): its spans (a click started with
+ * `host.root(fn, ctx, { trace })`, the calls under it, carriers on its calls) are kept in memory and sent to the
+ * server's telemetry object every few seconds and when the page is hidden. Off by default.
+ */
+ readonly telemetry?: boolean;
/** Plugins left out or kept old, a failed update, the host's errors, messages' reports: the console by default. */
readonly onError?: (error: ClientError) => void;
};
@@ -55,6 +63,14 @@ export async function startPage
(options: PageOptions
): P
...(options.core ?? []),
];
const onError = options.onError ?? ((error: ClientError) => console.error("chord page:", error));
+ let recorder: TelemetryRecorder | undefined;
+ const telemetry =
+ options.telemetry === true
+ ? (incarnation: () => string) => {
+ recorder = new TelemetryRecorder(() => `browser:${incarnation()}`, PAGE_QUEUE);
+ return recorder;
+ }
+ : undefined;
const client = await startClient
({
scripts: WebScripts,
base: scripts.base,
@@ -74,14 +90,30 @@ export async function startPage
(options: PageOptions
): P
...(options.onConnection === undefined ? {} : { onConnection: options.onConnection }),
applied: (set) => syncStylesheets(set, PREFIX),
environment: pageEnvironment(),
+ ...(telemetry === undefined ? {} : { telemetry }),
onError,
});
+ if (recorder !== undefined) sendEvery(sendPageTelemetry(client.host, recorder, BACKGROUND_CONTEXT));
await followThemes(client.host, BACKGROUND_CONTEXT);
await followLanguage(client.host, (report) => onError({ kind: "messages", report }), BACKGROUND_CONTEXT);
options.render(client.host);
return client;
}
+/** How many finished spans a page keeps while it cannot send (past it new ones are dropped). */
+const PAGE_QUEUE = 1000;
+
+/** How often a page sends its finished spans. */
+const PAGE_SEND_MS = 3000;
+
+/** Sends with `sender` every `PAGE_SEND_MS` and at once when the page is hidden (it may not come back). */
+function sendEvery(sender: TelemetrySender): void {
+ setInterval(() => void sender.send(false), PAGE_SEND_MS);
+ document.addEventListener("visibilitychange", () => {
+ if (document.visibilityState === "hidden") void sender.send(true);
+ });
+}
+
/** The server's current base bundle hash (`undefined` when it cannot be asked: offline, restarting). */
async function serverBase(): Promise {
try {
diff --git a/packages/chord/test/documents/documents.test.ts b/packages/chord/test/documents/documents.test.ts
index 03dbe683c..9160f7798 100644
--- a/packages/chord/test/documents/documents.test.ts
+++ b/packages/chord/test/documents/documents.test.ts
@@ -1,9 +1,13 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
-import { BACKGROUND_CONTEXT as context, withCancel, withTelemetry } from "../../src/context/index.ts";
+import { type Context, BACKGROUND_CONTEXT as context, withCancel, withTelemetry } from "../../src/context/index.ts";
import { arr, int, local, method, obj, str } from "../../src/contracts/index.ts";
+import type { Tx } from "../../src/documents/index.ts";
import { defineState, type KeyedHandle, type SingletonHandle } from "../../src/documents/index.ts";
-import { delivered, framesOf, loaded, rejection } from "../support.ts";
+import { eq } from "../../src/store/expression.ts";
+import type { TableOf } from "../../src/store/index.ts";
+import { defineTable } from "../../src/store/table.ts";
+import { delivered, framesOf, loaded, memoryStore, rejection } from "../support.ts";
const List = defineState("list", { schema: obj({ items: arr(str()) }), version: 1, initial: () => ({ items: [] }) });
const Drafts = defineState("drafts", {
@@ -196,7 +200,7 @@ describe("commits in telemetry (slice 9)", () => {
});
const work = telemetry.getSpans().find(({ name }) => name === "work");
expect(work!.events).toEqual([
- { name: "chord.commit", attributes: { documents: 1, ops: 1, duration: expect.any(Number) } },
+ { name: "chord.commit", attributes: { documents: 1, ops: 1, rows: 0, duration: expect.any(Number) } },
]);
expect(telemetry.getMetrics().map(({ name, unit }) => [name, unit])).toContainEqual([
"chord.commit.duration",
@@ -204,6 +208,39 @@ describe("commits in telemetry (slice 9)", () => {
]);
});
+ it("counts the table rows a commit's writes changed: a put one, an update or delete the rows it changed", async () => {
+ const Rows = defineTable("rows", { version: 1, columns: { id: int(), text: str() }, key: ["id"] });
+ // A table's owner has empty params.
+ const Keeper = local("app.keeper", { version: 1, params: {}, members: { touch: method() } });
+ const telemetry = new InMemoryTelemetryContext();
+ let write: ((fn: (tx: Tx, rows: TableOf) => void, ctx: Context) => Promise) | undefined;
+ const { host } = await loaded(
+ (h) =>
+ h.serve(Keeper, (_, self) => {
+ const rows = self.table(Rows);
+ write = (fn, ctx) => self.tx((tx) => fn(tx, rows), ctx);
+ return { touch: async () => null };
+ }),
+ { telemetry, store: await memoryStore() },
+ );
+ await telemetry.startSpan({ name: "work" }, async (span) => {
+ const traced = withTelemetry(span, context);
+ await write!((tx, rows) => {
+ for (const id of [1, 2, 3]) tx.put(rows, { id, text: "a" });
+ }, traced);
+ await write!((tx, rows) => {
+ tx.updateWhere(rows, (row) => eq(row.text, "a"), { text: "b" });
+ tx.delete(rows, { id: 9 });
+ }, traced);
+ });
+ const work = telemetry.getSpans().find(({ name }) => name === "work");
+ expect(work!.events.map(({ attributes }) => [attributes.documents, attributes.ops, attributes.rows])).toEqual([
+ [0, 0, 3],
+ [0, 0, 3],
+ ]);
+ await host.close(context);
+ });
+
it("times nothing when nothing records", async () => {
const { list } = await owner();
const now = vi.spyOn(performance, "now");
diff --git a/packages/chord/test/examples/61-tutorial/main.ts b/packages/chord/test/examples/61-tutorial/main.ts
index 63e63d407..126387b8a 100644
--- a/packages/chord/test/examples/61-tutorial/main.ts
+++ b/packages/chord/test/examples/61-tutorial/main.ts
@@ -1,7 +1,7 @@
// The tutorial's app (`docs/tutorial/book.md`): a shared todo app built with the app kit, one worker per list. Each
// numbered step is the tutorial's chapter of that number: the server and the owner's sign-in, a list on its worker,
// routes, the page, the terminal, a theme plugin added while the app runs, a second user, languages, an edit applied in
-// place, a list exported and imported, and a trace across the page, the server and a worker, read back from the app's
+// place, a list exported and imported, and a request's trace across the server and a worker, read back from the app's
// telemetry store. The lists plugin's own test is `plugins/lists/worker.test.ts`; `screenshots.ts` shows the page and
// the trace viewer in Chromium; `trace.ts` reads a data directory's traces.
// Run from packages/chord (with Node 26.5.1 or later the terminal client runs too; `--serve` keeps the app running):
@@ -16,7 +16,7 @@ import type { StoredTrace } from "@earendil-works/pi-telemetry";
import { renderTrace } from "@earendil-works/pi-telemetry/render";
import { List } from "@todo/app/v1";
import { WebSocket } from "ws";
-import { BACKGROUND_CONTEXT as context, withTelemetry } from "../../../src/context/index.ts";
+import { BACKGROUND_CONTEXT as context } from "../../../src/context/index.ts";
import {
type ChordError,
createHost,
@@ -249,37 +249,27 @@ await app.importData(archive, List({ id: "groceries" }), context).catch((error:
console.log(" importing over groceries:", error.message.replace(base, "…"));
});
-// 11. Telemetry. Every process of the app records to the store in the data directory (step 1 opened it for the server,
-// `worker.ts` opens it in each list's worker). A page stands in here as a client host of this process with a
-// recorder of its own on the same file, signed in with the owner's cookie of step 1. A click is one span of the
-// page; the call under it goes through the server's relay into the list's worker, and the carriers on the wire make
-// one trace of the three processes' spans. The store's `add` checks the text in a span of its own (`ctx.trace`).
-const pageTelemetry = await openTelemetry(telemetryFile(dataDir));
-const page = createHost({
- telemetry: pageTelemetry.store,
- onError: (error) => console.error("page:", error.kind),
-});
-await page.load([], context);
-const pageSocket = new WebSocket(`${url.replace(/^http/, "ws")}/chord`, { headers: { cookie } });
-page.connect(webSocketLink(pageSocket as unknown as WebSocketLike), { principal: { kind: "server" } }, context);
-const pageTodos = await page.get(Todos, { list: "groceries" }, context);
-const click = (text: string) =>
- pageTelemetry.store.startSpan({ name: "page.add" }, (span) => pageTodos.add(text, withTelemetry(span, context)));
-await click("honey");
-await click(" ").catch(() => "refused");
-pageTodos.release();
-await page.close(context);
-await pageTelemetry.close();
-// Each recorder writes what settled once a second: read until the worker's spans of both clicks are there.
-const [refusedTrace, honeyTrace] = await written(telemetry.store, "page.add", 2, "todos.validate");
-console.log("11. adding honey from the page:");
+// 11. Telemetry. The server records to the store in the data directory (step 1 opened it) and writes what every list's
+// worker sends it. A command-line client adds honey and a blank todo: each request is a `chord.http` trace of the
+// server, the call into the list's worker under it, and the store's `add` checks the text in a span of its own
+// (`ctx.trace`). A page's click, recorded by the page itself, is `screenshots.ts`'s (it needs Chromium).
+for (const text of ["honey", " "]) {
+ await fetch(`${url}/api/lists/groceries`, {
+ method: "POST",
+ headers: { ...cli, "content-type": "application/json" },
+ body: JSON.stringify(text),
+ });
+}
+// The worker sends every second, the server writes every second: read until the worker's spans of both are there.
+const [refusedTrace, honeyTrace] = await written(telemetry.store, "chord.http", 2, "todos.validate");
+console.log("11. adding honey from the command line:");
printTelemetry(renderTrace(honeyTrace!.spans));
// `trace.ts` reads the same file from a process of its own: the newest traces, then one by its id.
const traceScript = fileURLToPath(new URL("./trace.ts", import.meta.url));
const read = async (...args: string[]) =>
(await promisify(execFile)(process.execPath, [...process.execArgv, traceScript, ...args])).stdout;
-console.log(" trace.ts --name page.add:");
-printTelemetry(await read(dataDir, "--name", "page.add"));
+console.log(" trace.ts --name chord.http --principal owner:");
+printTelemetry(await read(dataDir, "--name", "chord.http", "--principal", "owner"));
console.log(" trace.ts :");
printTelemetry(await read(dataDir, refusedTrace!.traceId));
diff --git a/packages/chord/test/examples/61-tutorial/plugins/lists/web.ts b/packages/chord/test/examples/61-tutorial/plugins/lists/web.ts
index 34c4b9127..f0ce6755e 100644
--- a/packages/chord/test/examples/61-tutorial/plugins/lists/web.ts
+++ b/packages/chord/test/examples/61-tutorial/plugins/lists/web.ts
@@ -4,7 +4,7 @@
// texts are in the page's language (`useMessages`), and its catalogs are its contribution to the page's `Translations`.
import { BACKGROUND_CONTEXT as context, defineFacet, Translations } from "@todo/app/v1";
-import { Panels, useHold, useMessages, usePageState, useWatch } from "@todo/app/v1/web";
+import { Panels, useHold, useHost, useMessages, usePageState, useWatch } from "@todo/app/v1/web";
import { createElement as h } from "react";
import { Todos } from "./contract.ts";
import { messages } from "./messages.ts";
@@ -12,6 +12,7 @@ import "./lists.css";
function TodoList() {
const { t } = useMessages(messages);
+ const host = useHost();
const list = location.hash.slice(1) || "groceries";
const todos = useHold(Todos, { list });
const items = useWatch(todos?.items) ?? [];
@@ -20,8 +21,11 @@ function TodoList() {
const [text, setText] = usePageState(`lists.draft.${list}`, "");
const add = (event: { preventDefault(): void }) => {
event.preventDefault();
- if (todos === undefined || text.trim() === "") return;
- void todos.add(text, context);
+ // An empty todo too: the list's store refuses it, and the click's trace shows where.
+ if (todos === undefined) return;
+ // The click is a trace of its own: a root span of the page, the call to the list's worker under it.
+ const trace = { name: "page.add", attributes: { chars: text.length } };
+ void host.root((ctx) => todos.add(text, ctx), context, { trace }).catch(() => {});
setText("");
};
return h(
diff --git a/packages/chord/test/examples/61-tutorial/plugins/traces/clock.test.ts b/packages/chord/test/examples/61-tutorial/plugins/traces/clock.test.ts
new file mode 100644
index 000000000..7ad75e33c
--- /dev/null
+++ b/packages/chord/test/examples/61-tutorial/plugins/traces/clock.test.ts
@@ -0,0 +1,60 @@
+// The viewer's clock correction: a page's spans moved by the least amount that puts the server's spans under them
+// inside them; nothing moved when they fit, or when no server span is under a page span.
+// Run from packages/chord:
+// node ../../node_modules/vitest/dist/cli.js --run test/examples/61-tutorial/plugins/traces/clock.test.ts
+import type { StoredSpan } from "@todo/app/v1/server";
+import { describe, expect, it } from "vitest";
+import { clamped } from "./clock.ts";
+
+/** A span `id` on `host` from `startedMs` to `endedMs`, under `parentId`. */
+function span(id: string, host: string, startedMs: number, endedMs: number, parentId?: string): StoredSpan {
+ return {
+ id,
+ traceId: "t",
+ ...(parentId === undefined ? {} : { parentId }),
+ name: id,
+ startedMs,
+ endedMs,
+ attributes: { "chord.host": host },
+ events: [],
+ links: [],
+ status: { status: "ok" },
+ };
+}
+
+/** Each span's times after the correction. */
+function times(spans: readonly StoredSpan[]): [string, number, number][] {
+ return clamped(spans).map(({ id, startedMs, endedMs }) => [id, startedMs, endedMs]);
+}
+
+describe("clamped", () => {
+ it("moves a page that runs late back, so its call contains the server's relay", () => {
+ const spans = [span("click", "browser", 5000, 5010), span("call", "browser", 5001, 5009, "click")];
+ spans.push(span("relay", "server", 2002, 2008, "call"));
+ expect(times(spans)).toEqual([
+ ["click", 2001, 2011],
+ ["call", 2002, 2010],
+ ["relay", 2002, 2008],
+ ]);
+ });
+
+ it("moves a page that runs early forward by the least amount", () => {
+ const spans = [span("call", "browser", 100, 110), span("relay", "server", 1101, 1105, "call")];
+ expect(times(spans)).toEqual([
+ ["call", 1095, 1105],
+ ["relay", 1101, 1105],
+ ]);
+ });
+
+ it("moves nothing when the server's spans fit, or when no server span is under a page span", () => {
+ const fitting = [span("call", "browser", 100, 110), span("relay", "server", 101, 109, "call")];
+ expect(clamped(fitting)).toBe(fitting);
+ const alone = [span("click", "browser", 5000, 5010), span("other", "server", 1, 2)];
+ expect(clamped(alone)).toBe(alone);
+ });
+
+ it("centres a server child longer than its page parent", () => {
+ const spans = [span("call", "browser", 100, 102), span("relay", "server", 200, 210, "call")];
+ expect(times(spans)[0]).toEqual(["call", 204, 206]);
+ });
+});
diff --git a/packages/chord/test/examples/61-tutorial/plugins/traces/clock.ts b/packages/chord/test/examples/61-tutorial/plugins/traces/clock.ts
new file mode 100644
index 000000000..6e3f50a38
--- /dev/null
+++ b/packages/chord/test/examples/61-tutorial/plugins/traces/clock.ts
@@ -0,0 +1,42 @@
+// The trace viewer's clocks: a page's spans come with the page's clock, which may be off by seconds against the
+// server's; a trace's page spans are moved onto the server's clock by its own spans under them.
+
+import type { StoredSpan } from "@todo/app/v1/server";
+
+/**
+ * `spans` with the page's moved onto the server's clock: a page's clock may be off by seconds, so its spans are moved
+ * by the least amount that puts each server span under a page span inside it (`skewOf`); none without such a pair.
+ */
+export function clamped(spans: readonly StoredSpan[]): readonly StoredSpan[] {
+ const skew = skewOf(spans);
+ if (skew === 0) return spans;
+ return spans.map((span) =>
+ hostOf(span) === "browser" ? { ...span, startedMs: span.startedMs + skew, endedMs: span.endedMs + skew } : span,
+ );
+}
+
+/**
+ * The shift of the page's spans closest to none that puts every server child of a page span inside it: at least each
+ * child's end past its parent's, at most each child's start past its parent's (centred when no shift fits both: a
+ * child longer than its parent).
+ */
+function skewOf(spans: readonly StoredSpan[]): number {
+ const byId = new Map(spans.map((span) => [span.id, span]));
+ let least = Number.NEGATIVE_INFINITY;
+ let most = Number.POSITIVE_INFINITY;
+ for (const child of spans) {
+ const parent = child.parentId === undefined ? undefined : byId.get(child.parentId);
+ if (parent === undefined || hostOf(parent) !== "browser" || hostOf(child) === "browser") continue;
+ least = Math.max(least, child.endedMs - parent.endedMs);
+ most = Math.min(most, child.startedMs - parent.startedMs);
+ }
+ if (least === Number.NEGATIVE_INFINITY) return 0;
+ if (least > most) return (least + most) / 2;
+ return Math.min(Math.max(0, least), most);
+}
+
+/** The host that recorded `span`, as every span of Chord's names it (`chord.host`). */
+export function hostOf(span: StoredSpan): string | undefined {
+ const host = span.attributes["chord.host"];
+ return typeof host === "string" ? host : undefined;
+}
diff --git a/packages/chord/test/examples/61-tutorial/plugins/traces/server.ts b/packages/chord/test/examples/61-tutorial/plugins/traces/server.ts
index 63336c795..f630b448c 100644
--- a/packages/chord/test/examples/61-tutorial/plugins/traces/server.ts
+++ b/packages/chord/test/examples/61-tutorial/plugins/traces/server.ts
@@ -1,10 +1,12 @@
// The trace viewer's server half: the owner's JSON routes over the app's telemetry store, which the page's viewer at
-// `/traces` reads (`src/web/traces.ts`). One object per server opens the store's file in the data directory (a native)
-// and contributes the routes while it is live; they read through the store's read interface only (`findTraces`,
-// `getTrace`) and never follow a link to another trace.
+// `/traces` reads (`src/web/traces.ts`). One object per server opens the store's file in the data directory read-only
+// (a native) and contributes the routes while it is live; they read through the store's read interface only
+// (`findTraces`, filtered by who the spans were for, and `getTrace`) and never follow a link to another trace. A page's
+// spans come with the page's clock: the trace moves them onto the server's (`clamped`).
import { type Ctx, defineFacet, forbidden, local } from "@todo/app/v1";
-import { AppInfo, Http, openTelemetry, type StoredSpan, telemetryFile } from "@todo/app/v1/server";
+import { AppInfo, Http, openTelemetryStore, type StoredSpan, telemetryFile } from "@todo/app/v1/server";
+import { clamped, hostOf } from "./clock.ts";
/** The viewer's reader, once per server: empty params, so it lives as long as the server and may contribute. */
const Traces = local("todo.traces", { version: 1, params: {}, members: {} });
@@ -15,23 +17,26 @@ const RECENT = 40;
export default defineFacet((host) => {
host.serve(Traces, (_params, self) => {
const info = self.get(AppInfo, {});
- // The server records to the same file with its own recorder; this one only reads.
+ // The server records to the same file with its own recorder; this object only reads it.
const telemetry = self.open(
- async () => openTelemetry(telemetryFile(info.dataDir.value)),
- (opened) => opened.close(),
+ async () => openTelemetryStore(telemetryFile(info.dataDir.value)),
+ (store) => store.close(),
);
self.contribute(Http, {
routes: {
- "GET /api/traces": async (_request, ctx) => {
+ "GET /api/traces": async (request, ctx) => {
ownerOnly(ctx);
- const { traces } = await telemetry.value.store.findTraces({ limit: RECENT });
+ // `?principal=user:u1`: the traces with a span for that principal (`principalAttributes`).
+ const principal = request.query.get("principal");
+ const attributes = principal === null ? undefined : { "chord.principal": principal };
+ const { traces } = await telemetry.value.findTraces({ limit: RECENT, attributes });
return { kind: "json", value: traces.map(({ traceId, spans }) => summaryOf(traceId, spans)) };
},
"GET /api/traces/:id": async (request, ctx) => {
ownerOnly(ctx);
- const trace = await telemetry.value.store.getTrace(request.params.id!);
+ const trace = await telemetry.value.getTrace(request.params.id!);
if (trace === undefined) return { kind: "error", status: 404 };
- return { kind: "json", value: { id: trace.traceId, spans: rowsOf(trace.spans) } };
+ return { kind: "json", value: { id: trace.traceId, spans: rowsOf(clamped(trace.spans)) } };
},
},
});
@@ -47,17 +52,23 @@ function ownerOnly(ctx: Ctx): void {
/** The attributes of a trace's first span the list shows: an object's type and member, an HTTP route. */
const DETAIL = ["type", "member", "route"];
-/** A trace as the list shows it: its first span's name and details, its size, its processes, its length, its failure. */
-function summaryOf(id: string, spans: readonly StoredSpan[]) {
+/**
+ * A trace as the list shows it: its first span's name and details, whom it was for (a user's name, else the principal
+ * key of its first span that has one), its size, its hosts, its length, its failure.
+ */
+function summaryOf(id: string, stored: readonly StoredSpan[]) {
+ const spans = clamped(stored);
const start = Math.min(...spans.map((span) => span.startedMs));
// A stored trace has at least one span; its spans come in start order.
const first = spans[0]!;
+ const who = spans.find(({ attributes }) => attributes["chord.principal"] !== undefined)?.attributes;
return {
id,
name: first.name,
detail: DETAIL.flatMap((key) => first.attributes[key] ?? []).join(" "),
+ principal: String(who?.["user.name"] ?? who?.["chord.principal"] ?? ""),
spans: spans.length,
- processes: new Set(spans.map(processOf)).size,
+ hosts: new Set(spans.flatMap((span) => hostOf(span) ?? [])).size,
durationMs: Math.max(...spans.map((span) => span.endedMs)) - start,
error: spans.some((span) => span.status.status === "error"),
};
@@ -65,8 +76,9 @@ function summaryOf(id: string, spans: readonly StoredSpan[]) {
/**
* The trace's spans as the tree shows them, parents before their children (in start order), each with its depth, its
- * process, its offset and length from the trace's start, and its attributes, events, links and error as text. A span
- * whose parent is not in the trace (another trace's, or one not stored) is a root.
+ * host, its offset and length from the trace's start, and its attributes, events, links and error as text. A span
+ * whose parent is not in the trace (another trace's, or one not stored) is a root. A span naming no host (one an app
+ * started on an adapter itself) is shown on its parent's.
*/
function rowsOf(spans: readonly StoredSpan[]) {
const start = Math.min(...spans.map((span) => span.startedMs));
@@ -80,24 +92,26 @@ function rowsOf(spans: readonly StoredSpan[]) {
else siblings.push(span);
}
const rows: ReturnType[] = [];
- const visit = (span: StoredSpan, depth: number): void => {
- rows.push(rowOf(span, depth, start));
- for (const child of children.get(span.id) ?? []) visit(child, depth + 1);
+ const visit = (span: StoredSpan, depth: number, around: string): void => {
+ const host = hostOf(span) ?? around;
+ rows.push(rowOf(span, depth, host, start));
+ for (const child of children.get(span.id) ?? []) visit(child, depth + 1, host);
};
- for (const root of children.get(undefined) ?? []) visit(root, 0);
+ for (const root of children.get(undefined) ?? []) visit(root, 0, "?");
return rows;
}
-/** One span of the tree (see `rowsOf`). */
-function rowOf(span: StoredSpan, depth: number, start: number) {
+/** One span of the tree (see `rowsOf`), recorded on `host`. */
+function rowOf(span: StoredSpan, depth: number, host: string, start: number) {
const { status } = span;
return {
name: span.name,
depth,
- process: processOf(span),
+ host,
offsetMs: span.startedMs - start,
durationMs: span.endedMs - span.startedMs,
- attributes: pairs(span.attributes),
+ // Its host is shown as its tag.
+ attributes: pairs(span.attributes).filter((pair) => !pair.startsWith("chord.host=")),
events: span.events.map((event) => [event.name, ...pairs(event.attributes)].join(" ")),
// A reference to a span of another trace, shown and never followed.
links: span.links.map((link) => `trace ${link.traceId} span ${link.spanId}`),
@@ -105,11 +119,6 @@ function rowOf(span: StoredSpan, depth: number, start: number) {
};
}
-/** The recording process of `span`: the SQLite store's span ids are `:`, one recorder per process. */
-function processOf(span: StoredSpan): string {
- return span.id.slice(0, span.id.lastIndexOf(":"));
-}
-
/** Attributes as `key=value` texts, the values as JSON, fractions at two decimals (`duration=0.41`). */
function pairs(attributes: StoredSpan["attributes"]): string[] {
return Object.entries(attributes).map(([key, value]) => {
diff --git a/packages/chord/test/examples/61-tutorial/screenshots.ts b/packages/chord/test/examples/61-tutorial/screenshots.ts
index ead0ca851..d6f480cd2 100644
--- a/packages/chord/test/examples/61-tutorial/screenshots.ts
+++ b/packages/chord/test/examples/61-tutorial/screenshots.ts
@@ -1,18 +1,22 @@
// Screenshots of the tutorial's page (`docs/tutorial/screens/`), taken in headless Chromium: the page after the owner
// signed in with the owner link, the page in the Harbor theme added while it runs, the page after an edit of the
// lists plugin's web facet applied in place, the page after the owner chose French, with the list's notice, and the
-// owner's trace viewer showing a todo added from a page.
+// page before and after the owner adds honey (the page records its clicks), the trace viewer showing that click's
+// trace, then the traces for Ada.
// Run from packages/chord, with Chromium (`CHROMIUM_BIN`, else `chromium-docker` on the `PATH`):
// node --conditions=source --experimental-strip-types test/examples/61-tutorial/screenshots.ts docs/tutorial/screens
+
+import { execFile } from "node:child_process";
import { cp, mkdir, readFile, rm, writeFile } from "node:fs/promises";
import { join, resolve } from "node:path";
import { fileURLToPath } from "node:url";
-import { WebSocket } from "ws";
-import { BACKGROUND_CONTEXT as context, withTelemetry } from "../../../src/context/index.ts";
-import { createHost, LocaleChoice, type WebSocketLike, webSocketLink } from "../../../src/index.ts";
+import { promisify } from "node:util";
+import type { StoredTrace } from "@earendil-works/pi-telemetry";
+import { renderTrace } from "@earendil-works/pi-telemetry/render";
+import { BACKGROUND_CONTEXT as context } from "../../../src/context/index.ts";
+import { LocaleChoice } from "../../../src/index.ts";
import { Browser, CHROMIUM } from "../../node/web/browser.ts";
import { Todos } from "./plugins/lists/contract.ts";
-import type { TodoPrincipal } from "./src/principals.ts";
import { openTelemetry, telemetryFile } from "./src/telemetry.ts";
import { startTodo, todoDirectories } from "./start.ts";
@@ -115,36 +119,42 @@ try {
console.log(`after choosing French: lang="${lang}", ${JSON.stringify(french)} still typed`);
console.log("the page did not reload:", await browser.evaluate("window.marked === true"));
- // 5. Honey added from a page that records, and a blank todo refused (main.ts's step 11: a client host with a recorder
- // of its own, here signed in with the owner token), then the owner opens the trace viewer on honey's trace.
- const pageTelemetry = await openTelemetry(telemetryFile(dataDir));
- const page = createHost({ telemetry: pageTelemetry.store, onError: () => {} });
- await page.load([], context);
- const token = (await readFile(app.ownerTokenFile, "utf8")).trim();
- const origin = new URL(app.ownerLink()).origin;
- const socket = new WebSocket(`${origin.replace(/^http/, "ws")}/chord`, {
- headers: { authorization: `Bearer ${token}` },
- });
- page.connect(webSocketLink(socket as unknown as WebSocketLike), { principal: { kind: "server" } }, context);
- const todos = await page.get(Todos, { list: "groceries" }, context);
- const click = (text: string) =>
- pageTelemetry.store.startSpan({ name: "page.add" }, (span) => todos.add(text, withTelemetry(span, context)));
- await click("honey");
- await click("").catch(() => "refused");
- todos.release();
- await page.close(context);
- await pageTelemetry.close();
- // Each recorder writes what settled once a second: read until the worker's span of honey's add is there.
- const honey = async () => {
+ // 5. The page records (`startPage({ telemetry: true })`): the owner adds honey, then clicks again with nothing typed;
+ // each click is a trace of the page's, the call under it through the server's relay into the list's worker. The
+ // page sends its spans every few seconds, the worker every second, the server writes every second: read until the
+ // worker's span of each click is there, print honey's trace, read the store with `trace.ts`, then open the viewer.
+ await browser.evaluate("document.querySelector('.lists-panel input').select()");
+ await browser.type("honey");
+ await shoot("click-before.png");
+ const submit = "document.querySelector('.lists-panel form').requestSubmit()";
+ await browser.evaluate(submit);
+ await browser.wait(
+ "[...document.querySelectorAll('.lists-panel li')].some((item) => item.textContent.startsWith('honey'))",
+ );
+ await browser.evaluate("document.querySelector('.lists-panel input').blur()");
+ await shoot("click-after.png");
+ await browser.evaluate(submit);
+ const clicks = async () => {
await telemetry.store.flush();
- const [, trace] = (await telemetry.store.findTraces({ name: "page.add", limit: 2 })).traces;
- return trace?.spans.some(({ name }) => name === "todos.validate") ? trace : undefined;
+ const { traces } = await telemetry.store.findTraces({ name: "page.add", limit: 2 });
+ return traces.filter(({ spans }) => spans.some(({ name }) => name === "todos.validate"));
};
- let trace = await honey();
- while (trace === undefined) {
+ let traces = await clicks();
+ while (traces.length < 2) {
await new Promise((done) => setTimeout(done, 100));
- trace = await honey();
+ traces = await clicks();
}
+ const [refused, trace] = traces as [StoredTrace, StoredTrace];
+ console.log("adding honey from the page:");
+ printTelemetry(renderTrace(trace.spans));
+ const traceScript = fileURLToPath(new URL("./trace.ts", import.meta.url));
+ const read = async (...args: string[]) =>
+ (await promisify(execFile)(process.execPath, [...process.execArgv, traceScript, ...args])).stdout;
+ console.log("trace.ts --name page.add --principal owner:");
+ printTelemetry(await read(dataDir, "--name", "page.add", "--principal", "owner"));
+ console.log("trace.ts :");
+ printTelemetry(await read(dataDir, refused.traceId));
+ const origin = new URL(app.ownerLink()).origin;
await browser.call("Emulation.setDeviceMetricsOverride", {
width: 900,
height: 640,
@@ -158,9 +168,33 @@ try {
"new Set([...document.querySelectorAll('.traces-tree .traces-host')].map((tag) => tag.textContent)).size",
);
console.log(`the viewer shows page.add: 6 spans on ${hosts} hosts`);
+
+ // 6. The traces for Ada (`user:u1`, the app's `principalAttributes` names her): her todo of the start, a call of the
+ // server's root acting as her, recorded by the list's worker with her name.
+ await browser.evaluate("document.querySelector('.traces-filter').focus()");
+ await browser.type("user:u1");
+ await browser.wait("document.querySelector('.traces nav a small')?.textContent.includes('ada')");
+ await browser.evaluate("document.querySelector('.traces nav a').click()");
+ await browser.wait("document.querySelectorAll('.traces-tree li').length > 0");
+ await shoot("traces-ada.png");
+ const listed = await browser.evaluate(
+ "[...document.querySelectorAll('.traces nav a')].map((a) => a.querySelector('span').textContent + ' for ' + a.querySelectorAll('small')[0].textContent.split(' · ').at(-1))",
+ );
+ console.log(`the viewer for user:u1 lists ${[...new Set(listed)].join(", ")}`);
} finally {
await browser.close();
await app.close(context);
await telemetry.close();
await rm(base, { recursive: true, force: true });
}
+
+/** Prints telemetry indented, as the same text at every run: span ids, lengths of time and byte counts masked. */
+function printTelemetry(text: string): void {
+ const steady = text
+ .replaceAll(/browser:[0-9a-f-]{36}:\d+|[0-9a-f-]{36}:\d+/g, "")
+ .replaceAll(/ \(\+?[\d.]+ms\)/g, "")
+ .replaceAll(/duration=[\d.]+/g, "duration=")
+ .replaceAll(/ [\d.]+ ms/g, " ")
+ .replaceAll(/\d+ bytes in \d+ messages/g, " bytes in messages");
+ for (const line of steady.trim().split("\n")) console.log(` ${line}`);
+}
diff --git a/packages/chord/test/examples/61-tutorial/src/api/v1/server.ts b/packages/chord/test/examples/61-tutorial/src/api/v1/server.ts
index 43ec8e61c..c683695c0 100644
--- a/packages/chord/test/examples/61-tutorial/src/api/v1/server.ts
+++ b/packages/chord/test/examples/61-tutorial/src/api/v1/server.ts
@@ -1,6 +1,6 @@
// The todo app's API v1 for server facets (`@todo/app/v1/server`): the HTTP registry plugins add routes to, the kit's
-// pick-a-name login as a facet a one-line plugin exports, and the app's telemetry store (where it is, how a server
-// facet opens it to read) with the kit's `AppInfo`, which names the data directory.
+// pick-a-name login as a facet a one-line plugin exports, and the app's telemetry store (where it is, and Chord's
+// read-only store a server facet opens it with) with the kit's `AppInfo`, which names the data directory.
import { ephemeralLoginFacet } from "../../../../../../src/node/app/index.ts";
import type { TodoPrincipal } from "../../principals.ts";
@@ -8,7 +8,8 @@ import type { TodoPrincipal } from "../../principals.ts";
export type { StoredSpan, StoredTrace } from "@earendil-works/pi-telemetry";
export { AppInfo } from "../../../../../../src/node/app/index.ts";
export { Http } from "../../../../../../src/node/http/index.ts";
-export { openTelemetry, type TodoTelemetry, telemetryFile } from "../../telemetry.ts";
+export { openTelemetryStore } from "../../../../../../src/telemetry-sqlite/node.ts";
+export { telemetryFile } from "../../telemetry.ts";
/** The kit's ephemeral login: `POST /_chord/login { name }` signs in as `{ kind: "user", id, name }`. */
export const login = ephemeralLoginFacet();
diff --git a/packages/chord/test/examples/61-tutorial/src/api/v1/web.ts b/packages/chord/test/examples/61-tutorial/src/api/v1/web.ts
index c29d217e3..76237b36c 100644
--- a/packages/chord/test/examples/61-tutorial/src/api/v1/web.ts
+++ b/packages/chord/test/examples/61-tutorial/src/api/v1/web.ts
@@ -4,7 +4,7 @@
import type { ComponentType } from "react";
import { defineRegistry } from "../../../../../../src/index.ts";
-export { useHold, useMessages, usePageState, useWatch } from "../../../../../../src/react/index.ts";
+export { useHold, useHost, useMessages, usePageState, useWatch } from "../../../../../../src/react/index.ts";
/** A panel of the page: its name (a key, never shown) and its React component, which shows its own title. */
export type Panel = { readonly name: string; readonly Component: ComponentType };
diff --git a/packages/chord/test/examples/61-tutorial/src/principals.ts b/packages/chord/test/examples/61-tutorial/src/principals.ts
index e3844887e..2f39af99f 100644
--- a/packages/chord/test/examples/61-tutorial/src/principals.ts
+++ b/packages/chord/test/examples/61-tutorial/src/principals.ts
@@ -6,3 +6,23 @@ export type TodoPrincipal =
| { readonly kind: "worker"; readonly list: string }
| { readonly kind: "owner" }
| { readonly kind: "user"; readonly id: string; readonly name: string };
+
+/** The names the telemetry records, by principal: a principal crossing a link is one object per link, made once. */
+const recorded = new WeakMap>>();
+
+/**
+ * Who a span was for, as the app's telemetry records it (the hosts' `principalAttributes`): a short principal key, and
+ * a user's name, which the owner's trace viewer shows. Cheap and synchronous, as Chord calls it per recorded span; the
+ * cache is the hook's own.
+ */
+export function principalAttributes(principal: TodoPrincipal): Readonly> {
+ let attributes = recorded.get(principal);
+ if (attributes === undefined) {
+ attributes =
+ principal.kind === "user"
+ ? { "chord.principal": `user:${principal.id}`, "user.name": principal.name }
+ : { "chord.principal": principal.kind === "worker" ? `worker:${principal.list}` : principal.kind };
+ recorded.set(principal, attributes);
+ }
+ return attributes;
+}
diff --git a/packages/chord/test/examples/61-tutorial/src/telemetry.ts b/packages/chord/test/examples/61-tutorial/src/telemetry.ts
index e4e75e7c8..01b72c49a 100644
--- a/packages/chord/test/examples/61-tutorial/src/telemetry.ts
+++ b/packages/chord/test/examples/61-tutorial/src/telemetry.ts
@@ -1,6 +1,6 @@
-// The todo app's telemetry store: one SQLite file in the data directory, `telemetry.sqlite`. The server and every
-// list's worker record to it, each process with a recorder of its own on the shared file; readers (the trace viewer,
-// `trace.ts`) open it the same way and read through the store's read interface.
+// The todo app's telemetry store: one SQLite file in the data directory, `telemetry.sqlite`. The server is its only
+// writer: its own spans, and those every list's worker and every recording page send it; readers (the trace viewer,
+// `trace.ts`) open it read-only with Chord's `openTelemetryStore` and read through the store's read interface.
import { mkdir } from "node:fs/promises";
import { dirname, join } from "node:path";
diff --git a/packages/chord/test/examples/61-tutorial/src/web/main.ts b/packages/chord/test/examples/61-tutorial/src/web/main.ts
index 433fb3c6f..64fdf1816 100644
--- a/packages/chord/test/examples/61-tutorial/src/web/main.ts
+++ b/packages/chord/test/examples/61-tutorial/src/web/main.ts
@@ -33,5 +33,7 @@ void startPage({
connect: () => new WebSocket(`${location.origin.replace(/^http/, "ws")}/chord`),
modules: { "@todo/app/v1": v1, "@todo/app/v1/web": v1web, react: React, "react/jsx-runtime": jsx },
core: [{ name: "@todo/web", facet: core }],
+ // The page records its clicks and the calls under them, and sends them to the server every few seconds.
+ telemetry: true,
render: (host) => createRoot(document.getElementById("root")!).render(h(HostProvider, { host }, h(Page))),
});
diff --git a/packages/chord/test/examples/61-tutorial/src/web/style.css b/packages/chord/test/examples/61-tutorial/src/web/style.css
index 60f3aa857..48454ca26 100644
--- a/packages/chord/test/examples/61-tutorial/src/web/style.css
+++ b/packages/chord/test/examples/61-tutorial/src/web/style.css
@@ -4,12 +4,13 @@ main { max-width: 26rem; margin: 1.5rem auto; padding: 0 1rem; }
h1 { color: var(--accent); font-size: 1.4rem; margin: 0 0 1rem; }
h2 { font-size: 0.8rem; text-transform: uppercase; letter-spacing: 0.08em; color: var(--muted); }
-/* The trace viewer (`/traces`): the list beside the chosen trace's tree, a colour per process. */
+/* The trace viewer (`/traces`): the list (filtered by principal) beside the chosen trace's tree, a colour per host. */
main.wide { max-width: 60rem; }
.traces { display: grid; grid-template-columns: 13rem 1fr; gap: 1rem; align-items: start; }
.traces nav a { display: block; padding: 0.3rem 0.4rem; color: var(--fg); text-decoration: none; border-left: 2px solid transparent; }
.traces nav a.traces-chosen { border-left-color: var(--accent); background: color-mix(in srgb, var(--fg) 8%, transparent); }
.traces nav small { display: block; color: var(--muted); font-size: 0.75rem; }
+.traces-filter { width: 100%; box-sizing: border-box; margin-bottom: 0.5rem; background: transparent; color: var(--fg); border: 1px solid var(--muted); border-radius: 3px; padding: 0.2rem 0.4rem; }
.traces-tree { list-style: none; margin: 0; padding: 0; font-size: 0.8rem; }
.traces-tree li { padding: 0.25rem 0; border-bottom: 1px solid color-mix(in srgb, var(--muted) 30%, transparent); }
.traces-span { display: flex; gap: 0.5rem; align-items: baseline; }
diff --git a/packages/chord/test/examples/61-tutorial/src/web/traces.ts b/packages/chord/test/examples/61-tutorial/src/web/traces.ts
index 6a8ab0db7..96e376ad1 100644
--- a/packages/chord/test/examples/61-tutorial/src/web/traces.ts
+++ b/packages/chord/test/examples/61-tutorial/src/web/traces.ts
@@ -1,7 +1,8 @@
-// The owner's trace viewer, the page at `/traces`: the newest traces of the app's telemetry store and the one chosen
-// (its id in the URL's fragment) as a tree: each span with its host, its length as a bar on the trace's time line, its
-// attributes and events, its error marked, and its links as references to other traces, never followed. It reads the
-// traces plugin's JSON routes (`plugins/traces/server.ts`), which answer the owner only.
+// The owner's trace viewer, the page at `/traces`: the newest traces of the app's telemetry store (all, or those for
+// one principal: `user:u1`, `owner`), each with whom it was for, and the one chosen
+// (its id in the URL's fragment) as a tree: each span with its host (`chord.host`), its length as a bar on the trace's
+// time line, its attributes and events, its error marked, and its links as references to other traces, never
+// followed. It reads the traces plugin's JSON routes (`plugins/traces/server.ts`), which answer the owner only.
import { createElement as h, useEffect, useState } from "react";
@@ -10,8 +11,9 @@ type Summary = {
readonly id: string;
readonly name: string;
readonly detail: string;
+ readonly principal: string;
readonly spans: number;
- readonly processes: number;
+ readonly hosts: number;
readonly durationMs: number;
readonly error: boolean;
};
@@ -20,7 +22,7 @@ type Summary = {
type Row = {
readonly name: string;
readonly depth: number;
- readonly process: string;
+ readonly host: string;
readonly offsetMs: number;
readonly durationMs: number;
readonly attributes: readonly string[];
@@ -35,14 +37,18 @@ type Answer = { readonly kind: "ok"; readonly value: T } | { readonly kind: "
/** The viewer: the list, and the chosen trace's tree. */
export function TraceViewer() {
const [list, setList] = useState>();
+ const [principal, setPrincipal] = useState("");
const [chosen, setChosen] = useState(fragment);
const [trace, setTrace] = useState>();
useEffect(() => {
- void read("/api/traces").then(setList);
const follow = () => setChosen(fragment());
addEventListener("hashchange", follow);
return () => removeEventListener("hashchange", follow);
}, []);
+ useEffect(() => {
+ const query = principal === "" ? "" : `?principal=${encodeURIComponent(principal)}`;
+ void read(`/api/traces${query}`).then(setList);
+ }, [principal]);
useEffect(() => {
setTrace(undefined);
if (chosen === "") return;
@@ -56,6 +62,12 @@ export function TraceViewer() {
"nav",
null,
h("h2", null, "Traces"),
+ h("input", {
+ className: "traces-filter",
+ placeholder: "principal",
+ value: principal,
+ onChange: (event: { target: { value: string } }) => setPrincipal(event.target.value),
+ }),
...(list?.value ?? []).map((summary) =>
h(
"a",
@@ -65,11 +77,11 @@ export function TraceViewer() {
className: summary.id === chosen ? "traces-chosen" : undefined,
},
h("span", { className: summary.error ? "traces-error" : undefined }, summary.name),
- h("small", null, summary.detail),
+ h("small", null, [summary.detail, summary.principal].filter((part) => part !== "").join(" · ")),
h(
"small",
null,
- `${count(summary.spans, "span")} · ${count(summary.processes, "host")} · ${ms(summary.durationMs)}`,
+ `${count(summary.spans, "span")} · ${count(summary.hosts, "host")} · ${ms(summary.durationMs)}`,
),
),
),
@@ -78,19 +90,19 @@ export function TraceViewer() {
);
}
-/** One trace as a tree: a colour per host (the process that recorded the span), lengths on the trace's time line. */
+/** One trace as a tree: a colour per host (the host that recorded the span), lengths on the trace's time line. */
function Tree({ rows }: { readonly rows: readonly Row[] }) {
const total = Math.max(...rows.map((row) => row.offsetMs + row.durationMs));
- const hosts = [...new Set(rows.map((row) => row.process))];
+ const hosts = [...new Set(rows.map((row) => row.host))];
return h(
"ol",
{ className: "traces-tree" },
- ...rows.map((row, index) => h(Span, { key: index, row, host: hosts.indexOf(row.process), total })),
+ ...rows.map((row, index) => h(Span, { key: index, row, colour: hosts.indexOf(row.host), total })),
);
}
/** One span: its host, name and length, its bar, then its attributes, events, links and error. */
-function Span({ row, host, total }: { readonly row: Row; readonly host: number; readonly total: number }) {
+function Span({ row, colour, total }: { readonly row: Row; readonly colour: number; readonly total: number }) {
const indent = { paddingLeft: `${row.depth * 1.1}rem` };
// Inline styles are set through the DOM by React, which the page's CSP allows (it refuses style attributes in HTML).
const bar = {
@@ -103,14 +115,14 @@ function Span({ row, host, total }: { readonly row: Row; readonly host: number;
h(
"div",
{ className: "traces-span", style: indent },
- h("span", { className: `traces-host traces-host-${host % 4}` }, `host ${host + 1}`),
+ h("span", { className: `traces-host traces-host-${colour % 4}` }, row.host),
h("b", null, row.name),
h("span", { className: "traces-ms" }, ms(row.durationMs)),
),
h(
"div",
{ className: "traces-line" },
- h("span", { className: `traces-bar traces-host-${host % 4}`, style: bar }),
+ h("span", { className: `traces-bar traces-host-${colour % 4}`, style: bar }),
),
h(
"div",
diff --git a/packages/chord/test/examples/61-tutorial/start.ts b/packages/chord/test/examples/61-tutorial/start.ts
index 610070b5d..03315817d 100644
--- a/packages/chord/test/examples/61-tutorial/start.ts
+++ b/packages/chord/test/examples/61-tutorial/start.ts
@@ -1,7 +1,8 @@
// The todo app's start: what the app decides itself, given to the kit's `startServer`: its name and data directory,
// its API, its facet kinds, its principals, its one worker kind (a list), its page and its terminal client, and its
-// telemetry store (one SQLite file in the data directory, shared by the server and the workers). The kit does the rest. The examples call `startTodo` with a copy of `plugins/` they may edit; a real app's start script calls
-// it with the data directory from its command line and prints the owner link.
+// telemetry store (one SQLite file in the data directory, which the server writes for every process). The kit does the
+// rest. The examples call `startTodo` with a copy of `plugins/` they may edit; a real app's start script calls it with
+// the data directory from its command line and prints the owner link.
import { cp, mkdtemp } from "node:fs/promises";
import { tmpdir } from "node:os";
@@ -12,8 +13,8 @@ import * as v1server from "@todo/app/v1/server";
import type { Context } from "../../../src/context/index.ts";
import { type App, startServer } from "../../../src/node/app/index.ts";
import { type PageAssets, pageScripts } from "../../../src/node/surfaces/index.ts";
-import type { TodoPrincipal } from "./src/principals.ts";
-import { type TodoTelemetry, telemetryFile } from "./src/telemetry.ts";
+import { principalAttributes, type TodoPrincipal } from "./src/principals.ts";
+import type { TodoTelemetry } from "./src/telemetry.ts";
/** The app's API: its name, its versions (newest first), and this process's instances of its modules. */
export const API = {
@@ -54,14 +55,15 @@ export function startTodo(
api: API,
kinds: KINDS,
principal: { server: { kind: "server" }, worker: (address) => ({ kind: "worker", list: address.key }) },
- // The server's spans and metrics; each list's worker opens the same file (`worker.ts`).
+ // The store the server writes: its own spans and metrics, and what the workers and recording pages send.
telemetry: telemetry.store,
+ // Who a span was for: a short key and a user's name (each worker's `startWorker` gets the same hook).
+ principalAttributes,
workers: [
{
kind: v1.List,
entry: fileURLToPath(new URL("./worker.ts", import.meta.url)),
execArgv: ["--conditions=source", "--experimental-strip-types", "--no-warnings"],
- env: { TODO_TELEMETRY: telemetryFile(dataDir) },
start: () => ({}),
// Who may reach a list's worker: everyone signed in, and the server itself.
authorize: (principal) => principal.kind !== "worker",
diff --git a/packages/chord/test/examples/61-tutorial/trace.ts b/packages/chord/test/examples/61-tutorial/trace.ts
index 087c1755f..effee74a8 100644
--- a/packages/chord/test/examples/61-tutorial/trace.ts
+++ b/packages/chord/test/examples/61-tutorial/trace.ts
@@ -1,25 +1,34 @@
// The todo app's trace reader: a script reading the telemetry store of a data directory (`telemetry.sqlite`) through
// the store's read interface, while the app runs or after. Without a trace id it prints the newest traces (those whose
-// first span is `--name`, when given) and the bytes on the links; with one, that trace as the renderer prints it.
+// first span is `--name`, and with a span for `--principal`, when given) and the bytes on the links; with one, that
+// trace as the renderer prints it.
// Run from packages/chord:
-// node --conditions=source --experimental-strip-types test/examples/61-tutorial/trace.ts [--name ]
+// node --conditions=source --experimental-strip-types test/examples/61-tutorial/trace.ts [--name ] [--principal ]
// node --conditions=source --experimental-strip-types test/examples/61-tutorial/trace.ts
import { parseArgs } from "node:util";
import { renderTrace } from "@earendil-works/pi-telemetry/render";
-import { openTelemetry, telemetryFile } from "./src/telemetry.ts";
+import { openTelemetryStore } from "../../../src/telemetry-sqlite/node.ts";
+import { telemetryFile } from "./src/telemetry.ts";
-const { values, positionals } = parseArgs({ allowPositionals: true, options: { name: { type: "string" } } });
+const { values, positionals } = parseArgs({
+ allowPositionals: true,
+ options: { name: { type: "string" }, principal: { type: "string" } },
+});
const [dataDir, id] = positionals;
-if (dataDir === undefined) throw new Error("usage: trace.ts [--name ] []");
-// A recorder of this process on the shared file, which records nothing: the reads are what the script uses.
-const telemetry = await openTelemetry(telemetryFile(dataDir));
+if (dataDir === undefined) {
+ throw new Error("usage: trace.ts [--name ] [--principal ] []");
+}
+// The shared file, read-only: the app's processes may be writing it meanwhile.
+const store = await openTelemetryStore(telemetryFile(dataDir));
try {
if (id !== undefined) {
- const trace = await telemetry.store.getTrace(id);
+ const trace = await store.getTrace(id);
console.log(trace === undefined ? `no trace ${id}` : renderTrace(trace.spans));
} else {
- // Complete traces, newest first; a trace's first span (its root, by start time) names it.
- const { traces } = await telemetry.store.findTraces({ name: values.name, limit: 10 });
+ // Complete traces, newest first; a trace's first span (its root, by start time) names it, and the app's
+ // `principalAttributes` hook named whom each span was for.
+ const attributes = values.principal === undefined ? undefined : { "chord.principal": values.principal };
+ const { traces } = await store.findTraces({ name: values.name, attributes, limit: 10 });
for (const { traceId, spans } of traces) {
const start = Math.min(...spans.map((span) => span.startedMs));
const length = Math.max(...spans.map((span) => span.endedMs)) - start;
@@ -28,12 +37,12 @@ try {
}
// Metrics are stored per series and 10 s: a series is one set of attributes, here the direction.
for (const direction of ["sent", "received"]) {
- const rows = await telemetry.store.findMetrics({ name: "chord.link.bytes", attributes: { direction } });
+ const rows = await store.findMetrics({ name: "chord.link.bytes", attributes: { direction } });
const bytes = rows.reduce((sum, row) => sum + row.sum, 0);
const messages = rows.reduce((sum, row) => sum + row.count, 0);
console.log(`chord.link.bytes ${direction}: ${bytes} bytes in ${messages} messages`);
}
}
} finally {
- await telemetry.close();
+ await store.close();
}
diff --git a/packages/chord/test/examples/61-tutorial/worker.ts b/packages/chord/test/examples/61-tutorial/worker.ts
index 496dc3852..976625ee4 100644
--- a/packages/chord/test/examples/61-tutorial/worker.ts
+++ b/packages/chord/test/examples/61-tutorial/worker.ts
@@ -1,10 +1,9 @@
// The todo app's worker entry: one process per list. `startWorker` opens the list's store in its directory, connects
-// to the server and loads the plugins' worker facets. The worker records to the app's telemetry store, the file its
-// server named in the environment: its methods called through the server continue the caller's trace.
+// to the server and loads the plugins' worker facets. The worker records its spans in memory and sends them to the
+// server, which stores them: its methods called through the server continue the caller's trace.
import { startWorker } from "../../../src/node/app/index.ts";
-import { openTelemetry } from "./src/telemetry.ts";
+import { principalAttributes } from "./src/principals.ts";
import { API, KINDS } from "./start.ts";
-const telemetry = await openTelemetry(process.env.TODO_TELEMETRY!);
-startWorker({ api: API, kinds: KINDS, telemetry: telemetry.store, onError: (error) => console.error("list:", error) });
+startWorker({ api: API, kinds: KINDS, principalAttributes, onError: (error) => console.error("list:", error) });
diff --git a/packages/chord/test/examples/62-telemetry/main.ts b/packages/chord/test/examples/62-telemetry/main.ts
index ad2f16025..4248997aa 100644
--- a/packages/chord/test/examples/62-telemetry/main.ts
+++ b/packages/chord/test/examples/62-telemetry/main.ts
@@ -1,5 +1,5 @@
-// Telemetry across hosts (slice 9): a kit app (`start.ts`) whose server and tally workers record to one SQLite
-// telemetry store in the data directory. The owner's client host calls a tally's counter: the call goes from the client
+// Telemetry across hosts (slice 9): a kit app (`start.ts`) whose server records to a SQLite telemetry store in the
+// data directory, and whose tally workers send what they record to the server. The owner's client host calls a tally's counter: the call goes from the client
// over the server's relay into the worker's method, which checks its argument in a span of its own (`ctx.trace`) and
// commits through a local store object. Each host starts its spans with its own adapter; the carriers on the wire make
// them one trace. The example prints that trace as the store renders it, and a metric the server recorded.
@@ -18,7 +18,7 @@ import { openTelemetry, startTally, telemetryFile } from "./start.ts";
const dataDir = join(await mkdtemp(join(tmpdir(), "tally-")), "data");
-// 1. The server records to the store in its data directory; each tally's worker opens the same file.
+// 1. The server records to the store in its data directory; each tally's worker sends its spans to the server.
await mkdir(dataDir, { mode: 0o700 });
const telemetry = await openTelemetry(telemetryFile(dataDir));
const app = await startTally(dataDir, telemetry, context);
@@ -42,11 +42,17 @@ const total = await telemetry.startSpan({ name: "tally.click" }, async (span) =>
});
console.log("3. the tally's total:", total);
-// 4. Each process flushes its settled spans every second: wait for the worker's, flush the server's, then read the
-// trace back from the store (the newest trace whose first span is the click).
-await new Promise((resolve) => setTimeout(resolve, 1_500));
-await telemetry.flush();
-const { traces } = await telemetry.findTraces({ name: "tally.click", limit: 1 });
+// 4. A worker sends its settled spans every second, the server writes every second: read until the worker's method is
+// in the click's trace (the newest trace whose first span is the click).
+const clicked = async () => {
+ await telemetry.flush();
+ return (await telemetry.findTraces({ name: "tally.click", limit: 1 })).traces;
+};
+let traces = await clicked();
+while (!traces[0]?.spans.some(({ name }) => name === "tally.check")) {
+ await new Promise((resolve) => setTimeout(resolve, 100));
+ traces = await clicked();
+}
console.log("4. the trace across the client, the server and the worker (links name the root span they point to):");
// The roots a trace links to (the worker's start, an object's activation) are traces of their own: named here.
const names = new Map();
diff --git a/packages/chord/test/examples/62-telemetry/start.ts b/packages/chord/test/examples/62-telemetry/start.ts
index 1c41f73a5..6028a9ded 100644
--- a/packages/chord/test/examples/62-telemetry/start.ts
+++ b/packages/chord/test/examples/62-telemetry/start.ts
@@ -1,6 +1,5 @@
-// The tally app's start: `startServer` with the app's telemetry adapter, a SQLite telemetry store in the data
-// directory. Each process records to the store it is given: here every process opens the same file (`telemetry.sqlite`
-// in the data directory; its workers get the path in their environment), so one trace reads tab → server → worker.
+// The tally app's start: `startServer` with the app's telemetry store, a SQLite file in the data directory. The server
+// is its only writer: each worker sends what it records to the server, so one trace reads tab → server → worker.
import { join } from "node:path";
import { fileURLToPath } from "node:url";
@@ -22,7 +21,7 @@ export function telemetryFile(dataDir: string): string {
return join(dataDir, "telemetry.sqlite");
}
-/** Opens the SQLite telemetry store at `path` (each process its own recorder on the shared file). */
+/** Opens the SQLite telemetry store at `path` (the server's). */
export async function openTelemetry(path: string): Promise {
return createSqliteTelemetry(await openNodeSqliteDatabase(path));
}
@@ -48,7 +47,6 @@ export function startTally(
kind: v1.Tally,
entry: fileURLToPath(new URL("./worker.ts", import.meta.url)),
execArgv: ["--conditions=source", "--experimental-strip-types", "--no-warnings"],
- env: { TALLY_TELEMETRY: telemetryFile(dataDir) },
start: () => ({}),
// The owner reaches a tally through the server, which relays.
authorize: (principal) => principal.kind === "owner" || principal.kind === "server",
diff --git a/packages/chord/test/examples/62-telemetry/worker.ts b/packages/chord/test/examples/62-telemetry/worker.ts
index c00f2b6e2..94138ffff 100644
--- a/packages/chord/test/examples/62-telemetry/worker.ts
+++ b/packages/chord/test/examples/62-telemetry/worker.ts
@@ -1,9 +1,8 @@
-// The tally app's worker entry: one process per tally, recording to the app's telemetry store (the file its server
-// named in the environment). Its methods called through the server continue the caller's trace: the carrier travels on
-// the wire.
+// The tally app's worker entry: one process per tally. It records in memory and sends its spans and metrics to the
+// server, which stores them (the kit does it when the server has a telemetry store). Its methods called through the
+// server continue the caller's trace: the carrier travels on the wire.
import { startWorker } from "../../../src/node/app/index.ts";
-import { API, KINDS, openTelemetry } from "./start.ts";
+import { API, KINDS } from "./start.ts";
-const telemetry = await openTelemetry(process.env.TALLY_TELEMETRY!);
-startWorker({ api: API, kinds: KINDS, telemetry, onError: (error) => console.error("worker:", error) });
+startWorker({ api: API, kinds: KINDS, onError: (error) => console.error("worker:", error) });
diff --git a/packages/chord/test/host/ctx.test.ts b/packages/chord/test/host/ctx.test.ts
index d9307f326..2d700c499 100644
--- a/packages/chord/test/host/ctx.test.ts
+++ b/packages/chord/test/host/ctx.test.ts
@@ -259,7 +259,7 @@ describe("ctx.trace (C11, slice 9)", () => {
const spans = telemetry.getSpans();
const byName = (name: string) => spans.find((span) => span.name === name)!;
expect(byName("app.step").parentId).toBe(byName("chord.method").id);
- expect(byName("app.step").attributes).toEqual({ n: 1 });
+ expect(byName("app.step").attributes).toEqual({ "chord.host": "client", n: 1 });
expect(byName("app.deeper").parentId).toBe(byName("app.step").id);
expect(seen.inner).not.toBe(seen.outer);
expect(seen.inner!.principal).toBe(seen.outer!.principal);
diff --git a/packages/chord/test/host/facet.test.ts b/packages/chord/test/host/facet.test.ts
index 539ffd77b..1031f852a 100644
--- a/packages/chord/test/host/facet.test.ts
+++ b/packages/chord/test/host/facet.test.ts
@@ -1,7 +1,15 @@
+import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, expectTypeOf, it } from "vitest";
-import { BACKGROUND_CONTEXT as context } from "../../src/context/index.ts";
-import { int, local } from "../../src/contracts/index.ts";
-import { defineFacet, type Facet, type FacetHost, type FacetSelf, type Host } from "../../src/host/index.ts";
+import { BACKGROUND_CONTEXT as context, withTelemetry } from "../../src/context/index.ts";
+import { int, local, method } from "../../src/contracts/index.ts";
+import {
+ createHost,
+ defineFacet,
+ type Facet,
+ type FacetHost,
+ type FacetSelf,
+ type Host,
+} from "../../src/host/index.ts";
import { defineRegistry } from "../../src/registries/index.ts";
import { constant } from "../../src/state/index.ts";
import { loaded } from "../support.ts";
@@ -63,3 +71,29 @@ describe("facets", () => {
expectTypeOf>().not.toExtend>();
});
});
+
+describe("serve options", () => {
+ it("starts no method span for a type served `untraced`", async () => {
+ const Quiet = local("app.quiet", { version: 1, params: {}, members: { ping: method() } });
+ const Loud = local("app.loud", { version: 1, params: {}, members: { ping: method() } });
+ const telemetry = new InMemoryTelemetryContext();
+ const host = createHost({ telemetry, onError: () => {} });
+ const facet = defineFacet((h) => {
+ h.serve(Quiet, () => ({ ping: async () => null }), { untraced: true });
+ h.serve(Loud, () => ({ ping: async () => null }));
+ });
+ await host.load([{ name: "@test/app", facet }], context);
+ const [quiet, loud] = [await host.get(Quiet, {}, context), await host.get(Loud, {}, context)];
+ await telemetry.startSpan({ name: "work" }, async (span) => {
+ const traced = withTelemetry(span, context);
+ await quiet.ping(traced);
+ await loud.ping(traced);
+ });
+ expect(
+ telemetry
+ .getSpans()
+ .filter(({ name }) => name === "chord.method")
+ .map(({ attributes }) => attributes.type),
+ ).toEqual(["app.loud"]);
+ });
+});
diff --git a/packages/chord/test/host/host.test.ts b/packages/chord/test/host/host.test.ts
index 010712aa9..6c968aaf5 100644
--- a/packages/chord/test/host/host.test.ts
+++ b/packages/chord/test/host/host.test.ts
@@ -1,4 +1,4 @@
-import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
+import { InMemoryTelemetryContext, type SpanAttributes } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
import { BACKGROUND_CONTEXT as context, withAbortSignal, withCancel, withTelemetry } from "../../src/context/index.ts";
import { evolve, hostKind, int, local, method, obj, remote, str } from "../../src/contracts/index.ts";
@@ -1674,6 +1674,50 @@ describe("reload: an abort while staging (fix round 1)", () => {
});
});
+describe("who a span was for (principalAttributes)", () => {
+ const Echo = local("app.echo", { version: 1, params: {}, members: { echo: method(str(), str()) } });
+
+ /** A host acting as `{ kind: "user", id: "u1", name: "Ada" }` serving `Echo`, recording to `telemetry`. */
+ async function host(
+ telemetry: InMemoryTelemetryContext,
+ principalAttributes?: (p: { kind: string }) => Readonly,
+ ) {
+ const made = createHost({
+ principal: { kind: "user", id: "u1", name: "Ada" },
+ telemetry,
+ ...(principalAttributes === undefined ? {} : { principalAttributes }),
+ onError: () => {},
+ });
+ await made.load(
+ [{ name: "@test/echo", facet: defineFacet((h) => h.serve(Echo, () => ({ echo: async (text) => text }))) }],
+ context,
+ );
+ const echo = await made.get(Echo, {}, context);
+ await telemetry.startSpan({ name: "work" }, (span) => echo.echo("hi", withTelemetry(span, context)));
+ return telemetry.getSpans().find(({ name }) => name === "chord.method")!.attributes;
+ }
+
+ it("records a method's principal key as `chord.principal` by default", async () => {
+ expect(await host(new InMemoryTelemetryContext())).toMatchObject({
+ "chord.principal": '{"id":"u1","kind":"user","name":"Ada"}',
+ });
+ });
+
+ it("records the hook's attributes in its place, the hook called per recorded span only", 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);
+ 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);
+ });
+});
+
describe("the host's spans (slice 9)", () => {
it("traces load under its caller's span: plugins given and left out; host-lifetime activations link to it", async () => {
const telemetry = new InMemoryTelemetryContext();
@@ -1694,7 +1738,7 @@ describe("the host's spans (slice 9)", () => {
const spans = telemetry.getSpans();
const load = spans.find(({ name }) => name === "chord.load")!;
expect(load.parentId).toBe(spans.find(({ name }) => name === "start")!.id);
- expect(load.attributes).toEqual({ plugins: 2, failed: 1 });
+ expect(load.attributes).toEqual({ "chord.host": "client", plugins: 2, failed: 1 });
const activation = spans.find(({ name }) => name === "chord.activate")!;
expect(activation.links.map(({ context: carrier }) => carrier)).toEqual([load.context]);
});
@@ -1708,7 +1752,15 @@ describe("the host's spans (slice 9)", () => {
host.reload([{ name: "@test/app", facet: facet("b") }], withTelemetry(span, context)),
);
const reload = telemetry.getSpans().find(({ name }) => name === "chord.reload")!;
- expect(reload.attributes).toEqual({ plugins: 1, added: 0, changed: 1, removed: 0, failed: 0, fates: 1 });
+ expect(reload.attributes).toEqual({
+ "chord.host": "client",
+ plugins: 1,
+ added: 0,
+ changed: 1,
+ removed: 0,
+ failed: 0,
+ fates: 1,
+ });
expect(reload.events).toEqual([
{ name: "chord.reload.fate", attributes: { object: "app.info", fate: "swapped" } },
]);
@@ -1741,7 +1793,7 @@ describe("the host's spans (slice 9)", () => {
host.accept(a, { principal: { kind: "guest", session: "S1" } }, context);
await telemetry.startSpan({ name: "admin" }, (span) => host.revoke("S1", withTelemetry(span, context)));
const revoke = telemetry.getSpans().find(({ name }) => name === "chord.revoke")!;
- expect(revoke.attributes).toEqual({ count: 1 });
+ expect(revoke.attributes).toEqual({ "chord.host": "server", count: 1 });
host.revoke("S1", context);
expect(telemetry.getSpans().filter(({ name }) => name === "chord.revoke")).toHaveLength(1);
});
diff --git a/packages/chord/test/host/native.test.ts b/packages/chord/test/host/native.test.ts
index 08cee0b09..09aa909ea 100644
--- a/packages/chord/test/host/native.test.ts
+++ b/packages/chord/test/host/native.test.ts
@@ -279,7 +279,10 @@ describe("spans (slice 9)", () => {
expect(opens[1]!.status).toEqual({ status: "error", error: { name: "open_failed", message: "no socket" } });
expect(spans.find(({ name }) => name === "app.connect")!.parentId).toBe(opens[0]!.id);
const close = spans.find(({ name }) => name === "chord.close")!;
- expect([close.parentId, close.attributes]).toEqual([null, { type: "app.res", native: 1, reason: "end" }]);
+ expect([close.parentId, close.attributes]).toEqual([
+ null,
+ { "chord.host": "client", type: "app.res", native: 1, reason: "end" },
+ ]);
await host.close(context);
});
diff --git a/packages/chord/test/host/root.test.ts b/packages/chord/test/host/root.test.ts
index 34ecbf77a..24a9d117c 100644
--- a/packages/chord/test/host/root.test.ts
+++ b/packages/chord/test/host/root.test.ts
@@ -1,4 +1,5 @@
import { getEventListeners } from "node:events";
+import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it } from "vitest";
import { BACKGROUND_CONTEXT as context, withAbortSignal, withCancel } from "../../src/context/index.ts";
import { hostKind, int, local, method, remote, str } from "../../src/contracts/index.ts";
@@ -206,3 +207,43 @@ describe("host.root", () => {
await host.close(context);
});
});
+
+describe("host.root's trace", () => {
+ it("runs fn in a new root span of the host's adapter, with its host and attributes; a throw fails it", async () => {
+ const telemetry = new InMemoryTelemetryContext();
+ const host = createHost({ telemetry, onError: () => {} });
+ await host.load([], context);
+ const seen = await host.root(async (ctx) => ctx.telemetry, context, {
+ trace: { name: "page.add", attributes: { n: 1 } },
+ });
+ const error = await host
+ .root(
+ async () => {
+ throw new Error("refused");
+ },
+ context,
+ { trace: { name: "page.add" } },
+ )
+ .catch((thrown: unknown) => thrown);
+ expect(error).toBeInstanceOf(Error);
+ const spans = telemetry.getSpans();
+ expect(spans.map(({ name, parentId, attributes, status }) => [name, parentId, attributes, status])).toEqual([
+ ["page.add", null, { "chord.host": "client", n: 1 }, { status: "ok" }],
+ [
+ "page.add",
+ null,
+ { "chord.host": "client" },
+ { status: "error", error: { name: "trace_failed", message: "refused" } },
+ ],
+ ]);
+ expect(telemetry.inject(seen)).toEqual(spans[0]!.context);
+ });
+
+ it("starts nothing without an adapter that records", async () => {
+ const host = createHost({ onError: () => {} });
+ await host.load([], context);
+ expect(
+ await host.root(async (ctx) => ctx.telemetry === context.telemetry, context, { trace: { name: "x" } }),
+ ).toBe(true);
+ });
+});
diff --git a/packages/chord/test/host/route.test.ts b/packages/chord/test/host/route.test.ts
index 653b290e4..87fcbd7f7 100644
--- a/packages/chord/test/host/route.test.ts
+++ b/packages/chord/test/host/route.test.ts
@@ -512,7 +512,12 @@ describe("resolve spans (slice 9)", () => {
const resolve = spans.find(({ name }) => name === "chord.resolve")!;
const relay = spans.find(({ name }) => name === "chord.relay")!;
expect(resolve.parentId).toBeNull();
- expect(resolve.attributes).toEqual({ kind: "session", address: "session|S1", outcome: "failed" });
+ expect(resolve.attributes).toEqual({
+ "chord.host": "server",
+ kind: "session",
+ address: "session|S1",
+ outcome: "failed",
+ });
expect(resolve.status).toEqual({ status: "error", error: { name: "resolve_failed", message: "no worker" } });
expect(resolve.links.map(({ context: carrier }) => carrier)).toEqual([relay.context]);
expect(relay.links.map(({ context: carrier }) => carrier)).toEqual([resolve.context]);
diff --git a/packages/chord/test/host/routines.test.ts b/packages/chord/test/host/routines.test.ts
index 9cde37825..c9bf05c63 100644
--- a/packages/chord/test/host/routines.test.ts
+++ b/packages/chord/test/host/routines.test.ts
@@ -1179,7 +1179,14 @@ describe("routine spans (slice 9)", () => {
const live = routines.find(({ attributes }) => attributes.routine === "onLive")!;
expect([live.parentId, live.attributes]).toEqual([
null,
- { type: "app.store", object: "app.store", routine: "onLive", position: 1, outcome: "ok" },
+ {
+ "chord.host": "client",
+ type: "app.store",
+ object: "app.store",
+ routine: "onLive",
+ position: 1,
+ outcome: "ok",
+ },
]);
expect(live.events.map(({ name }) => name)).toEqual(["chord.commit"]);
const ons = routines.filter(({ attributes }) => attributes.routine === "on");
diff --git a/packages/chord/test/jobs/job.test.ts b/packages/chord/test/jobs/job.test.ts
index ddcbfadb2..d8aa5047a 100644
--- a/packages/chord/test/jobs/job.test.ts
+++ b/packages/chord/test/jobs/job.test.ts
@@ -1419,8 +1419,22 @@ describe("phase spans (slice 9)", () => {
const [intent, ran, finish] = spans.filter(({ name }) => name === "chord.job");
expect([intent!.parentId, ran!.parentId, finish!.parentId]).toEqual([request.id, intent!.id, intent!.id]);
expect([ran!.attributes, finish!.attributes]).toEqual([
- { job: "app.echo", phase: "run", object: "app.store", "job.id": run.id, outcome: "ok" },
- { job: "app.echo", phase: "finish", object: "app.store", "job.id": run.id, outcome: "ok" },
+ {
+ "chord.host": "client",
+ job: "app.echo",
+ phase: "run",
+ object: "app.store",
+ "job.id": run.id,
+ outcome: "ok",
+ },
+ {
+ "chord.host": "client",
+ job: "app.echo",
+ phase: "finish",
+ object: "app.store",
+ "job.id": run.id,
+ outcome: "ok",
+ },
]);
expect(finish!.events.map(({ name, attributes }) => [name, attributes])).toEqual([
["chord.retry", { backoff: 1_000 }],
diff --git a/packages/chord/test/jobs/persisted.test.ts b/packages/chord/test/jobs/persisted.test.ts
index 101a88391..ee24bc7b6 100644
--- a/packages/chord/test/jobs/persisted.test.ts
+++ b/packages/chord/test/jobs/persisted.test.ts
@@ -304,7 +304,14 @@ describe("trace (slice 9)", () => {
const phases = spans.filter(({ name }) => name === "chord.job");
const [intent] = phases;
expect([intent!.attributes, intent!.parentId]).toEqual([
- { job: "notes.import", phase: "intent", object: "notes.store", outcome: "ok", "job.id": run.id },
+ {
+ "chord.host": "client",
+ job: "notes.import",
+ phase: "intent",
+ object: "notes.store",
+ outcome: "ok",
+ "job.id": run.id,
+ },
request.id,
]);
// The run cut off by the crash (never settled), the rerun and the finish: one trace, children of the intent.
@@ -435,8 +442,8 @@ describe("a seal during the reservation (review regressions)", () => {
first = false;
const holding = {
admit: () => fence.admit(),
- adopt: (seq: number, ids: readonly number[]) => {
- fence.adopt(seq, ids);
+ adopt: (seq: number, ids: readonly number[], rows: number) => {
+ fence.adopt(seq, ids, rows);
void jobs.store.take(() => {}).then(held.resolve);
},
};
diff --git a/packages/chord/test/node/fixtures/web/telemetry.ts b/packages/chord/test/node/fixtures/web/telemetry.ts
new file mode 100644
index 000000000..a7390d8f8
--- /dev/null
+++ b/packages/chord/test/node/fixtures/web/telemetry.ts
@@ -0,0 +1,53 @@
+// The web entry of the page telemetry test (the base bundle): `startPage` recording (`telemetry: true`), and a button
+// whose click writes a project's note on its worker in a root span of the page (`host.root`'s `trace`), so the trace
+// runs page → server → worker.
+
+import { BACKGROUND_CONTEXT } from "../../../../src/context/index.ts";
+import * as chord from "../../../../src/index.ts";
+import { startPage } from "../../../../src/web/index.ts";
+import * as webApi from "./api.ts";
+
+const { hostKind, method, remote, str, unknown, int } = chord;
+
+/** The notes plugin's contract (`NOTES_PLUGIN` of the app tests), declared again: contracts are data. */
+const Notes = remote("test.notes", {
+ version: 1,
+ params: { id: str() },
+ hostAddress: ({ id }) => hostKind("project", { id: str() })({ id }),
+ variants: {
+ main: {
+ state: { text: str(), start: unknown() },
+ methods: {
+ write: method(str()),
+ visit: method(str(), int()),
+ attach: method(str(), str()),
+ file: method(str(), str()),
+ },
+ },
+ },
+});
+
+/** What the test reads from the page. */
+const probe = globalThis as unknown as { written?: number };
+
+void startPage({
+ connect: () => new WebSocket(`${location.origin.replace(/^http/, "ws")}/chord`),
+ modules: { "@test/app/v1": chord, "@test/app/v1/web": webApi },
+ telemetry: true,
+ render: (host) => {
+ const notes = host.hold(Notes, { id: "p1" }, BACKGROUND_CONTEXT);
+ const button = document.createElement("button");
+ button.id = "write";
+ button.textContent = "write";
+ button.addEventListener("click", () => {
+ void host
+ .root((ctx) => notes.write("from the page", ctx), BACKGROUND_CONTEXT, { trace: { name: "page.write" } })
+ .then(() => {
+ probe.written = (probe.written ?? 0) + 1;
+ });
+ });
+ const panels = document.createElement("div");
+ panels.id = "panels";
+ document.getElementById("root")!.append(panels, button);
+ },
+});
diff --git a/packages/chord/test/node/http/http.test.ts b/packages/chord/test/node/http/http.test.ts
index 9c1c6bb08..1336a1a8e 100644
--- a/packages/chord/test/node/http/http.test.ts
+++ b/packages/chord/test/node/http/http.test.ts
@@ -992,8 +992,8 @@ describe("request spans (slice 9)", () => {
await server.close();
const requests = telemetry.getSpans().filter(({ name }) => name === "chord.http");
expect(requests.map(({ attributes, parentId, status }) => [attributes, parentId, status.status])).toEqual([
- [{ method: "GET", route: "GET /items/:id", status: 200 }, null, "ok"],
- [{ method: "GET", route: "GET /broken", status: 500 }, null, "error"],
+ [{ "chord.host": "client", method: "GET", route: "GET /items/:id", status: 200 }, null, "ok"],
+ [{ "chord.host": "client", method: "GET", route: "GET /broken", status: 500 }, null, "error"],
]);
expect(JSON.stringify(telemetry.getSpans())).not.toContain("secret-id");
const lookup = telemetry.getSpans().find(({ name }) => name === "app.lookup")!;
diff --git a/packages/chord/test/node/web/page.test.ts b/packages/chord/test/node/web/page.test.ts
index 468af5a3a..3c95b326a 100644
--- a/packages/chord/test/node/web/page.test.ts
+++ b/packages/chord/test/node/web/page.test.ts
@@ -4,9 +4,14 @@
import { writeFile } from "node:fs/promises";
import { join } from "node:path";
+import { fileURLToPath } from "node:url";
+import { renderTrace } from "@earendil-works/pi-telemetry/render";
import { afterAll, beforeAll, describe, expect, it } from "vitest";
import { BACKGROUND_CONTEXT as context } from "../../../src/context/index.ts";
-import { Browser, CHROMIUM } from "./browser.ts";
+import { openNodeSqliteDatabase } from "../../../src/sqlite/node.ts";
+import { createSqliteTelemetry } from "../../../src/telemetry-sqlite/index.ts";
+import { NOTES_PLUGIN, tempDir } from "../app/support.ts";
+import { Browser, CHROMIUM, poll } from "./browser.ts";
import { freePort, panelPlugin, signIn, versionedEntry, webApp } from "./support.ts";
describe.skipIf(CHROMIUM === undefined)("a page", () => {
@@ -80,4 +85,47 @@ describe.skipIf(CHROMIUM === undefined)("a page", () => {
await second.app.close(context);
}
}, 120_000);
+
+ it("records a click as the root of one trace through the server into the worker, stored by the server", async () => {
+ const telemetry = await createSqliteTelemetry(await openNodeSqliteDatabase(join(await tempDir(), "t.sqlite")));
+ const entry = fileURLToPath(new URL("../fixtures/web/telemetry.ts", import.meta.url));
+ const { app } = await webApp(entry, await freePort(), {
+ plugins: { notes: NOTES_PLUGIN },
+ withWorkers: true,
+ telemetry,
+ });
+ try {
+ await signIn(browser, app.ownerLink());
+ await browser.evaluate("document.getElementById('write').click()");
+ await browser.wait("globalThis.written === 1");
+ // The page sends every few seconds, the worker every second, the server writes every second.
+ let spans: Awaited>["traces"][number]["spans"] = [];
+ await poll(
+ async () => {
+ await telemetry.flush();
+ spans = (await telemetry.findTraces({ name: "page.write" })).traces[0]?.spans ?? [];
+ return spans.some(({ attributes }) => attributes.type === "test.store");
+ },
+ 30_000,
+ "the click's trace",
+ );
+ const tree = renderTrace(
+ spans.map((span) => ({ ...span, attributes: { host: span.attributes["chord.host"] ?? "?" } })),
+ ).replaceAll(/ \(\+?[\d.]+ms\)/g, "");
+ expect(tree.split("\n").filter((line) => !line.includes("·"))).toEqual([
+ 'page.write host="browser"',
+ ' chord.call host="browser"',
+ ' chord.relay host="server"',
+ ' chord.method host="project|p1"',
+ ' chord.method host="project|p1"',
+ ]);
+ const [click] = spans;
+ expect(click!.id).toMatch(/^browser:[0-9a-f-]{36}:\d+$/);
+ expect(click!.attributes["chord.principal"]).toBe('{"kind":"owner"}');
+ expect(new Set(spans.map(({ traceId }) => traceId))).toEqual(new Set([click!.id]));
+ } finally {
+ await app.close(context);
+ await telemetry.close();
+ }
+ }, 120_000);
});
diff --git a/packages/chord/test/node/web/support.ts b/packages/chord/test/node/web/support.ts
index 0ae6ede63..939a9b1b7 100644
--- a/packages/chord/test/node/web/support.ts
+++ b/packages/chord/test/node/web/support.ts
@@ -6,8 +6,9 @@ import { writeFile } from "node:fs/promises";
import { createServer } from "node:net";
import { join } from "node:path";
import { fileURLToPath } from "node:url";
+import type { AppOptions } from "../../../src/node/app/index.ts";
import { pageScripts } from "../../../src/node/surfaces/index.ts";
-import { tempDir, testApp } from "../app/support.ts";
+import { type TestPrincipal, tempDir, testApp } from "../app/support.ts";
import type { Browser } from "./browser.ts";
/** The fixture's web entry. */
@@ -58,6 +59,8 @@ export function webApp(
readonly dataDir?: string;
readonly root?: string;
readonly plugins?: Record>;
+ readonly withWorkers?: boolean;
+ readonly telemetry?: AppOptions["telemetry"];
} = {},
) {
return testApp({
diff --git a/packages/chord/test/remote/provider.test.ts b/packages/chord/test/remote/provider.test.ts
index dbb529b5c..64dd630f5 100644
--- a/packages/chord/test/remote/provider.test.ts
+++ b/packages/chord/test/remote/provider.test.ts
@@ -1050,10 +1050,12 @@ describe("telemetry at the provider (slice 9)", () => {
);
expect(methods.map(({ parentId }) => parentId)).toEqual([caller.id, null, null]);
expect(methods[0]!.attributes).toEqual({
+ "chord.host": "server",
type: "app.notes",
member: "add",
object: "app.notes(S1)",
"principal.kind": "owner",
+ "chord.principal": '{"kind":"owner"}',
outcome: "ok",
});
});
diff --git a/packages/chord/test/remote/remote-object.test.ts b/packages/chord/test/remote/remote-object.test.ts
index 8c18e6792..da62c7e4e 100644
--- a/packages/chord/test/remote/remote-object.test.ts
+++ b/packages/chord/test/remote/remote-object.test.ts
@@ -870,6 +870,7 @@ describe("consumer spans (slice 9)", () => {
expect(held.trace).toEqual(hold.context);
expect(call.trace).toEqual(chordCall.context);
expect(hold.attributes).toEqual({
+ "chord.host": "client",
type: "app.notes",
object: "app.notes(S1)",
"address.kind": "server",
diff --git a/packages/chord/test/sqlite/node.test.ts b/packages/chord/test/sqlite/node.test.ts
index 8666b3f5d..21523defa 100644
--- a/packages/chord/test/sqlite/node.test.ts
+++ b/packages/chord/test/sqlite/node.test.ts
@@ -1,3 +1,6 @@
+import { mkdtempSync, rmSync } from "node:fs";
+import { tmpdir } from "node:os";
+import { join } from "node:path";
import { DatabaseSync } from "node:sqlite";
import { describe, expect, it, vi } from "vitest";
import type { SqliteExecutor } from "../../src/sqlite/index.ts";
@@ -199,6 +202,37 @@ describe("Node SQLite driver", () => {
});
});
+describe("read-only connections", () => {
+ it("read a file another connection writes, in deferred transactions, and never write it", async () => {
+ const dir = mkdtempSync(join(tmpdir(), "chord-sqlite-"));
+ const file = join(dir, "data.sqlite");
+ try {
+ const writer = await openNodeSqliteDatabase(file);
+ await writer.exec("CREATE TABLE probe (value INTEGER)");
+ await writer.run("INSERT INTO probe VALUES (1)");
+ const reader = await openNodeSqliteDatabase(file, { mode: "read-only" });
+ const exec = vi.spyOn(DatabaseSync.prototype, "exec");
+ // One snapshot per transaction: a write committed meanwhile shows in the next one.
+ expect(
+ await reader.transaction(async (tx) => {
+ const before = await tx.all("SELECT value FROM probe");
+ await writer.run("INSERT INTO probe VALUES (2)");
+ return [before, await tx.all("SELECT value FROM probe")];
+ }),
+ ).toEqual([[{ value: 1 }], [{ value: 1 }]]);
+ expect(exec.mock.calls.map(([sql]) => sql)).toEqual(["BEGIN", "COMMIT"]);
+ expect(await reader.all("SELECT value FROM probe")).toEqual([{ value: 1 }, { value: 2 }]);
+ await expect(reader.run("INSERT INTO probe VALUES (3)")).rejects.toThrow(/readonly/);
+ exec.mockRestore();
+ await reader.close();
+ await writer.close();
+ await expect(openNodeSqliteDatabase(join(dir, "missing.sqlite"), { mode: "read-only" })).rejects.toThrow();
+ } finally {
+ rmSync(dir, { recursive: true, force: true });
+ }
+ });
+});
+
describe("the outcome of a transaction (slice 6b D4)", () => {
/** A facade on `:memory:` whose next `statement` throws (and a `ROLLBACK` still rolls back). */
function faulty(statement?: "BEGIN IMMEDIATE" | "COMMIT" | "ROLLBACK") {
diff --git a/packages/chord/test/telemetry-ingest/facet.test.ts b/packages/chord/test/telemetry-ingest/facet.test.ts
new file mode 100644
index 000000000..60085bdbb
--- /dev/null
+++ b/packages/chord/test/telemetry-ingest/facet.test.ts
@@ -0,0 +1,189 @@
+// Tests of the server's telemetry ingest (decisions "Telemetry from browser pages", "The server is the one place
+// telemetry is stored", "Who a span was for"): a page's batch is checked by its schema (size, every field, no control
+// characters), its spans must carry the page's own ids, are capped per page and minute, marked `chord.host: browser`
+// and stamped with the link's principal; a worker's batch is written as it is, stamped with its host; nobody else
+// 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 { 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";
+import { createHost, type Host } from "../../src/host/index.ts";
+import { memoryLinkPair } from "../../src/link/index.ts";
+import {
+ PAGE_BATCH_SPANS,
+ PAGE_SPANS_PER_MINUTE,
+ PageTelemetry,
+ type TelemetryBatch,
+ telemetryIngestFacet,
+ WorkerTelemetry,
+} from "../../src/telemetry-ingest/index.ts";
+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> = {}) {
+ const batches: TelemetryBatch[] = [];
+ const telemetry = new InMemoryTelemetryContext();
+ const server = createHost({ address: Server(), principal: { kind: "server" }, telemetry, onError: () => {} });
+ const facet = telemetryIngestFacet({
+ target: {
+ ingest: (batch) => {
+ batches.push(batch);
+ return batch.spans.length;
+ },
+ },
+ workerHost: (who) => workers[JSON.stringify(who)],
+ principalAttributes: (who) => ({ "chord.principal": JSON.stringify(who), "user.name": "Ada" }),
+ });
+ await server.load([{ name: "chord.telemetry", facet }], context);
+ const client = createHost({ onError: () => {} });
+ await client.load([], context);
+ const [a, b] = memoryLinkPair();
+ server.accept(a, { principal, codec: testCodec() }, context);
+ client.connect(b, { principal: { kind: "server" }, codec: testCodec() }, context);
+ await transported();
+ return { server, client, batches, telemetry };
+}
+
+/** A page span of `host` numbered `n` (its own ids), with `override`. */
+function span(host: Host, n: number, override: Partial = {}): StoredSpan {
+ const id = `browser:${host.incarnation}:${n}`;
+ return {
+ id,
+ traceId: `browser:${host.incarnation}:1`,
+ ...(n === 1 ? {} : { parentId: `browser:${host.incarnation}:1` }),
+ name: "page.click",
+ startedMs: 1000,
+ endedMs: 1002,
+ attributes: {},
+ events: [],
+ links: [],
+ status: { status: "ok" },
+ ...override,
+ };
+}
+
+/** The page's `ingest` of `spans` over `client`'s link. */
+async function ingest(client: Host, spans: StoredSpan[]) {
+ const page = await client.get(PageTelemetry, {}, context);
+ return page.ingest({ spans }, context);
+}
+
+describe("a page's batches", () => {
+ it("writes its own spans marked `chord.host: browser` with its link's principal, no attribute of its overriding", async () => {
+ const { client, batches } = await ingesting({ kind: "owner" });
+ const spans = [
+ span(client, 1, { attributes: { "chord.host": "server", "chord.principal": "root" } }),
+ span(client, 2),
+ ];
+ expect(await ingest(client, spans)).toEqual({ written: 2, dropped: 0 });
+ expect(batches[0]!.spans.map(({ attributes }) => attributes)).toEqual([
+ { "chord.host": "browser", "chord.principal": '{"kind":"owner"}', "user.name": "Ada" },
+ { "chord.host": "browser", "chord.principal": '{"kind":"owner"}', "user.name": "Ada" },
+ ]);
+ expect(batches[0]!.metrics).toEqual([]);
+ });
+
+ 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";
+ const spans = [
+ span(client, 2),
+ span(client, 3, { id: server }),
+ span(client, 4, { traceId: server }),
+ span(client, 5, { parentId: server }),
+ span(client, 6, { id: "browser:someone-else:6" }),
+ span(client, 7, { startedMs: 2000, endedMs: 1000 }),
+ ];
+ expect(await ingest(client, spans)).toEqual({ written: 1, dropped: 5 });
+ expect(batches[0]!.spans.map(({ id }) => id)).toEqual([spans[0]!.id]);
+ });
+
+ it.each([
+ [
+ "more spans than a batch takes",
+ (host: Host) => Array.from({ length: PAGE_BATCH_SPANS + 1 }, (_, n) => span(host, n + 2)),
+ ],
+ ["a name with a control character", (host: Host) => [span(host, 1, { name: "\u001b]0;PWNED\u0007" })]],
+ ["an id with a space", (host: Host) => [span(host, 1, { id: `browser:${host.incarnation}: 1` })]],
+ ["a 129-character name", (host: Host) => [span(host, 1, { name: "n".repeat(129) })]],
+ ["a 257-character attribute", (host: Host) => [span(host, 1, { attributes: { text: "t".repeat(257) } })]],
+ ["an attribute key with a control character", (host: Host) => [span(host, 1, { attributes: { "a\u0000": 1 } })]],
+ [
+ "33 attributes",
+ (host: Host) => [
+ span(host, 1, { attributes: Object.fromEntries(Array.from({ length: 33 }, (_, n) => [`k${n}`, n])) }),
+ ],
+ ],
+ ["an array attribute", (host: Host) => [span(host, 1, { attributes: { tags: ["a"] } })]],
+ [
+ "17 events",
+ (host: Host) => [
+ span(host, 1, { events: Array.from({ length: 17 }, () => ({ name: "e", timeMs: 0, attributes: {} })) }),
+ ],
+ ],
+ [
+ "a 501-character error message",
+ (host: Host) => [
+ span(host, 1, { status: { status: "error", error: { name: "x", message: "m".repeat(501) } } }),
+ ],
+ ],
+ ])("refuses a batch with %s as invalid arguments, writing nothing", async (_, spans) => {
+ const { client, batches } = await ingesting({ kind: "owner" });
+ const error = await ingest(client, spans(client)).catch((thrown: unknown) => thrown);
+ expect(isChordError(error, "invalid")).toBe(true);
+ expect(batches).toEqual([]);
+ });
+
+ it("caps a page's spans per minute: past the budget they are dropped and counted", async () => {
+ const { client, batches } = await ingesting({ kind: "owner" });
+ let written = 0;
+ let dropped = 0;
+ for (let batch = 0; batch * PAGE_BATCH_SPANS < PAGE_SPANS_PER_MINUTE + PAGE_BATCH_SPANS; batch++) {
+ const spans = Array.from({ length: PAGE_BATCH_SPANS }, (_, n) =>
+ span(client, batch * PAGE_BATCH_SPANS + n + 2),
+ );
+ const receipt = await ingest(client, spans);
+ written += receipt.written;
+ dropped += receipt.dropped;
+ }
+ expect([written, dropped]).toEqual([PAGE_SPANS_PER_MINUTE, PAGE_BATCH_SPANS]);
+ expect(batches.flatMap(({ spans }) => spans)).toHaveLength(PAGE_SPANS_PER_MINUTE);
+ });
+
+ it("records no span for an ingest call", async () => {
+ const { client, telemetry } = await ingesting({ kind: "owner" });
+ await ingest(client, [span(client, 1)]);
+ expect(telemetry.getSpans().map(({ name }) => name)).not.toContain("chord.method");
+ });
+});
+
+describe("a worker's batches", () => {
+ it("writes a worker's spans and metrics as they are, stamped with its host; anyone else has nothing to call", async () => {
+ const worker = { kind: "worker", key: "project|p1" };
+ const { client, batches } = await ingesting(worker, { [JSON.stringify(worker)]: "project|p1" });
+ const held = await client.get(WorkerTelemetry, {}, context);
+ if (held.variant !== "worker") throw new Error("expected the worker variant");
+ const own = { ...span(client, 1), id: "w:1", traceId: "w:1", attributes: { tags: ["a", "b"] } };
+ const metric = {
+ intervalMs: 10_000,
+ name: "chord.link.bytes",
+ kind: "counter",
+ attributes: { direction: "sent" },
+ count: 2,
+ sum: 10,
+ min: 4,
+ max: 6,
+ } as const;
+ expect(await held.ingest({ spans: [own], metrics: [metric] }, context)).toEqual({ written: 1, dropped: 0 });
+ expect(batches[0]).toEqual({
+ spans: [{ ...own, attributes: { tags: ["a", "b"], "chord.host": "project|p1" } }],
+ metrics: [metric],
+ });
+ const { client: page } = await ingesting({ kind: "owner" });
+ expect((await page.get(WorkerTelemetry, {}, context)).variant).toBe("other");
+ });
+});
diff --git a/packages/chord/test/telemetry-ingest/recorder.test.ts b/packages/chord/test/telemetry-ingest/recorder.test.ts
new file mode 100644
index 000000000..88a4f3a1b
--- /dev/null
+++ b/packages/chord/test/telemetry-ingest/recorder.test.ts
@@ -0,0 +1,113 @@
+// Tests of Chord's telemetry recorder: settled spans and metric aggregates kept for its owner, taken as batches; ids
+// under a scope read at the first span; the queue bounded with a taken batch counted until released; ingested spans
+// and metrics join the queue; a stop makes later spans inert.
+
+import { afterEach, describe, expect, it, vi } from "vitest";
+import { TelemetryRecorder } from "../../src/telemetry-ingest/index.ts";
+
+afterEach(() => vi.restoreAllMocks());
+
+describe("recording", () => {
+ it("keeps settled spans only, its ids under the scope it reads at its first span, carriers its own", async () => {
+ let scope = "early";
+ const recorder = new TelemetryRecorder(() => scope, 100);
+ scope = "browser:inc";
+ const gate = Promise.withResolvers();
+ const open = recorder.startSpan({ name: "open" }, () => gate.promise);
+ let carrier: Record | undefined;
+ await recorder.startSpan({ name: "root" }, (span) => {
+ carrier = recorder.inject(span);
+ return span.startSpan({ name: "child" }, () => {});
+ });
+ const { spans } = recorder.take(false);
+ expect(spans.map(({ id, parentId, name }) => [id, parentId, name])).toEqual([
+ ["browser:inc:3", "browser:inc:2", "child"],
+ ["browser:inc:2", undefined, "root"],
+ ]);
+ expect(carrier).toEqual({ "pi-sqlite-span": "browser:inc:2", "pi-sqlite-trace": "browser:inc:2" });
+ gate.resolve();
+ await open;
+ expect(recorder.take(false).spans.map(({ name }) => name)).toEqual(["open"]);
+ });
+
+ it("aggregates metrics per series and 10 s, taking only intervals that are over unless partial", () => {
+ const now = vi.spyOn(Date, "now").mockReturnValue(20_001);
+ const recorder = new TelemetryRecorder(() => "s", 100);
+ recorder.metrics.counter("hits").add(2, { b: 1, a: true });
+ recorder.metrics.counter("hits").add(3, { a: true, b: 1 });
+ expect(recorder.take(false).metrics).toEqual([]);
+ now.mockReturnValue(30_001);
+ expect(recorder.take(false).metrics).toEqual([
+ {
+ intervalMs: 20_000,
+ name: "hits",
+ kind: "counter",
+ attributes: { a: true, b: 1 },
+ count: 2,
+ sum: 5,
+ min: 2,
+ max: 3,
+ },
+ ]);
+ recorder.metrics.counter("hits").add(1);
+ expect(recorder.take(true).metrics.map(({ intervalMs, sum }) => [intervalMs, sum])).toEqual([[30_000, 1]]);
+ });
+});
+
+describe("the queue", () => {
+ it("counts a taken batch against its bound until released, dropping and counting past it", async () => {
+ const recorder = new TelemetryRecorder(() => "s", 2);
+ await recorder.startSpan({ name: "a" }, () => {});
+ await recorder.startSpan({ name: "b" }, () => {});
+ const taken = recorder.take(false, 1);
+ expect(taken.spans.map(({ name }) => name)).toEqual(["a"]);
+ await recorder.startSpan({ name: "c" }, () => {});
+ expect(recorder.droppedSpans).toBe(1);
+ recorder.release();
+ await recorder.startSpan({ name: "d" }, () => {});
+ expect(recorder.take(false).spans.map(({ name }) => name)).toEqual(["b", "d"]);
+ });
+
+ it("queues ingested spans and merges ingested metric rows within its bounds", () => {
+ const recorder = new TelemetryRecorder(() => "s", 1);
+ const span = {
+ id: "w:1",
+ traceId: "w:1",
+ name: "x",
+ startedMs: 1,
+ endedMs: 2,
+ attributes: {},
+ events: [],
+ links: [],
+ status: { status: "ok" },
+ } as const;
+ const metric = {
+ intervalMs: 0,
+ name: "m",
+ kind: "counter",
+ attributes: {},
+ count: 1,
+ sum: 2,
+ min: 2,
+ max: 2,
+ } as const;
+ expect(recorder.ingest({ spans: [span, { ...span, id: "w:2" }], metrics: [metric, metric] })).toBe(1);
+ expect(recorder.droppedSpans).toBe(1);
+ const batch = recorder.take(true);
+ expect(batch.spans.map(({ id }) => id)).toEqual(["w:1"]);
+ expect(batch.metrics).toEqual([{ ...metric, count: 2, sum: 4 }]);
+ });
+
+ it("records nothing once stopped; a discarding stop drops what waits", async () => {
+ const recorder = new TelemetryRecorder(() => "s", 10);
+ await recorder.startSpan({ name: "kept" }, () => {});
+ recorder.stop("keep");
+ await recorder.startSpan({ name: "late" }, () => {});
+ recorder.metrics.counter("late").add(1);
+ expect(recorder.take(true)).toEqual({ spans: [expect.objectContaining({ name: "kept" })], metrics: [] });
+ const discarding = new TelemetryRecorder(() => "s", 10);
+ await discarding.startSpan({ name: "gone" }, () => {});
+ discarding.stop("discard");
+ expect(discarding.take(true)).toEqual({ spans: [], metrics: [] });
+ });
+});
diff --git a/packages/chord/test/telemetry-ingest/sender.test.ts b/packages/chord/test/telemetry-ingest/sender.test.ts
new file mode 100644
index 000000000..f65929ca4
--- /dev/null
+++ b/packages/chord/test/telemetry-ingest/sender.test.ts
@@ -0,0 +1,98 @@
+// Tests of the senders: a page's sends its spans (never its metrics) to the server's `PageTelemetry`, a worker's its
+// spans and metrics to `WorkerTelemetry`; nothing is sent (or lost) while the object is not bound, a refused batch is
+// given up.
+
+import { describe, expect, it } from "vitest";
+import { BACKGROUND_CONTEXT as context } from "../../src/context/index.ts";
+import { hostKind } from "../../src/contracts/index.ts";
+import type { Principal } from "../../src/data/index.ts";
+import { createHost } from "../../src/host/index.ts";
+import { memoryLinkPair } from "../../src/link/index.ts";
+import {
+ sendPageTelemetry,
+ sendWorkerTelemetry,
+ type TelemetryBatch,
+ TelemetryRecorder,
+ telemetryIngestFacet,
+} from "../../src/telemetry-ingest/index.ts";
+import { testCodec, transported } from "../support.ts";
+
+const Server = hostKind("server");
+
+/** A server with the ingest facet (its batches collected) and a client of `principal` recording to `recorder`. */
+async function sending(principal: Principal, scope: (incarnation: string) => string) {
+ const batches: TelemetryBatch[] = [];
+ const server = createHost({ address: Server(), principal: { kind: "server" }, onError: () => {} });
+ const facet = telemetryIngestFacet({
+ target: {
+ ingest: (batch) => {
+ batches.push(batch);
+ return batch.spans.length;
+ },
+ },
+ workerHost: (who) => (who.kind === "worker" ? "project|p1" : undefined),
+ principalAttributes: () => ({}),
+ });
+ await server.load([{ name: "chord.telemetry", facet }], context);
+ let incarnation = "";
+ const recorder = new TelemetryRecorder(() => scope(incarnation), 100);
+ const client = createHost({ telemetry: recorder, onError: () => {} });
+ incarnation = client.incarnation;
+ await client.load([], context);
+ const connect = () => {
+ const [a, b] = memoryLinkPair();
+ server.accept(a, { principal, codec: testCodec() }, context);
+ client.connect(b, { principal: { kind: "server" }, codec: testCodec() }, context);
+ return a;
+ };
+ return { batches, recorder, client, connect };
+}
+
+describe("a page's sender", () => {
+ it("sends its spans without metrics once bound; until then they wait in the recorder", async () => {
+ const { batches, recorder, client, connect } = await sending({ kind: "owner" }, (inc) => `browser:${inc}`);
+ const sender = sendPageTelemetry(client, recorder, context);
+ await recorder.startSpan({ name: "page.click" }, () => {});
+ recorder.metrics.counter("clicks").add(1);
+ await sender.send(true);
+ expect(batches).toEqual([]);
+ connect();
+ await transported();
+ await sender.send(true);
+ expect(batches.map(({ spans, metrics }) => [spans.map(({ name }) => name), metrics])).toEqual([
+ [["page.click"], []],
+ ]);
+ expect(recorder.queuedSpans).toBe(0);
+ // Nothing waits: no call.
+ await sender.send(true);
+ expect(batches).toHaveLength(1);
+ sender.stop();
+ });
+
+ it("gives a refused batch up", async () => {
+ // Ids the server refuses: not under the page's prefix.
+ const { batches, recorder, client, connect } = await sending({ kind: "owner" }, () => "elsewhere");
+ connect();
+ const sender = sendPageTelemetry(client, recorder, context);
+ await transported();
+ await recorder.startSpan({ name: "page.click" }, () => {});
+ await sender.send(false);
+ expect(batches.map(({ spans }) => spans)).toEqual([[]]);
+ expect(recorder.queuedSpans).toBe(0);
+ });
+});
+
+describe("a worker's sender", () => {
+ it("sends spans and metrics to the worker variant", async () => {
+ const { batches, recorder, client, connect } = await sending({ kind: "worker" }, () => "w");
+ connect();
+ const sender = sendWorkerTelemetry(client, recorder, context);
+ await transported();
+ await recorder.startSpan({ name: "worker.job" }, () => {});
+ recorder.metrics.counter("runs").add(2);
+ await sender.send(true);
+ const [batch] = batches;
+ expect(batch!.spans.map(({ name }) => name)).toEqual(["worker.job"]);
+ expect(batch!.metrics.find(({ name }) => name === "runs")?.sum).toBe(2);
+ });
+});
diff --git a/packages/chord/test/telemetry-sqlite-node.test.ts b/packages/chord/test/telemetry-sqlite-node.test.ts
new file mode 100644
index 000000000..4c3cdd20e
--- /dev/null
+++ b/packages/chord/test/telemetry-sqlite-node.test.ts
@@ -0,0 +1,72 @@
+// Tests of the read-only SQLite telemetry store on Node (`openTelemetryStore`): it reads what recorders of the file
+// write, while they write, never writes the file, and refuses a file without a store or with one of another version.
+
+import { mkdtempSync, readFileSync, rmSync } from "node:fs";
+import { tmpdir } from "node:os";
+import { join } from "node:path";
+import { afterEach, beforeEach, describe, expect, it } from "vitest";
+import { openNodeSqliteDatabase } from "../src/sqlite/node.ts";
+import { createSqliteTelemetry } from "../src/telemetry-sqlite/index.ts";
+import { openTelemetryStore } from "../src/telemetry-sqlite/node.ts";
+
+let dir = "";
+beforeEach(() => {
+ dir = mkdtempSync(join(tmpdir(), "chord-telemetry-"));
+});
+afterEach(() => rmSync(dir, { recursive: true, force: true }));
+
+/** A recorder on `file` of its own database. */
+async function recorder(file: string) {
+ const db = await openNodeSqliteDatabase(file);
+ const telemetry = await createSqliteTelemetry(db);
+ return {
+ telemetry,
+ close: async () => {
+ await telemetry.close();
+ await db.close();
+ },
+ };
+}
+
+describe("the read-only store", () => {
+ it("reads the traces and metrics recorders wrote, while one still records, and never writes the file", async () => {
+ const file = join(dir, "telemetry.sqlite");
+ const writing = await recorder(file);
+ await writing.telemetry.startSpan({ name: "first" }, (span) => span.startSpan({ name: "child" }, () => {}));
+ writing.telemetry.metrics.counter("hits").add(2);
+ await writing.telemetry.flush();
+ const store = await openTelemetryStore(file);
+ const { traces } = await store.findTraces({ name: "first" });
+ expect(traces.map(({ spans }) => spans.map(({ name }) => name))).toEqual([["first", "child"]]);
+ expect(await store.getTrace(traces[0]!.traceId)).toEqual(traces[0]);
+ // The recorder goes on: the reader sees each flush.
+ await writing.telemetry.startSpan({ name: "second" }, () => {});
+ await writing.close();
+ expect((await store.findTraces()).traces.map(({ spans }) => spans[0]!.name)).toEqual(["second", "first"]);
+ expect((await store.findMetrics({ name: "hits" })).map(({ sum }) => sum)).toEqual([2]);
+ const before = readFileSync(file);
+ await store.findTraces({ limit: 100 });
+ await store.close();
+ expect(readFileSync(file).equals(before)).toBe(true);
+ await expect(store.findTraces()).rejects.toThrow();
+ });
+
+ it("refuses a missing file, a file without a store and a store of another version", async () => {
+ await expect(openTelemetryStore(join(dir, "missing.sqlite"))).rejects.toThrow();
+ const other = join(dir, "other.sqlite");
+ const db = await openNodeSqliteDatabase(other);
+ await db.exec("CREATE TABLE notes (id INTEGER)");
+ await db.close();
+ await expect(openTelemetryStore(other)).rejects.toThrow("not a telemetry store");
+ const old = join(dir, "old.sqlite");
+ await (await recorder(old)).close();
+ const downgraded = await openNodeSqliteDatabase(old);
+ await downgraded.run("UPDATE telemetry_schema SET version = 1");
+ await downgraded.close();
+ await expect(openTelemetryStore(old)).rejects.toThrow("telemetry store version 1, not 2");
+ const newer = await openNodeSqliteDatabase(old);
+ await newer.run("UPDATE telemetry_schema SET version = 3");
+ await newer.close();
+ await expect(openTelemetryStore(old)).rejects.toThrow("telemetry store version 3 is newer than this reader's 2");
+ });
+});
diff --git a/packages/chord/test/telemetry-sqlite.test.ts b/packages/chord/test/telemetry-sqlite.test.ts
index cd1589a35..30ae15034 100644
--- a/packages/chord/test/telemetry-sqlite.test.ts
+++ b/packages/chord/test/telemetry-sqlite.test.ts
@@ -16,8 +16,8 @@ type SpanRow = {
trace_id: string;
parent_id: string | null;
name: string;
- started_ms: number;
- ended_ms: number;
+ started_us: number;
+ ended_us: number;
attributes: string;
events: string;
links: string;
@@ -109,6 +109,89 @@ describe("SQLite telemetry buffering and aggregation", () => {
]);
});
+ it("stores span times in whole microseconds of telemetryNow, read back as milliseconds", async () => {
+ vi.spyOn(Date, "now").mockReturnValue(20_001);
+ const clock = vi.spyOn(performance, "now").mockReturnValue(500);
+ await using f = await fixture();
+ await f.telemetry.startSpan({ name: "root" }, async (span) => {
+ clock.mockReturnValue(500.125);
+ await span.startSpan({ name: "child" }, () => {
+ clock.mockReturnValue(500.5);
+ span.addEvent("half", {});
+ });
+ });
+ await f.telemetry.flush();
+ expect(
+ await f.db.all("SELECT name, started_us, ended_us, events FROM telemetry_spans ORDER BY started_us"),
+ ).toEqual([
+ {
+ name: "root",
+ started_us: 20_001_000,
+ ended_us: 20_001_500,
+ events: '[{"name":"half","time_ms":0.5,"attributes":{}}]',
+ },
+ { name: "child", started_us: 20_001_125, ended_us: 20_001_500, events: "[]" },
+ ]);
+ const { traces } = await f.telemetry.findTraces({ startMin: 20_001, startMax: 20_001 });
+ expect(traces[0]!.spans.map(({ startedMs, endedMs }) => [startedMs, endedMs])).toEqual([
+ [20_001, 20_001.5],
+ [20_001.125, 20_001.5],
+ ]);
+ });
+
+ it("migrates a store of version 1 (milliseconds) to microseconds, its rows kept", async () => {
+ const db = await openNodeSqliteDatabase(":memory:");
+ try {
+ // Version 1 as it shipped: its tables and one span.
+ await db.exec(`CREATE TABLE telemetry_schema (singleton INTEGER PRIMARY KEY CHECK (singleton = 1),
+ version INTEGER NOT NULL CHECK (version >= 0)) STRICT`);
+ await db.run("INSERT INTO telemetry_schema VALUES (1, 1)");
+ await db.exec(`CREATE TABLE telemetry_spans (id TEXT PRIMARY KEY, trace_id TEXT NOT NULL, parent_id TEXT,
+ name TEXT, started_ms REAL, ended_ms REAL NOT NULL, attributes TEXT, events TEXT, links TEXT, status TEXT)`);
+ await db.exec("CREATE INDEX telemetry_spans_started_ms ON telemetry_spans(started_ms)");
+ await db.exec(`CREATE TABLE telemetry_metrics (interval_ms INTEGER, series_key TEXT, name TEXT, kind TEXT,
+ unit TEXT, attributes TEXT, count INTEGER, sum REAL, min REAL, max REAL, PRIMARY KEY(interval_ms, series_key))`);
+ await db.run(
+ "INSERT INTO telemetry_spans VALUES ('old:1', 'old:1', NULL, 'old', 1000, 1002.5, '{}', '[]', '[]', '{\"status\":\"ok\"}')",
+ );
+ const telemetry = await createSqliteTelemetry(db);
+ expect(await db.get("SELECT version FROM telemetry_schema")).toEqual({ version: 2 });
+ expect(await db.all("SELECT started_us, ended_us FROM telemetry_spans")).toEqual([
+ { started_us: 1_000_000, ended_us: 1_002_500 },
+ ]);
+ expect(
+ (await telemetry.getTrace("old:1"))?.spans.map(({ startedMs, endedMs }) => [startedMs, endedMs]),
+ ).toEqual([[1000, 1002.5]]);
+ await telemetry.close();
+ } finally {
+ await db.close();
+ }
+ });
+
+ it("writes ingested spans and metric rows with its own, never replacing a stored span", async () => {
+ vi.spyOn(Date, "now").mockReturnValue(20_001);
+ await using f = await fixture();
+ await f.telemetry.startSpan({ name: "own" }, () => {});
+ await f.telemetry.flush();
+ const [own] = (await f.telemetry.findTraces({ name: "own" })).traces[0]!.spans;
+ const span = { ...own!, id: "w:1", traceId: "w:1", name: "worker", startedMs: 1000.5, endedMs: 1001.25 };
+ const metric = {
+ intervalMs: 10_000,
+ name: "hits",
+ kind: "counter",
+ attributes: { b: 1, a: 2 },
+ count: 2,
+ sum: 6,
+ min: 2,
+ max: 4,
+ } as const;
+ expect(f.telemetry.ingest({ spans: [span, { ...own!, name: "impostor" }], metrics: [metric] })).toBe(2);
+ await f.telemetry.flush();
+ expect((await f.telemetry.getTrace("w:1"))?.spans).toEqual([span]);
+ expect((await f.telemetry.getTrace(own!.traceId))?.spans.map(({ name }) => name)).toEqual(["own"]);
+ expect(await f.telemetry.findMetrics({ name: "hits" })).toEqual([{ ...metric, attributes: { a: 2, b: 1 } }]);
+ });
+
it("does not execute SQL while recording and stores only settled spans", async () => {
await using f = await fixture();
const transaction = vi.spyOn(f.db, "transaction");
@@ -129,7 +212,7 @@ describe("SQLite telemetry buffering and aggregation", () => {
active.addEvent("late");
await f.telemetry.flush();
const row = await f.db.get("SELECT * FROM telemetry_spans");
- expect(row?.ended_ms).toBeGreaterThanOrEqual(row?.started_ms ?? Infinity);
+ expect(row?.ended_us).toBeGreaterThanOrEqual(row?.started_us ?? Infinity);
expect(JSON.parse(row?.events ?? "[]")).toEqual([{ name: "begin", time_ms: expect.any(Number), attributes: {} }]);
});
diff --git a/packages/chord/test/telemetry.test.ts b/packages/chord/test/telemetry.test.ts
index edc9d1deb..6d31daeea 100644
--- a/packages/chord/test/telemetry.test.ts
+++ b/packages/chord/test/telemetry.test.ts
@@ -126,7 +126,7 @@ describe("carriers", () => {
describe("open spans", () => {
it("ends once, with how its work settled: ok, a cancel (status ok), or an error with its category", async () => {
const telemetry = new InMemoryTelemetryContext();
- const attributes = { type: "t", member: "m", object: "o", "principal.kind": "none" };
+ const attributes = { "chord.host": "client", type: "t", member: "m", object: "o", "principal.kind": "none" };
const ok = new OpenSpan(telemetry, "chord.method", attributes);
ok.endWhen(Promise.resolve(1), "method_failed", undefined);
const aborted = new OpenSpan(telemetry, "chord.method", attributes);
@@ -225,6 +225,32 @@ describe("across hosts", () => {
await telemetry.close();
});
+ it("names the host that recorded each span: its address key, `client` without an address", async () => {
+ const { telemetry, tab } = await store();
+ await telemetry.startSpan({ name: "test" }, async (span) => {
+ const context = withTelemetry(span, BACKGROUND_CONTEXT);
+ const notes = await tab.get(PlacedNotes, { session: "S1" }, context);
+ if (notes.variant !== "editor") throw new Error("expected the editor");
+ await notes.add({ text: "a" }, context);
+ });
+ await transported();
+ await telemetry.flush();
+ const { traces } = await telemetry.findTraces({ limit: 100 });
+ const spans = traces.flatMap((trace) => trace.spans).filter(({ name }) => name !== "test");
+ const hosts = new Map>();
+ for (const { name, attributes } of spans)
+ hosts.set(name, (hosts.get(name) ?? new Set()).add(attributes["chord.host"]));
+ expect(Object.fromEntries([...hosts].map(([name, of]) => [name, [...of].sort()]))).toEqual({
+ "chord.activate": ["session|S1"],
+ "chord.call": ["client"],
+ "chord.hold": ["client"],
+ "chord.method": ["session|S1"],
+ "chord.relay": ["server"],
+ "chord.resolve": ["server"],
+ });
+ await telemetry.close();
+ });
+
it("holds through the relay under the tab's span; the worker's start and its activations link to their triggers", async () => {
const { telemetry, tab } = await store();
await telemetry.startSpan({ name: "test" }, async (span) => {
diff --git a/packages/telemetry/CHANGELOG.md b/packages/telemetry/CHANGELOG.md
index fa95b46aa..824b50113 100644
--- a/packages/telemetry/CHANGELOG.md
+++ b/packages/telemetry/CHANGELOG.md
@@ -2,6 +2,10 @@
## [Unreleased]
+### Added
+
+- `telemetryNow()`, the span clock: wall-clock milliseconds at microsecond resolution from `performance.now()` anchored to `Date.now()`, anchored anew when the two part by more than 10 ms. The in-memory adapter stamps span starts with it (span times rounded to the microsecond), and `renderTrace` prints lengths of time to the microsecond.
+
### Fixed
- `renderTrace` escapes control characters (C0, C1, DEL) as `\uXXXX` in span and event names, trace and span ids of links, attribute keys and error names and messages, so ids taken from another process's carrier never reach a terminal or viewer raw.
diff --git a/packages/telemetry/src/index.ts b/packages/telemetry/src/index.ts
index 6432d095a..b0f8b3270 100644
--- a/packages/telemetry/src/index.ts
+++ b/packages/telemetry/src/index.ts
@@ -29,12 +29,16 @@ export interface SpanOptions {
export type SpanStatus = { status: "ok" } | { status: "error"; error?: { name: string; message: string } };
-/** A settled span snapshot, independent of the recording adapter. Event times are relative to span start. */
+/**
+ * A settled span snapshot, independent of the recording adapter. Times are milliseconds at microsecond resolution;
+ * event times are relative to span start.
+ */
export interface StoredSpan {
readonly id: string;
readonly traceId: string;
readonly parentId?: string;
readonly name: string;
+ /** Wall-clock milliseconds since the epoch (`telemetryNow`). */
readonly startedMs: number;
readonly endedMs: number;
readonly attributes: SpanAttributes;
@@ -462,4 +466,4 @@ export type {
RecordedTelemetryMeasurement,
RecordedTelemetrySpan,
} from "./memory.ts";
-export { InMemoryTelemetryContext } from "./memory.ts";
+export { InMemoryTelemetryContext, telemetryNow } from "./memory.ts";
diff --git a/packages/telemetry/src/memory.ts b/packages/telemetry/src/memory.ts
index b59cb1639..0ce7e6699 100644
--- a/packages/telemetry/src/memory.ts
+++ b/packages/telemetry/src/memory.ts
@@ -94,6 +94,37 @@ function carrierId(carrier: Readonly): string {
return `${carrier["pi-memory-scope"]}:${carrier["pi-memory-span"]}`;
}
+// The clock of span times: wall-clock milliseconds at microsecond resolution, from the monotonic high-resolution
+// clock anchored to the wall clock (`telemetryNow`, also Chord's SQLite store's).
+
+/**
+ * How far the anchored clock may part from `Date.now()` before it is anchored anew: more than `Date.now()`'s own
+ * truncation to whole milliseconds, less than any step worth following (a wall clock set, a sleep the monotonic clock
+ * did not count).
+ */
+const TOLERANCE_MS = 10;
+
+/** The wall-clock time of `performance.now()`'s zero; `performance.timeOrigin` until the first step is followed. */
+let anchor = performance.timeOrigin;
+
+/**
+ * Now as milliseconds since the epoch, rounded to the microsecond: `performance.now()` (monotonic, sub-millisecond)
+ * plus an anchor to the wall clock. While the two agree within 10 ms, times in one process keep their order and
+ * spacing to the microsecond; past that the clock follows `Date.now()` again, at whole milliseconds. Every adapter
+ * of this package and Chord's SQLite store stamp span starts with it, so their times agree.
+ */
+export function telemetryNow(): number {
+ const clock = performance.now();
+ const wall = Date.now();
+ if (Math.abs(anchor + clock - wall) > TOLERANCE_MS) anchor = wall - clock;
+ return microseconds(anchor + clock);
+}
+
+/** `ms` rounded to the microsecond, as span times are. */
+function microseconds(ms: number): number {
+ return Math.round(ms * 1000) / 1000;
+}
+
// Identity survives settlement without exposing backend IDs on the generic context contract.
const contextCarriers = new WeakMap();
@@ -141,7 +172,7 @@ function createSpan(
}
const id = state.nextSpanId++;
return {
- startedMs: Date.now(),
+ startedMs: telemetryNow(),
clock: performance.now(),
id,
parentId: parent?.localId ?? null,
@@ -212,7 +243,7 @@ async function startInMemorySpan(
if (recordedSpan.settled) return;
recordedSpan.events.push({
name,
- timeMs: performance.now() - recordedSpan.clock,
+ timeMs: microseconds(performance.now() - recordedSpan.clock),
attributes: copyAttributes(attributes),
});
},
@@ -240,7 +271,7 @@ async function startInMemorySpan(
throw error;
} finally {
recordedSpan.settled = true;
- recordedSpan.endedMs = recordedSpan.startedMs + performance.now() - recordedSpan.clock;
+ recordedSpan.endedMs = microseconds(recordedSpan.startedMs + performance.now() - recordedSpan.clock);
recordedSpan.endSequence = state.nextEndSequence++;
}
}
diff --git a/packages/telemetry/src/render.ts b/packages/telemetry/src/render.ts
index a99f6ff90..c83cbb2c8 100644
--- a/packages/telemetry/src/render.ts
+++ b/packages/telemetry/src/render.ts
@@ -9,6 +9,11 @@ function escaped(text: string): string {
return text.replace(CONTROL, (char) => `\\u${char.charCodeAt(0).toString(16).padStart(4, "0")}`);
}
+/** `ms` rounded to the microsecond, as the adapters record span times. */
+function microseconds(ms: number): number {
+ return Math.round(ms * 1000) / 1000;
+}
+
function formatAttributes(attributes: Readonly = {}): string {
return Object.entries(attributes)
.map(([key, value]) => ` ${escaped(key)}=${JSON.stringify(value)}`)
@@ -16,8 +21,9 @@ function formatAttributes(attributes: Readonly = {}): string {
}
/**
- * Render stored spans as a chronological forest, treating absent parents as roots. Control characters in ids, names,
- * attribute keys and error messages are escaped (attribute values are JSON).
+ * Render stored spans as a chronological forest, treating absent parents as roots. Lengths of time are milliseconds to
+ * the microsecond. Control characters in ids, names, attribute keys and error messages are escaped (attribute values
+ * are JSON).
*/
export function renderTrace(spans: readonly StoredSpan[]): string {
const byId = new Map(spans.map((span) => [span.id, span]));
@@ -46,10 +52,12 @@ export function renderTrace(spans: readonly StoredSpan[]): string {
}
}
lines.push(
- `${indent}${escaped(span.name)}${formatAttributes(span.attributes)} (${span.endedMs - span.startedMs}ms)${error}`,
+ `${indent}${escaped(span.name)}${formatAttributes(span.attributes)} (${microseconds(span.endedMs - span.startedMs)}ms)${error}`,
);
for (const event of span.events) {
- lines.push(`${indent} · ${escaped(event.name)}${formatAttributes(event.attributes)} (+${event.timeMs}ms)`);
+ lines.push(
+ `${indent} · ${escaped(event.name)}${formatAttributes(event.attributes)} (+${microseconds(event.timeMs)}ms)`,
+ );
}
for (const link of span.links) {
const ids = `trace ${escaped(link.traceId)} span ${escaped(link.spanId)}`;
diff --git a/packages/telemetry/test/render.test.ts b/packages/telemetry/test/render.test.ts
index 82afb383a..5be9a60b8 100644
--- a/packages/telemetry/test/render.test.ts
+++ b/packages/telemetry/test/render.test.ts
@@ -141,6 +141,15 @@ describe("renderTrace", () => {
expect(rendered.endsWith(`${" ".repeat(1999)}1999 (10ms)`)).toBe(true);
});
+ it("renders lengths of time to the microsecond, as the adapters record them", () => {
+ const root = span("root", {
+ startedMs: 1_793_789_452_816.123,
+ endedMs: 1_793_789_452_816.431,
+ events: [{ name: "half", timeMs: 0.15400000002, attributes: {} }],
+ });
+ expect(renderTrace([root])).toBe("root (0.308ms)\n · half (+0.154ms)");
+ });
+
it("renders an empty input as an empty string", () => {
expect(renderTrace([])).toBe("");
});
diff --git a/packages/telemetry/test/store.test.ts b/packages/telemetry/test/store.test.ts
index d59d45cad..b1b381e59 100644
--- a/packages/telemetry/test/store.test.ts
+++ b/packages/telemetry/test/store.test.ts
@@ -1,5 +1,5 @@
import { afterEach, describe, expect, it, vi } from "vitest";
-import { InMemoryTelemetryContext, type TelemetrySpan } from "../src/index.ts";
+import { InMemoryTelemetryContext, type TelemetrySpan, telemetryNow } from "../src/index.ts";
import { telemetryStoreConformance } from "./store-conformance.ts";
afterEach(() => vi.restoreAllMocks());
@@ -42,6 +42,23 @@ describe("in-memory store snapshots", () => {
expect(telemetry.getSpans()[0]).not.toHaveProperty("startedMs");
});
+ it("stamps starts with telemetryNow: spans of one millisecond apart to the microsecond, in their order", async () => {
+ vi.spyOn(Date, "now").mockReturnValue(1000);
+ const clock = vi.spyOn(performance, "now").mockReturnValue(100);
+ const telemetry = new InMemoryTelemetryContext();
+ await telemetry.startSpan({ name: "first" }, () => {
+ clock.mockReturnValue(100.25);
+ });
+ await telemetry.startSpan({ name: "second" }, () => {
+ clock.mockReturnValue(100.5);
+ });
+ const spans = (await telemetry.findTraces()).traces.flatMap((trace) => trace.spans);
+ expect(spans.map(({ name, startedMs, endedMs }) => [name, startedMs, endedMs])).toEqual([
+ ["second", 1000.25, 1000.5],
+ ["first", 1000, 1000.25],
+ ]);
+ });
+
it("maps raw metric measurements to count-one rows without exposing private timing in getMetrics", async () => {
vi.spyOn(Date, "now").mockReturnValue(20_001);
const telemetry = new InMemoryTelemetryContext();
@@ -80,3 +97,32 @@ describe("in-memory store snapshots", () => {
expect(fresh.status).toEqual({ status: "error", error: { name: "Expected", message: "original" } });
});
});
+
+describe("telemetryNow", () => {
+ it("counts sub-millisecond steps of the monotonic clock while the wall clock stays in its millisecond", () => {
+ vi.spyOn(Date, "now").mockReturnValue(50_000);
+ const clock = vi.spyOn(performance, "now").mockReturnValue(1000.25);
+ const first = telemetryNow();
+ clock.mockReturnValue(1000.2504);
+ expect(telemetryNow() - first).toBeCloseTo(0, 6);
+ clock.mockReturnValue(1000.7512);
+ expect(telemetryNow() - first).toBeCloseTo(0.501, 6);
+ expect(Number.isInteger(telemetryNow() * 1000)).toBe(true);
+ });
+
+ it("follows a step of the wall clock (set, or a sleep the monotonic clock did not count) past 10 ms", () => {
+ // Far from the anchor any earlier call left: anchored anew, at the wall clock's millisecond.
+ const wall = vi.spyOn(Date, "now").mockReturnValue(80_000);
+ const clock = vi.spyOn(performance, "now").mockReturnValue(1000);
+ expect(telemetryNow()).toBe(80_000);
+ clock.mockReturnValue(1003.5);
+ wall.mockReturnValue(80_005);
+ // Within 10 ms the anchored clock keeps its own spacing.
+ expect(telemetryNow()).toBe(80_003.5);
+ clock.mockReturnValue(1004);
+ wall.mockReturnValue(3_650_004);
+ expect(telemetryNow()).toBe(3_650_004);
+ clock.mockReturnValue(1004.125);
+ expect(telemetryNow()).toBe(3_650_004.125);
+ });
+});