sscoble/pi-mono
1
0
Fork 0
mirror of https://github.com/badlogic/pi-mono.git synced 2026-11-05 23:37:25 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions 4

feat(chord): telemetry, spans across hosts (slice 9)

Browse source 
Chord's telemetry schema; spans for calls, methods, relays, holds, activations, natives, loads, reloads, resolves,
revocations, routines, jobs and HTTP requests; trace carriers on hold and call (bounded, printable ASCII) continued by
relays and workers; events and host-wide metrics; the app kit passes an adapter to its hosts. renderTrace escapes
control characters. Example 62 prints a trace across three hosts.
This commit is contained in:
Mario Zechner 2026-11-04 10:02:47 +00:00
parent ee962fb4db
commit 378d45a05b
76 changed files with 3929 additions and 241 deletions
Download patch file Download diff file Expand all files Collapse all files

2
packages/chord/CHANGELOG.md
View file

@ -21,6 +21,8 @@
- Chord v2 gains live queries: `self.query(table, q, limit)` in the factory of a table's owner is a watchable of the query's rows (at most `limit`, in its order), usable as a state member and a derive source. Chord runs it before the object goes live and again inside the commit step of every commit of the object that writes the table, publishing only the diff in that commit's batch; a commit writing no table with a live query runs nothing (`chord.query.runs` counts the runs). Only the object's own tables; the limit is required (`invalid/args` at declaration). A run that fails (a row the code cannot read) is a failed member, reported once as the new `HostError` `query_failed { object, table, error }`, and heals at the next good run. A live query is no native, so an object showing table rows live swaps on reload instead of restarting, as reading them in `self.open` made it. Each touching commit runs the query once (100 rows: about 60 µs, 80 µs watched): not for tables written hundreds of times a second.
- Chord v2 gains messages and languages in the app kit (design §23): `defineMessages(namespace, { en: {...}, de: {...} })` returns a typed `t(key, ...args)` (the first catalog types the others: a missing key, an unknown one or a wrong argument is a type error; values are strings or functions), `t.message(key, ...args)` builds a message as data (`MessageData`, `{ namespace, key, params }`, for state members typed with `MessageSchema`), `t.render(message)` renders one (a foreign namespace or an unknown key from a link shows the key), `t.translations` lists its catalogs, and `MessagesOf<typeof t>` types a translation. The `Translations` registry takes a list of `{ namespace, locale, messages, override? }` per contributor (one catalog per namespace and locale: the first by plugin name wins, reported; `override: true` wins); a missing key falls back down the locale's chain (`pt-BR`, `pt`) to the first catalog, reported once. `LocaleChoice` keeps one locale per principal on the server (the theme choice's store, now shared as one preference); a client follows it with `followActiveLanguage`, defaulting to `navigator.languages` on a page and the system locale in the terminal (`startTerminal`'s `locales`), matched against the catalogs, switched live. `useMessages(t)` (`/react`) and `TuiScope.messages(t)` (`/tui`) render in the host's language and re-render or redraw on a change; `startPage` sets `lang` and `dir` on the page (`followLanguage`, `/web`); `formatTime` and `formatNumber` use `Intl` in the language being rendered. The kit serves `Translations` on the server, workers, pages and terminals and `LocaleChoice` on the server; client errors gain `{ kind: "messages", report }`.
- Chord v2 gains telemetry across hosts (slice 9): `CHORD_TELEMETRY_SCHEMA` (root export) types every span, event and metric Chord records. With a host adapter (`createHost({ telemetry })`), calls (`chord.call`), methods (`chord.method`, local and remote), relays (`chord.relay`), holds (`chord.hold`), activations (`chord.activate`, ending `live`, `failed`, `parked` or `ended`, with `chord.retry` and `chord.park` events), natives' opens and closes, `load`, `reload` (a `chord.reload.fate` event per object), resolves (a worker start included), revocations, routine calls, job phases (`intent`, `run`, `finish`: a persisted run resumed in a new attempt or process stays under its stored carrier) and HTTP requests (`chord.http`: method, route pattern, status, never the path) are spans; failures carry a fixed category and the message cut at 500 characters, a cancel is no error; commits are `chord.commit { documents, ops, duration }` events of the span they ran under. `hold` and `call` carry the caller's trace carrier (`trace`, at most 8 keys, keys and values of at most 256 characters of printable ASCII, else the message fails the message schema and the link closes; the binary codec's kind byte flag `0x40`), relays forward their own span's, and the provider runs the method under it (an absent or unknown carrier: the adapter's root); a reference's carrier rides on its first hold only, a re-hold after a reconnect being a fresh root linked to it. A hold's `type` and its address's `kind` are bounded at 256 characters by the message schema, and span attributes a peer chose at 256 characters. `ctx.trace(name, attributes, fn)` runs `fn` in a child span with a child ctx. Host-wide metrics: `chord.link.bytes`, `chord.link.state_messages`, `chord.commit.duration`, `chord.calls.in_flight`, `chord.holds.active`, `chord.links.open`, `chord.park.duration`, `chord.backpressure.wait`. Without an adapter nothing is started, built or sent: a call over a link costs what it did before. `createHttp`, `startServer` and `startWorker` take a `telemetry` adapter (`createHttp` continues a W3C `traceparent` only from a request a contributed relay verified: an app's proxy must strip it from browsers). A host with an adapter counts the cost counters of its links' and root scopes' work on it also when the app passed a context without a span. The SQLite telemetry store keeps spans of one millisecond in the order they started.
### Changed
- Chord v2's HTTP component denies by default (slice 13): a request or plugin socket without a principal gets 401 before plugin code runs unless its route or socket is marked `public: true` (`{ handler, public: true }`; a `crossSite` route is public), and the `/chord` links endpoint refuses requests without a principal.

40
packages/chord/docs/benchmarks.md
View file

@ -994,3 +994,43 @@ The diff depends on the reuse: with every row decoded anew, `diffRevisions` comp
previous 100 by content and the watched commit took 885 µs; with unchanged rows the same objects it compares them by
identity. "There may be dragons": at 100 rows a table written more than a few thousand times a second spends most of
its time in the query.
## Slice 9: telemetry (2026-11-04)
`test/bench/telemetry.ts`, Node 24.4.1, CPU 10, medians of nine bursts after a warm-up, three runs each; heap
allocated per operation includes what the collections during a burst freed. "Before" is the same script (`--noop`,
its imports pointed at a checkout of the commit before slice 9) run alternately with this one.
A call over a memory link (a client host holding a remote counter on a server host; `bump` returns at once, `add`
commits one document change):
| Call | Before slice 9 | NOOP adapter | In-memory adapter on both hosts |
| --- | --- | --- | --- |
| over a link | 10.46-10.64 µs, 13,083 B | 10.24-10.30 µs, 12,766 B | 31.3 µs, 28,886 B |
| that commits | 32.91-34.06 µs, 28,898 B | 31.44-31.61 µs, 28,598 B | 64.6 µs, 53,902 B |
With the NOOP adapter the span code is within noise (the target): every span site is one identity check of its parent
against the NOOP context's span starter, and nothing else runs (no span, no attribute object, no carrier). A call
allocates 317 B less than before slice 9 (300 B less for one that commits), from the review's three code shapes (fix
round): the call message takes its optional `trace` as a plain key (a key holding `undefined`, which both codecs and the
schema treat as absent) instead of a conditional spread, `ChordObject.call`'s optional `parent` has no default
expression (an async function with a non-simple parameter list allocated 48 B more), and `ProviderSide.#run` is a
`.then` chain instead of an `async` function (its frame, about 85 B, held the extra argument). The first build's 206 B
more per call were these shapes, not the `trace` field. Recording costs what the adapter does: the in-memory one keeps
every span and measurement (each call records `chord.call`, `chord.method`, the commit's event, the host metrics,
`chord.link.bytes` per message and, since the fix round, the links' cost counters on the host's adapter), about 21 µs
and 16 KB per call here.
Container width (R24, design §12): one item of a flat array changed per commit (a new text each time), alone and
under a watched `mapShared` derive of the array (one mapper run per change: only the changed item is mapped again;
the derive still visits every element once by identity and `diffRevisions` compares the arrays):
| Width | One item changed | Under a watched `mapShared` derive |
| --- | --- | --- |
| 1,000 | 43.7-45.8 µs, 27.8 KB | 89.0-97.5 µs, 40.8 KB |
| 10,000 | 84.5-88.7 µs, 131.7 KB | 299.8-310.0 µs, 262.8 KB |
| 100,000 | 552.5-670.1 µs, 819.7 KB | 3,711-4,197 µs, 1,624.8 KB |
A change costs O(width): the array's slots are copied (about 8 bytes per element) and a derive over it walks them. The
documented limit: up to about 10,000 elements a list in one document stays below 0.3 ms per change with a derive; past
that, keyed documents or a bounded window (design §12) keep commits O(change).

88
packages/chord/docs/design.md
View file

@ -912,8 +912,11 @@ Every handler gets a `ctx` (a `Context`): `telemetry` (the current span, section
cancelled or the object ended; there is no per-call deadline), `principal` (the caller as its link stamped it; on a
local object's handler the host's principal, none on a client), `incarnation` (the calling host's, section 4), and
`get(Type, params, { readyTimeout? })` (references as the caller sees them, released when the handler settles; a
`get` after that throws `released`). Later: `ctx.trace(name, attributes, fn)` gives `fn` a child `ctx` under a child
span (slice 9, cut C11 to decide); in a job's `run` also `jobId` and `state` (slice 5). Pass `ctx` to everything you wait
`get` after that throws `released`), and `trace(name, attributes, fn)`: `fn` in a child span of `ctx.telemetry` with a
child `ctx` (the same principal, incarnation, signal and `get`, its references the handler's), so calls inside are
parented under it; a throw marks the span failed (`trace_failed`) and is rethrown; without an adapter that records,
`fn` gets `ctx` itself (slice 9; round-3 cut C11 kept, as this section already stated it); in a job's `run` also `jobId`
and `state` (slice 5). Pass `ctx` to everything you wait
on. Code outside objects gets a `ctx` from `host.root` (slice 8). Durable's `Context` is the same module
(`../context`); bridging is explicit. No code versions, no request ids.
@ -2207,8 +2210,17 @@ validation, no clone of snapshots or ops.
The asynchronous inflate runs one part at a time; the queue behind it is bounded by the sending peer's window and N,
so only a misbehaving parent or route peer could grow it (accepted: those are the app's own hosts). The adapter reports "too large"
and "corrupt" as a tagged result. Limits and the threshold count bytes. No per-link compression.
- **Trace carriers (R5; slice 9)** are an optional bounded field of `call` and `hold` (key count, string lengths);
relays read them from the envelope.
- **Trace carriers (R5; slice 9)** are an optional field `trace` of `call` and `hold`: an adapter's string record of at
most 8 keys, keys and values of at most 256 characters of printable ASCII (keys without spaces; W3C's headers and
Chord's adapters fit); past the bounds, with a control character or not a string record, the message fails `MESSAGE`
as any malformed header and the link closes (a trusted link skips the check; the adapter's `extract` then checks it).
A carrier names stored trace and parent ids, so no control character reaches a renderer (and `renderTrace` escapes
them anyway). Names a relay records unparsed are bounded the same way: a hold's `type` and its address's `kind` have
at most 256 characters. The
binary codec flags it in the kind byte (`0x40`, beside the origin's `0x80`) and writes it as JSON after the origin;
the text codec writes it as the last element (a hold's after `limit`, absent ones before it `null`; a call's after its
payload, whose two fields are then positional, `null` when absent). Relays read it from the envelope and forward
their own span's carrier (a relay recording nothing forwards it as it came). `PROTOCOL_VERSION` stays 1.
- **Adapted bindings get diffs** (slice 7b; decision "References are the only indirection" (5)): a consumer bound
through `accepts` attaches to the object instance's shared mapping for its version: per member one derive of the
instance's member through `(current) => old` (a changed member), of its whole state (a removed member), or the
@ -2598,7 +2610,6 @@ this document):
| 16 | a Durable Object profile | 24 | when a DO target becomes concrete |
| 24 | a per-type drain override: a host option or fixed (no install watchdog: `reload` takes the app's context, decision "Slice 7b's open points" (4); the routine handover uses `closeTimeout`; a failing job `finish` backs off 1-60 s and blocks after five failures, decided) | 3 | if a real case needs it |
| 28 | Astra's circuit breaker (a hard transport-buffer cap plus a stall deadline); the heartbeat is built, the cap was never decided | 3 | if a real case needs it |
| 29 | round-3 cut C11 (`ctx.trace`); C3 and C4 are decided (§14, §15) | 8 | slice 9 |
Apps (p3), from the functionality map, decided per domain when p3 is designed:
@ -2736,7 +2747,72 @@ Chord reports traces, events and metrics through `@earendil-works/pi-telemetry`;
(`pi-telemetry/render`) prints links and never follows them. A web trace viewer in the playground reads the store.
- **Durable** (done): submit and phase spans, stored carriers on submissions and tasks (`TaskOptions.trace`, creation
links), events after commit, report events; pi-ai emits `pi.ai.request`/`pi.ai.poll` from one observer in
`lazyStream`. Persisted Chord jobs store their start carrier.
`lazyStream`. Persisted Chord jobs store their start carrier. A worker's Harness gets its host's adapter
(`HarnessOptions.telemetry`) and a method that submits input passes its `ctx` (its `telemetry` the `chord.method`
span), so `pi.durable.submit` links to it and starts its own trace, as decided.
**Built (slice 9, `slice-9.md`; `src/telemetry.ts`):**
- **The schema:** `CHORD_TELEMETRY_SCHEMA` (root export, `defineTelemetrySchema`) declares every span, event and metric
Chord records with its attributes; the cost counters (`chord.data.*`, `chord.link.*`, `chord.store.*`,
`chord.query.runs`, `chord.cycle.visits`, `chord.derive.*`, `chord.registry.*`, `chord.contract.adapts`) are recorded
through it (`chordMetrics(metrics)`: typed instruments made once per adapter's metrics object and name, a `WeakMap`;
the NOOP metrics share one set). Ids (object labels, run ids, address keys) are span attributes only.
- **Spans:** `chord.call` (a consumer's call of a remote member, until its reply), `chord.method` (a provider running a
method: under the call's carrier over a link, the caller's span on the same host; in `Attempt.call`, so local and
remote calls alike), `chord.relay` (a relayed hold until it is held upstream, a relayed call until its reply is
forwarded; the member is `hold` or `#<index>`: a relay never knows names), `chord.hold` (a remote reference's hold
until its first `bound` or failure; its carrier rides on the reference's first hold only: a re-hold after a reconnect
is a fresh `chord.hold` root of the host's adapter linked to the first, and a relay's re-hold upstream after a drop a
fresh `chord.relay` root linked to its first, so a page kept open for days never adds children under a span long
ended), `chord.activate`,
`chord.open` (under the activation), `chord.close` (a root), `chord.load`, `chord.reload` (a `chord.reload.fate`
event per object), `chord.resolve`, `chord.revoke` (recorded after the synchronous revocation, its `count`),
`chord.routine` (a root per call), `chord.job` (`intent` under the starter, `run` and `finish` under the start's
carrier), `chord.http`. Outcomes are attributes; a failure is `status: "error"` with a fixed category (`call_failed`,
`method_failed`, `relay_failed`, `hold_failed`, `activation_failed`, `open_failed`, `close_failed`, `load_failed`,
`reload_failed`, `resolve_failed`, `routine_failed`, `job_failed`, `http_failed` for a status of 500 or more,
`trace_failed`) and the message cut at 500 characters; a cancel (the caller's signal, `aborted`, an open its attempt
abandoned) sets status ok explicitly (an adapter marks a span failed when its callback throws). String attributes a
peer chose (an object's label with its params key, an address key, a principal's kind, names from the wire) are cut
at 256 characters: stores keep them for days.
- **Activations:** one span per attempt on the host's adapter, linked to the object's first trigger (the span that
created it, or a hold's carrier), a retry's to the attempt before it; it ends `live`, `failed` (a transient failure's
backoff a `chord.retry` event) or `ended`, or `parked` with a `chord.park { cause }` event, and a parked attempt's own
steps resume in a new span linked to the parked one (spans stay short); one that fails or ends while still parked
records it in a short span linked to the parked one. A getter binding to an object while it
activates links its span to the activation (shared work); a route's first hold links to its resolve and back.
- **Parents across processes are carriers, not spans:** a settled span starts no recorded children, so whatever runs
later under work that has ended (a job's run and finish, a re-hold) goes through a carrier extracted with the host's
adapter. Every job run keeps its start's carrier (a persisted one stores it): a run resumed in a new attempt or
process stays in its trace.
- **`ctx.trace`** gives `fn` a child of the same kind (a job run's keeps `jobId` and `state`), and a synchronous throw of
`fn` rejects whether or not anything records: recording changes nothing `fn` sees but its span.
- **Routines:** each call's span links to the span of the commit that changed its source when the watch frame's
context names one (the newest folded frame's; the first call, with the current value, has none), and a call that
threw carries its backoff as a `chord.retry` event.
- **Cost (§30):** a span site checks `untraced(parent)` (the parent starts spans as the NOOP context does: no adapter can
record) and then
starts no span, builds no attribute object and injects no carrier; with the NOOP adapter a call over a link is within
noise of the code before slice 9 (`benchmarks.md`). A recording host's call costs its spans (`OpenSpan`, a span kept
open until its work's promise settles).
- **Events and metrics:** `chord.commit { documents, ops, duration }` on the span of the context a transaction ran
under (a method, a routine, a job phase, an HTTP request), only for a commit that changed something; the host-wide
metrics go to the host's adapter (`host.metrics`), not to a context: `chord.link.bytes { direction }` (every encoded
message of the host's links), `chord.link.state_messages`, `chord.commit.duration`, `chord.calls.in_flight`,
`chord.holds.active`, `chord.links.open`, `chord.park.duration`, `chord.backpressure.wait`. The cost counters still
count through the context of the work; a host with an adapter gives its links' and root scopes' work, when the app
passed a context without a span (`BACKGROUND_CONTEXT`, as the kit does), a span that records nothing but carries the
adapter's metrics (`countingOnly`), so they reach the adapter in an app too.
- **Components:** `createHttp({ telemetry })` makes each routed request a `chord.http` root (method, route pattern,
status; never the path), its scope's `ctx` under it; a W3C `traceparent` (with its `tracestate`) is extracted (as the
carrier `{ traceparent, tracestate }`) only from a request a contributed relay verified, each header at most 256 and
512 characters of printable ASCII (else ignored). A verified relay vouches for the proxy, not the browser behind it:
an app's proxy must strip `traceparent` and `tracestate` from browsers' requests (or set its own), or a browser
chooses the trace its requests join. `startServer({ telemetry })` passes the adapter to
its host and HTTP; `startWorker({ telemetry })` to its host. Each process exports to the store it is given; a shared
SQLite file per data directory is the app's choice (example 62). The SQLite store orders spans of one millisecond as
their recorder started them (by start time, then id length and id).
## 30. Cost model

56
packages/chord/docs/guide-plugins-hosts/book.md
View file

@ -13,7 +13,7 @@ note: |
`slice-10.md`, `slice-12.md`, `slice-13.md`, the decision log and the code in `packages/chord/src`. API names
are the current ones. The early chapters wire hosts by hand to show the parts; the last chapter shows the app kit
(`chord/app`), which does that wiring for an app.
colophon: Hosts and Plugins · third edition · 2026-11-03 · Chord v2 slices 1-10, 12 and 13, messages and languages
colophon: Hosts and Plugins · fourth edition · 2026-11-04 · Chord v2 slices 1-13, messages and languages, telemetry
---
# Before we begin {.preface}
@ -809,6 +809,60 @@ writes them as one archive (a manifest, the store's export, the files) and stops
own store at one consistent point. `app.importData(path, Project({ id: "copy" }), ctx)` makes a new project from it and
refuses one that already has data (example 55).
# Seeing a Request Across Hosts {#telemetry lede="One trace from a click in a client through the server's relay into a worker's method: adapters, carriers and spans."}
A tab calls `notes.add(…)`. The call leaves the tab, the server relays it, the project's worker runs the method, the
method commits. When it is slow, where did the time go? Each host is a different process, so no single log has the
answer. Chord's telemetry makes the four steps one **trace**: a tree of **spans** (named, timed pieces of work), each
host recording its own with its own **adapter**, joined by **carriers** (a few strings naming the caller's span) that
ride on the wire with every `hold` and `call`.
Give each host an adapter. With the app kit that is one option per process; the SQLite store
(`@earendil-works/chord/telemetry-sqlite`) records settled spans and metrics, and here every process of the app opens
the same file in the data directory (example 62):
```ts
// start.ts: the server
const telemetry = await createSqliteTelemetry(await openNodeSqliteDatabase(join(dataDir, "telemetry.sqlite")));
await startServer({ ...options, telemetry }, ctx);
// worker.ts: each worker, its own recorder on the same file (the path in its environment)
startWorker({ api, kinds, telemetry: await openTelemetry(process.env.TALLY_TELEMETRY!), onError });
```
Nothing else changes in plugin code. A method's `ctx.telemetry` is its `chord.method` span, so whatever it calls or
commits is parented under it, on its host or the next one. `ctx.trace(name, attributes, fn)` adds a span of your own:
```ts
add: async (n, ctx) => {
await ctx.trace("tally.check", { n }, async () => {
if (!Number.isSafeInteger(n) || n <= 0) throw new Error("add a positive count");
});
return store.add(n, ctx);
},
```
The store renders the click's trace across the three hosts (the client's spans, the server's relay, the worker's
methods and the commit, an event of the method that made it):
```
tally.click
chord.hold type="tally.counter" object="tally.counter(t1)" address.kind="tally" outcome="bound"
chord.relay type="tally.counter" member="hold" upstream.kind="tally" outcome="ok"
→ link to chord.resolve
chord.call type="tally.counter" member="add" object="tally.counter(t1)" address.kind="tally" outcome="ok"
chord.relay type="tally.counter" member="#0" upstream.kind="tally" outcome="ok"
chord.method type="tally.counter" member="add" object="tally.counter(t1)" principal.kind="owner" outcome="ok"
tally.check n=3
chord.method type="tally.store" member="add" object="tally.store" principal.kind="worker" outcome="ok"
· chord.commit documents=1 ops=1 duration=1.9
```
Work shared by several requests is its own trace, linked rather than nested: the worker's start (`chord.resolve`),
an object's activation (`chord.activate`, linked to whoever asked first). Routines and job phases are roots too; a job's
`run` and `finish` stay under the carrier its start stored, even when a restarted worker resumes the run. Metrics
(`chord.link.bytes`, `chord.commit.duration`, `chord.calls.in_flight`, ...) are aggregated per 10 s; ids are never their
attributes. Without an adapter (the default), Chord starts no span and sends no carrier: a call costs what it did before.
# Reference {.appendix}
| Call | What it does |

44
packages/chord/docs/guide-plugins-hosts/index.html
View file

@ -131,6 +131,7 @@ are the current ones. The early chapters wire hosts by hand to show the parts; t
<li><a href="#reload">VIII. Changing a Plugin</a></li>
<li><a href="#base">IX. Base Code and Plugins</a></li>
<li><a href="#kit">X. The App Kit</a></li>
<li><a href="#telemetry">XI. Seeing a Request Across Hosts</a></li>
<li><a href="#reference">Appendix A: Reference</a></li>
</ol></nav>
@ -727,6 +728,47 @@ own store at one consistent point. <code>app.importData(path, Project({ id: &quo
refuses one that already has data (example 55).</p>
</section>
<section class="chapter" id="telemetry"><header class="opener"><div class="numeral">XI</div><h2>Seeing a Request Across Hosts</h2><p class="lede">One trace from a click in a client through the server&#39;s relay into a worker&#39;s method: adapters, carriers and spans.</p></header>
<p class="dropcap">A tab calls <code>notes.add(…)</code>. The call leaves the tab, the server relays it, the project&#39;s worker runs the method, the
method commits. When it is slow, where did the time go? Each host is a different process, so no single log has the
answer. Chord&#39;s telemetry makes the four steps one <strong>trace</strong>: a tree of <strong>spans</strong> (named, timed pieces of work), each
host recording its own with its own <strong>adapter</strong>, joined by <strong>carriers</strong> (a few strings naming the caller&#39;s span) that
ride on the wire with every <code>hold</code> and <code>call</code>.</p>
<p>Give each host an adapter. With the app kit that is one option per process; the SQLite store
(<code>@earendil-works/chord/telemetry-sqlite</code>) records settled spans and metrics, and here every process of the app opens
the same file in the data directory (example 62):</p>
<pre><code><span class="tk-c">// start.ts: the server</span>
<span class="tk-k">const</span> telemetry = <span class="tk-k">await</span> <span class="tk-f">createSqliteTelemetry</span>(<span class="tk-k">await</span> <span class="tk-f">openNodeSqliteDatabase</span>(<span class="tk-f">join</span>(dataDir, <span class="tk-s">"telemetry.sqlite"</span>)));
<span class="tk-k">await</span> <span class="tk-f">startServer</span>({ ...options, telemetry }, ctx);
<span class="tk-c">// worker.ts: each worker, its own recorder on the same file (the path in its environment)</span>
<span class="tk-f">startWorker</span>({ api, kinds, telemetry: <span class="tk-k">await</span> <span class="tk-f">openTelemetry</span>(process.env.TALLY_TELEMETRY!), onError });</code></pre>
<p>Nothing else changes in plugin code. A method&#39;s <code>ctx.telemetry</code> is its <code>chord.method</code> span, so whatever it calls or
commits is parented under it, on its host or the next one. <code>ctx.trace(name, attributes, fn)</code> adds a span of your own:</p>
<pre><code>add: <span class="tk-k">async</span> (n, ctx) =&gt; {
<span class="tk-k">await</span> ctx.<span class="tk-f">trace</span>(<span class="tk-s">"tally.check"</span>, { n }, <span class="tk-k">async</span> () =&gt; {
<span class="tk-k">if</span> (!<span class="tk-t">Number</span>.<span class="tk-f">isSafeInteger</span>(n) || n &lt;= <span class="tk-n">0</span>) <span class="tk-k">throw</span> <span class="tk-k">new</span> <span class="tk-t">Error</span>(<span class="tk-s">"add a positive count"</span>);
});
<span class="tk-k">return</span> store.<span class="tk-f">add</span>(n, ctx);
},</code></pre>
<p>The store renders the click&#39;s trace across the three hosts (the client&#39;s spans, the server&#39;s relay, the worker&#39;s
methods and the commit, an event of the method that made it):</p>
<pre><code>tally.click
chord.hold type="tally.counter" object="tally.counter(t1)" address.kind="tally" outcome="bound"
chord.relay type="tally.counter" member="hold" upstream.kind="tally" outcome="ok"
→ link to chord.resolve
chord.call type="tally.counter" member="add" object="tally.counter(t1)" address.kind="tally" outcome="ok"
chord.relay type="tally.counter" member="#0" upstream.kind="tally" outcome="ok"
chord.method type="tally.counter" member="add" object="tally.counter(t1)" principal.kind="owner" outcome="ok"
tally.check n=3
chord.method type="tally.store" member="add" object="tally.store" principal.kind="worker" outcome="ok"
· chord.commit documents=1 ops=1 duration=1.9</code></pre>
<p>Work shared by several requests is its own trace, linked rather than nested: the worker&#39;s start (<code>chord.resolve</code>),
an object&#39;s activation (<code>chord.activate</code>, linked to whoever asked first). Routines and job phases are roots too; a job&#39;s
<code>run</code> and <code>finish</code> stay under the carrier its start stored, even when a restarted worker resumes the run. Metrics
(<code>chord.link.bytes</code>, <code>chord.commit.duration</code>, <code>chord.calls.in_flight</code>, ...) are aggregated per 10 s; ids are never their
attributes. Without an adapter (the default), Chord starts no span and sends no carrier: a call costs what it did before.</p>
</section>
<section class="chapter appendix" id="reference"><header class="opener"><div class="numeral">A</div><h2>Reference</h2></header>
<table>
<thead>
@ -798,7 +840,7 @@ refuses one that already has data (example 55).</p>
</tbody></table>
</section>
<p class="colophon">Hosts and Plugins · third edition · 2026-11-03 · Chord v2 slices 1-10, 12 and 13, messages and languages</p>
<p class="colophon">Hosts and Plugins · fourth edition · 2026-11-04 · Chord v2 slices 1-13, messages and languages, telemetry</p>
</div></div>
<script>(function activate(root) {
const replay = (f) => {

12
packages/chord/docs/slices.md
View file

@ -46,6 +46,11 @@ slice spec's section citations are for orientation, not a reading limit (owner,
launcher and its child-process sandbox); examples 56-59.
- **Live queries** (built 2026-11-03, decision "Live queries over an object's own tables"): `self.query` in
`src/store/live-query.ts`; examples 59 and 61 use it; `test/bench/live-query.ts`.
- **Slice 9** (built 2026-11-04, `slice-9.md`): telemetry, `src/telemetry.ts` (`CHORD_TELEMETRY_SCHEMA`, the span sites'
NOOP rule, open spans, typed instruments), spans of calls, methods, relays, holds, activations, natives, loads,
reloads, resolves, revocations, routines, job phases and HTTP requests, carriers on `hold` and `call`, `ctx.trace`,
commit events and the host-wide metrics, `telemetry` options of `createHttp`, `startServer` and `startWorker`;
example 62; `test/bench/telemetry.ts` (with R24's container width).
- **Chord's shared code** (upstream pi): `src/watch.ts` (`Watch`, `NativeWatch`, `WatchHandle`, `WatchEnd`,
`NativeWatchable`), Delta (`track`, `diffRevisions`, `applyImmutable`, encoders, `PendingOps`, `appendText`),
context, JSON, output, SQLite drivers.
@ -219,13 +224,6 @@ deleted (the slice's spec and code are the record). Moved here from `carry-over.
- **Small examples** (owner, 2026-10-30: the 7c examples are complete but complex): once HTTP, workers, web and TUI
exist, a pass of small, easy-to-read examples, each showing one thing a plugin author or app does.
### Slice 9: telemetry
- Spans for routine calls and job runs (from slice 5).
- The use of a persisted run's stored start trace carrier (`trace`, stored since slice 6b).
- Round-3 cut to decide: C11 (`ctx.trace`).
### When v2 goes upstream
- `mapShared` lives in `src/state/derive.ts` and moves into Delta. (L2 decisions.)

3
packages/chord/src/data/principal.ts
View file

@ -2,6 +2,7 @@
import type { Context } from "../context/index.ts";
import type { JsonValue } from "../json.ts";
import { chordMetrics } from "../telemetry.ts";
/** An app's principal: plain JSON with a `kind`. Chord never persists it. */
export type Principal = { readonly kind: string; readonly [field: string]: JsonValue };
@ -42,7 +43,7 @@ function customKeyCache(customKey: PrincipalKeyFunction<never>): WeakMap<Princip
/** Canonical JSON: sorted object keys, `-0` written as `0`. Counts one walk. */
export function canonicalJson(value: JsonValue, context: Context): string {
context.telemetry.metrics?.counter("chord.data.walks").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.walks").add(1);
return canonical(value);
}

7
packages/chord/src/data/validator.ts
View file

@ -2,6 +2,7 @@
import { compile, type JsonSchema, type Validator } from "@earendil-works/pi-schema";
import type { Context } from "../context/index.ts";
import { chordMetrics } from "../telemetry.ts";
import { type ChordError, invalid } from "./errors.ts";
/** A Chord-owned record holding a schema: a snapshot, or a contract's params. */
@ -11,7 +12,7 @@ type SchemaOwner = { readonly schema: JsonSchema };
export function validatorFor(owner: SchemaOwner, context: Context): Validator {
let validator = validators.get(owner);
if (validator === undefined) {
context.telemetry.metrics?.counter("chord.data.compilations").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.compilations").add(1);
// `format` is an annotation (decided for the schema switch): no format checks are compiled in.
validator = compile(owner.schema);
validators.set(owner, validator);
@ -28,7 +29,7 @@ export function check(
reason: "args" | "params" | "host_address",
context: Context,
): void {
context.telemetry.metrics?.counter("chord.data.validations").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.validations").add(1);
if (!validator.check(value)) throw failedCheck(validator, value, reason, context);
}
@ -43,7 +44,7 @@ function failedCheck(
reason: "args" | "params" | "host_address",
context: Context,
): ChordError {
context.telemetry.metrics?.counter("chord.data.walks").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.walks").add(1);
// A value that failed the check has at least one error.
const error = validator.errors(value)[0]!;
const path = error.path || "/";

3
packages/chord/src/documents/definition.ts
View file

@ -8,6 +8,7 @@ import { snapshotSchema } from "../contracts/snapshot.ts";
import { validatorFor } from "../data/internal.ts";
import type { Op } from "../delta/index.ts";
import type { JsonValue } from "../json.ts";
import { chordMetrics } from "../telemetry.ts";
/** A document root: a JSON object. */
export type JsonObject = { [key: string]: JsonValue };
@ -158,7 +159,7 @@ export class StateDefinition<T extends JsonObject, K extends boolean, P extends
}
#check(value: T, what: string, context: Context): void {
context.telemetry.metrics?.counter("chord.data.validations").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.validations").add(1);
if (!validatorFor(this, context).check(value)) {
throw new Error(`${this.name}: ${what} does not match the schema`);
}

22
packages/chord/src/documents/documents.ts
View file

@ -1,11 +1,13 @@
// An object's documents (§9, P2, slice 6a §1.2, §10): its slots across attempts, its line (its transactions and line
// jobs run one at a time), the seal fence over the transaction holding the line, the factory's pins between attempts,
// the activation's loads and the residency of keyed documents.
// the activation's loads and the residency of keyed documents; a commit's telemetry (its event, its duration, slice 9).
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import type { Context } from "../context/index.ts";
import { ChordError } from "../data/index.ts";
import type { Batch } from "../state/internal.ts";
import type { ChordStore } from "../store/store.ts";
import { chordMetrics, untraced } from "../telemetry.ts";
import type { CommitPersistence, JsonObject, StateDefinition } from "./definition.ts";
import { SealToken } from "./fence.ts";
import { type HandleOf, type KeyDeclarer, Keyed, Singleton } from "./handles.ts";
@ -44,6 +46,8 @@ export type DocumentsOwner = {
fail(error: ChordError): void;
/** Reports a transaction its context's end cancelled (the host's `onError`). */
report(error: TransactionCancelled): void;
/** The host's telemetry adapter: commit durations go to its metrics. */
readonly telemetry: TelemetryContext;
};
/**
@ -180,9 +184,13 @@ export class Documents {
this.assertAdmitted(token);
this.#holder = tx;
const result = await fn(tx);
// Timed only when something records: the commit's duration metric, its event on the enclosing span.
const timed = !untraced(this.#owner.telemetry) || !untraced(context.telemetry);
const started = timed ? performance.now() : 0;
// In-memory-only commits are synchronous (W12): no await unless the store's step is taken.
const step = tx.commit();
if (step !== undefined) await step;
if (timed) this.#recordCommit(tx, performance.now() - started, context);
return result;
} catch (error) {
tx.discard();
@ -198,6 +206,18 @@ export class Documents {
}
}
/**
* A commit of `tx` that took `duration` ms (from its start to its adoption): its event on `context`'s span (the
* method, routine or job it ran in) and the host's commit duration metric; a commit that changed nothing records
* nothing.
*/
#recordCommit(tx: Transaction, duration: number, context: Context): void {
const { documents, ops, writes } = tx.committed();
if (documents === 0 && writes === 0) return;
if (!untraced(context.telemetry)) context.telemetry.addEvent("chord.commit", { documents, ops, duration });
chordMetrics(this.#owner.telemetry.metrics).histogram("chord.commit.duration").record(duration);
}
/**
* Seals `token` (the seal fence): its transactions are refused from now on, and the one holding the line is
* discarded and the line released.

3
packages/chord/src/documents/persistence.ts
View file

@ -17,6 +17,7 @@ import {
} from "../store/engine.ts";
import type { StagedWrite } from "../store/step.ts";
import type { ChordStore } from "../store/store.ts";
import { chordMetrics } from "../telemetry.ts";
import type { JsonObject } from "./definition.ts";
import type { AnyDefinition } from "./slot.ts";
@ -76,7 +77,7 @@ export class Persistence {
const record = await findDocument(executor, address);
return record === undefined ? undefined : loadDocument(executor, record);
}, context);
if (document !== undefined) context.telemetry.metrics?.counter("chord.store.loads").add(1);
if (document !== undefined) chordMetrics(context.telemetry.metrics).counter("chord.store.loads").add(1);
return document;
}

10
packages/chord/src/documents/transaction.ts
View file

@ -142,6 +142,8 @@ export class Transaction implements Tx {
#state: "open" | "committing" | "stepping" | "committed" | "discarded" | "cut" = "open";
/** Rejected by `cut` while the commit waits in the store's queue: its caller is told at once (rule 3). */
#queued: PromiseWithResolvers<never> | undefined;
/** What its commit adopts, once it started (telemetry's `chord.commit` counts it when asked). */
#adoptions: readonly Adoption[] = [];
constructor(
documents: Documents,
@ -166,6 +168,13 @@ export class Transaction implements Tx {
return this.#writes.staged;
}
/** What its commit adopted: its documents, their ops and its store writes (all 0 before it committed). */
committed(): { readonly documents: number; readonly ops: number; readonly writes: number } {
let ops = 0;
for (const { prepared } of this.#adoptions) ops += prepared?.ops.length ?? 0;
return { documents: this.#adoptions.length, ops, writes: this.#writes?.staged.length ?? 0 };
}
/** The object whose transaction this is. */
get documents(): Documents {
return this.#documents;
@ -358,6 +367,7 @@ export class Transaction implements Tx {
}
}
const writes = this.#writes;
this.#adoptions = adoptions;
if (writes === undefined) {
this.#adopt(adoptions);
this.#state = "committed";

4
packages/chord/src/host/README.md
View file

@ -421,7 +421,9 @@ server.accept(webSocketLink(ws), { principal, limits: { part: 16 * MiB, decoded:
named it; on a local object's handler the host's), `incarnation` (the calling host's over a link, the origin's
through a relay, this host's otherwise, R20), `get(Type, params, { readyTimeout? })` (a reference as
`ctx.principal` sees it, with `ctx.incarnation`, also over a route; released when the handler settles; afterwards
`get` throws `released`), the abort signal (the caller cancelled or released, or the object ends) and telemetry.
`get` throws `released`), the abort signal (the caller cancelled or released, or the object ends), telemetry (the
handler's `chord.method` span when the host records) and `trace(name, attributes, fn)` (`fn` in a child span with a
child ctx: the same principal, signal and references; slice 9).
- `self.open(open, close, { closeTimeout? })` returns a `Native<T>`: its `value` is readable from the moment its open
resolved until its close starts; before, it throws `not_ready`, after, `released`. `open(ctx)` gets a context
aborted when the attempt is abandoned; `close(value, reason, ctx)` gets `{ kind: "end" | "close" | "reload" }` (end:

140
packages/chord/src/host/attempt.ts
View file

@ -5,7 +5,8 @@
// routines stop and hand over to the new attempt's, its jobs to the new attempt's, and it is sealed once its calls
// settled.
import { awaitWithContext, type Context, withAbortSignal } from "../context/index.ts";
import type { TelemetryContext, TelemetrySpan } from "@earendil-works/pi-telemetry";
import { awaitWithContext, type Context, withAbortSignal, withTelemetry } from "../context/index.ts";
import type { Contract, Implementation, ParamsOf } from "../contracts/index.ts";
import { contractData, type ShapeOf } from "../contracts/internal.ts";
import { ChordError, type FailureCause, type Principal } from "../data/index.ts";
@ -33,6 +34,7 @@ import type { ChordStore } from "../store/store.ts";
import type { TableDefinition } from "../store/table.ts";
import { type Table, TableHandle } from "../store/table-handle.ts";
import { prepareTables } from "../store/table-migration.ts";
import { capped, MAX_MESSAGE, OpenSpan, spanFailed, untraced } from "../telemetry.ts";
import type { NativeWatchable, Watchable, WatchEnd } from "../watch.ts";
import { AdaptedMembers } from "./adapted.ts";
import { CallContext, type Caller, type Ctx, withLinkedAbortSignal } from "./ctx.ts";
@ -58,7 +60,7 @@ import {
type NativeSlot,
} from "./native.ts";
import type { ChordObject, Served } from "./object.ts";
import type { Failed } from "./ref-state.ts";
import type { Failed, RefState } from "./ref-state.ts";
import type { Binding, CheckedParams, Reference, RetryWalk } from "./reference.ts";
import { type RetrySource, retrySource } from "./retry-on.ts";
import {
@ -232,6 +234,18 @@ type Activation =
/** How an activation that did not go live ended. */
type NotLive = Exclude<Activation, { readonly kind: "live" }>;
/** What an attempt's activation span links to (its object's first trigger, or its last attempt's span) and its number. */
export type AttemptTrace = { readonly trigger: TelemetryContext; readonly attempt: number };
/**
* How an attempt's activation ended, for its span: live, failed (a transient failure's next attempt at `retryAt`), or
* ended (abandoned, its object gone).
*/
export type Activated =
| { readonly kind: "live" }
| { readonly kind: "failed"; readonly cause: FailureCause; readonly retryAt: number | undefined }
| { readonly kind: "ended" };
/** The error of an object, or a getter, that waited `ms` without the object going live. */
export function notLive(label: string, ms: number): ChordError {
return new ChordError({ code: "unavailable", message: `${label}: did not become live within ${ms} ms` });
@ -255,8 +269,13 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
readonly #context: Context;
/** Aborted when the attempt is abandoned or ends: openers, activation's waits and calls run under its signal. */
readonly #abort = new AbortController();
/** The object's context under this attempt's signal. */
readonly #opening: Context;
/** The object's context under this attempt's signal, and its activation span while one is recorded. */
#opening: Context;
readonly #trace: AttemptTrace;
/** Its activation span while it runs (none when the host records nothing); a parked attempt resumes in a new one. */
#activation: OpenSpan<"chord.activate"> | undefined;
/** When it parked (`performance.now()`), while it is parked: `chord.park.duration` once it leaves. */
#parkedAt: number | undefined;
/** The seal token its handles and transactions carry (the seal fence). */
readonly #token = new SealToken();
/** Its routines once they started (most attempts have none). */
@ -325,11 +344,12 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
/** What a reload did to it, made by the first such step (most attempts never meet one). */
#reloaded: Reloaded | undefined;
constructor(object: ChordObject, context: Context) {
constructor(object: ChordObject, context: Context, trace: AttemptTrace) {
this.#object = object;
this.#served = object.served;
this.#context = context;
this.#opening = withAbortSignal(this.#abort.signal, context);
this.#trace = trace;
}
state<D extends StateDefinition<JsonObject, boolean, boolean>>(definition: D): HandleOf<D> {
@ -481,8 +501,10 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
const closeTimeout = options.closeTimeout ?? host.timeouts.close;
const owner = {
object: label,
type: this.#object.served.contract.name,
position: this.#natives.length + 1,
context: this.#context,
telemetry: host.telemetry,
report: (error: HostError) => host.report(error),
};
const native = new NativeHandle(open, close, closeTimeout, owner);
@ -552,6 +574,7 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
* while it waits has opened nothing).
*/
async activate(ending: Promise<void> | undefined): Promise<Activation> {
this.#startActivation(this.#trace.trigger);
const { ready } = this.#object.host.timeouts;
const deadline = new Deadline(ready, () => {
this.abandon({ kind: "failed", cause: { kind: "transient", error: notLive(this.#object.label, ready) } });
@ -573,6 +596,66 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
}
}
/** Its current (or last) activation span; `undefined` when the host records nothing. */
get activationSpan(): TelemetrySpan | undefined {
return this.#activation?.span;
}
/**
* Its activation's outcome, as its object took it: its span ends with it (a failure's error and a transient one's
* backoff an event). An attempt still parked (its span ended `parked`) that fails or ends there records it in a short
* span linked to the parked one, as its resumed steps would run in one (review L4).
*/
activated(outcome: Activated): void {
const current = this.#activation;
if (current === undefined) return;
if (current.ended) {
if (outcome.kind === "live") return;
this.#startActivation(current.span);
}
const activation = this.#activation!;
const { span } = activation;
if (outcome.kind === "failed") {
spanFailed(span, "activation_failed", outcome.cause.error);
if (outcome.retryAt !== undefined)
span.addEvent("chord.retry", { backoff: Math.max(0, outcome.retryAt - Date.now()) });
}
span.setAttributes({ outcome: outcome.kind });
activation.end();
}
/**
* Starts an activation span on the host's adapter linked to `link` (none when it records nothing); the activation's
* steps (its natives' opens, its references' holds) run under it.
*/
#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 activation = new OpenSpan(host.telemetry, "chord.activate", attributes);
if (!untraced(link)) activation.span.addLink({ context: link });
this.#activation = activation;
this.#opening = withTelemetry(activation.span, this.#opening);
}
/** It parked showing `shown`: its activation span ends `parked` with the cause as an event. */
#parkedOn(shown: RefState): void {
this.#parkedAt ??= performance.now();
const activation = this.#activation;
if (activation === undefined || activation.ended) return;
const cause = shown.kind === "failed" ? shown.cause.error.message.slice(0, MAX_MESSAGE) : "loading";
activation.span.addEvent("chord.park", { cause });
activation.span.setAttributes({ outcome: "parked" });
activation.end();
}
/** It leaves its parking (its dependencies live, or abandoned): its park's duration is recorded. */
#parkEnded(): void {
if (this.#parkedAt === undefined) return;
this.#object.host.metrics.histogram("chord.park.duration").record(performance.now() - this.#parkedAt);
this.#parkedAt = undefined;
}
/** Abandons the activation with `outcome` (once): its waits stop and the openers' contexts are aborted. */
abandon(outcome: NotLive): void {
if (this.#abandoned !== undefined) return;
@ -628,6 +711,7 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
this.#routineRun = run;
this.#routines.start({
label,
type: this.#object.served.contract.name,
host,
caller: this.#caller(),
context: withAbortSignal(run.abort.signal, this.#context),
@ -765,7 +849,14 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
* call over a link was about 10% slower in the links benchmark), and no `async` (a check's throw is returned as a
* rejection; as an async function a local call allocated about 250 B more).
*/
call(method: string, args: unknown, context: Context, caller: Caller, version: number): Promise<unknown> {
call(
method: string,
args: unknown,
context: Context,
caller: Caller,
version: number,
parent: TelemetryContext,
): Promise<unknown> {
let checked: ReturnType<typeof checkArgs>;
let handler: Method | undefined;
try {
@ -786,15 +877,24 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
// A local object's handlers act as the host, its principal and its incarnation (§4); a remote one's as their
// caller. The caller stays the reference's (presence, §19).
const acting = served.kind === "remote" ? caller : { principal: host.principal, incarnation: host.incarnation };
const ctx = new CallContext(callContext, acting, host);
// Its span only when something records (§30: nothing else is made per call).
const span = untraced(parent) ? undefined : this.#methodSpan(parent, method, acting);
const ctx = new CallContext(
span === undefined ? callContext : withTelemetry(span.span, callContext),
acting,
host,
);
// Admitted to the drain before the handler runs: the handler may end its own object before it returns.
const running = Promise.withResolvers<unknown>();
host.count("calls", 1);
host.metrics.upDownCounter("chord.calls.in_flight").add(1);
this.#admit(this.#running, running.promise, () => {
host.count("calls", -1);
host.metrics.upDownCounter("chord.calls.in_flight").add(-1);
linked.release();
ctx.settle();
});
span?.endWhen(running.promise, "method_failed", callContext.abortSignal);
// Plugin code, not type-checked: a synchronous throw or a plain value becomes the promise. Constants: the closure
// captures them, not the `let`s above.
const run = handler;
@ -807,6 +907,17 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
return settled.then((result) => back(result as Value));
}
/** 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;
return new OpenSpan(parent, "chord.method", {
type: served.contract.name,
member: method,
object: capped(label),
"principal.kind": capped(acting.principal?.kind ?? "none"),
});
}
/** The `invalid/member` error of a method outside the variant. */
#noMethod(method: string): ChordError {
return invalid("member", `${this.#object.label}${this.#inVariant()} has no method "${method}"`);
@ -1061,17 +1172,23 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
if (pinned === undefined && !this.#moved) {
// Its own steps follow: `loading` until its outcome (a failure shows as the failure, not this).
object.unparked(this);
this.#unparked();
return undefined;
}
if (pinned !== undefined) object.parked(this, pinned, true);
if (pinned !== undefined) {
object.parked(this, pinned, true);
this.#parkedOn(pinned);
}
} else {
object.parked(this, check.shown, check.firstPass);
this.#settleCheck(parkedCause(check));
long.blockedBy(check.blocker);
this.#parkedOn(check.shown);
}
if (!(await this.#nextChange())) return this.#abandoned!;
}
} finally {
this.#parkEnded();
long.stop();
for (const release of waits) release();
this.#parked = undefined;
@ -1080,6 +1197,13 @@ export class Attempt implements StoreSelf, KeyDeclarer, RegistryWaiter {
}
}
/** Its dependencies are live after it parked: its own steps run in a new activation span, linked to the parked one. */
#unparked(): void {
this.#parkEnded();
const parked = this.#activation;
if (parked?.ended) this.#startActivation(parked.span);
}
/**
* Waits for the next change of a dependency (at once when one came during the check); `false` when the attempt was
* abandoned meanwhile (its end, the only thing that stops the wait).

99
packages/chord/src/host/ctx.ts
View file

@ -1,9 +1,12 @@
// The `ctx` a method handler gets (§8): its call's context, who called, the calling host's incarnation, and
// call-scoped references; and the abort signal of a call's context, linked to long-lived sources until it settles.
// The `ctx` a method handler gets (§8): its call's context, who called, the calling host's incarnation, call-scoped
// references and child spans (`ctx.trace`, slice 9); and the abort signal of a call's context, linked to long-lived
// sources until it settles.
import { type Context, type ContextKey, withAbortSignal, withoutAbortSignal } from "../context/index.ts";
import type { SpanAttributes, TelemetrySpan } from "@earendil-works/pi-telemetry";
import { type Context, type ContextKey, withAbortSignal, withoutAbortSignal, withTelemetry } from "../context/index.ts";
import type { Contract, ParamsOf } from "../contracts/index.ts";
import { ChordError, type Principal } from "../data/index.ts";
import { ended, untraced } from "../telemetry.ts";
import type { AnyHost, GetOptions } from "./host.ts";
import type { Binding, Reference } from "./reference.ts";
@ -18,6 +21,13 @@ export interface Ctx<P extends Principal = Principal> extends Context {
* `released`.
*/
get<C extends Contract>(Type: C, params: ParamsOf<C>, options?: GetOptions): Promise<Reference<C>>;
/**
* 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.
*/
trace<T>(name: string, attributes: SpanAttributes, fn: (ctx: Ctx<P>) => Promise<T>): Promise<T>;
}
/** Who makes a call: the principal it acts as and its host's incarnation. */
@ -83,6 +93,15 @@ export class CallContext implements Ctx {
return binding.reference as Reference<C>;
}
trace<T>(name: string, attributes: SpanAttributes, fn: (ctx: Ctx) => Promise<T>): Promise<T> {
return traceUnder(this, name, attributes, fn);
}
/** Its child under `span` (`ctx.trace`), every member kept. */
traced(span: TelemetrySpan): Ctx {
return new SpanCtx(this, span);
}
/** The handler settled: its references are released, waiting gets give up, and `get` throws from now on. */
settle(): void {
const references = this.#references ?? [];
@ -92,6 +111,80 @@ 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 };
/**
* `ctx.trace` of `ctx`: `fn` in a child span with its child ctx; with nothing recorded, `fn` with `ctx` itself. Either
* way a synchronous throw of `fn` rejects (review L5: recording changes nothing `fn` sees but its span).
*/
function traceUnder<T>(
ctx: Traceable,
name: string,
attributes: SpanAttributes,
fn: (ctx: Ctx) => Promise<T>,
): Promise<T> {
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) => {
try {
return await fn(ctx.traced(span));
} catch (error) {
ended(span, "trace_failed", error, ctx.abortSignal);
throw error;
}
});
}
/** 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 #context: Context;
constructor(parent: Ctx, span: TelemetrySpan) {
this.#parent = parent;
this.#context = withTelemetry(span, parent);
}
get principal(): Principal | undefined {
return this.#parent.principal;
}
get incarnation(): string {
return this.#parent.incarnation;
}
get abortSignal(): AbortSignal | undefined {
return this.#context.abortSignal;
}
get telemetry(): Context["telemetry"] {
return this.#context.telemetry;
}
value<T>(key: ContextKey<T>): T | undefined {
return this.#context.value(key);
}
toString(): string {
return `${this.#parent}.Trace`;
}
get<C extends Contract>(Type: C, params: ParamsOf<C>, options?: GetOptions): Promise<Reference<C>> {
return this.#parent.get(Type, params, options);
}
trace<T>(name: string, attributes: SpanAttributes, fn: (ctx: Ctx) => Promise<T>): Promise<T> {
return traceUnder(this, name, attributes, fn);
}
/** Its child under `span`, of its own kind. */
traced(span: TelemetrySpan): Ctx {
return new SpanCtx(this, span);
}
}
function settled(Type: Contract): ChordError {
return new ChordError({
code: "released",

154
packages/chord/src/host/host.ts
View file

@ -4,13 +4,14 @@
// (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 type { TelemetryContext } from "@earendil-works/pi-telemetry";
import { NOOP_TELEMETRY_CONTEXT, type TelemetryContext, type TelemetrySpan } from "@earendil-works/pi-telemetry";
import {
awaitWithContext,
BACKGROUND_CONTEXT,
type Context,
withAbortSignal,
withoutAbortSignal,
withTelemetry,
} from "../context/index.ts";
import type { Address, Contract, HostKind, ParamsOf } from "../contracts/index.ts";
import { contractData, type Params } from "../contracts/internal.ts";
@ -42,6 +43,16 @@ import {
} from "../remote/internal.ts";
import { Batch, type BatchError } from "../state/internal.ts";
import type { ChordStore, Store } from "../store/store.ts";
import {
type ChordMetrics,
capped,
chordMetrics,
chordSpans,
countingOnly,
ended,
parentOf,
untraced,
} from "../telemetry.ts";
import type { Watchable } from "../watch.ts";
import { Activity, type ActivityCounts } from "./activity.ts";
import { type Attempt, notLive } from "./attempt.ts";
@ -83,7 +94,11 @@ export type HostOptions<P extends Principal = Principal, R extends JsonValue = J
readonly principal?: P;
/** The key of a principal in identities; L1's canonical JSON by default. The same function on every host. */
readonly principalKey?: PrincipalKeyFunction<P>;
/** The telemetry adapter; NOOP by default. */
/**
* The telemetry adapter (§29): this host's root spans (activations, closes, resolves, routines, methods called over
* links) and metrics, and the carriers its links extract; NOOP by default, which records nothing and costs one call
* per span site.
*/
readonly telemetry?: TelemetryContext;
/** Everything that fails in the background; every app handles it. */
readonly onError: (error: HostError) => void;
@ -449,6 +464,12 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
readonly compression: Compression | undefined;
/** The host's store, if it has one. */
readonly store: ChordStore | undefined;
/** The telemetry adapter: root spans start on it, carriers from links are extracted with it. */
readonly telemetry: TelemetryContext;
/** Chord's instruments on the adapter's metrics: the host's own counts (links, holds, calls, commits). */
readonly metrics: ChordMetrics;
/** The telemetry of this host's work under a context without a span (`#counted`); none without an adapter. */
readonly #counting: TelemetrySpan | undefined;
readonly #activity: Activity;
readonly #principalKey: PrincipalKeyFunction<P> | undefined;
readonly #revocationKeys: RevocationKeys;
@ -503,7 +524,11 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
this.principal = options.principal;
this.#principalKey = options.principalKey;
this.#onError = options.onError;
this.batch = new Batch((error) => this.report(error), options.telemetry?.metrics);
this.telemetry = options.telemetry ?? NOOP_TELEMETRY_CONTEXT;
this.metrics = chordMetrics(this.telemetry.metrics);
const metrics = this.telemetry.metrics;
this.#counting = untraced(this.telemetry) || metrics === undefined ? undefined : countingOnly(metrics);
this.batch = new Batch((error) => this.report(error), this.telemetry.metrics);
this.compression = options.compression;
this.#activity = new Activity(this.batch);
// `revokedBy` is called with this host's principals only, the `P`s its links stamp.
@ -522,6 +547,22 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
if (this.#state !== "new") throw new Error("load runs once per host");
checkPluginNames(facets);
this.#state = "loading";
const parent = context.telemetry;
if (untraced(parent)) return this.#load(facets, context);
return chordSpans(parent)("chord.load", { plugins: facets.length }, async (span) => {
try {
const report = await this.#load(facets, withTelemetry(span, context));
span.setAttributes({ failed: report.failed.length });
return report;
} catch (error) {
ended(span, "load_failed", error, context.abortSignal);
throw error;
}
});
}
/** `load`'s steps under its span: the setups, the publication, then the start barrier. */
async #load(facets: readonly PluginFacet<P>[], context: Context): Promise<LoadReport> {
const staged = emptyStaged();
const loaded = new Map<string, Facet<P>>();
const failed: PluginFailure[] = [];
@ -549,7 +590,7 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
this.#unbound.wakeAll();
const objects = [...this.#types.values()]
.filter((served) => served.kind === "local" && served.hostLifetime)
.map((served) => this.#object(served, EMPTY_PARAMS, undefined, context));
.map((served) => this.#object(served, EMPTY_PARAMS, undefined, context.telemetry, context));
await Promise.all(objects.map(({ firstOutcome }) => firstOutcome));
if (this.#state === "loading") this.#state = "loaded";
return { failed };
@ -600,11 +641,35 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
return reload;
}
/** One reload, after the previous one: staging, the commit, the fates, the report. */
/** One reload, after the previous one, in its span: each object's fate an event of it. */
async #reload(
facets: readonly PluginFacet<P>[],
before: readonly PluginFailure[],
context: Context,
): Promise<ReloadReport> {
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;
}
});
}
/** One reload's steps: staging, the commit, the fates, the report. */
async #reloadSteps(
facets: readonly PluginFacet<P>[],
before: readonly PluginFailure[],
context: Context,
): Promise<ReloadReport> {
this.#assertOpen();
if (context.abortSignal?.aborted) throw reloadAborted();
@ -789,7 +854,9 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
for (const [name, { plugin }] of staged.registries) if (published.has(plugin)) names.add(name);
const started = this.#startFates(plan.fates);
for (const type of types.values()) {
if (type.kind === "local" && type.hostLifetime) this.#object(type, EMPTY_PARAMS, undefined, context);
if (type.kind === "local" && type.hostLifetime) {
this.#object(type, EMPTY_PARAMS, undefined, context.telemetry, context);
}
}
this.#unbound.wake(names);
return started;
@ -919,13 +986,24 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
}
revoke(revocation: R, context: Context): void {
const count = this.#revoke(revocation, context);
const parent = context.telemetry;
// Recorded after the work: a revocation is synchronous, its span only says what it ended.
if (!untraced(parent)) void chordSpans(parent)("chord.revoke", {}, (span) => span.setAttributes({ count }));
}
/** `revoke`'s work; how many objects it ended and child links it closed. */
#revoke(revocation: R, context: Context): number {
let count = 0;
const key = canonicalJson(revocation, context);
const revoked = (principal: Principal): boolean =>
!this.#isOwn(principal, context) && this.#revocationKeys.revokes(principal, key, context);
const error = (label: string): ChordError =>
new ChordError({ code: "forbidden", reason: "revoked", message: `${label}: revoked` });
for (const object of [...this.#objects.values()]) {
if (object.principal !== undefined && revoked(object.principal)) object.end(error(object.label));
if (object.principal === undefined || !revoked(object.principal)) continue;
object.end(error(object.label));
count++;
}
// Requests not bound (waiting for the publication or a provider, refused, waiting for their link) end too: nothing
// revives them.
@ -942,7 +1020,12 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
// Down the route links before the child links close: a worker ends the principal's objects with the revocation's
// error before the closed origins release their holds.
for (const link of this.#links) if (link.role === "route") link.send({ kind: "revoke", revocation });
for (const link of [...this.#links]) if (link.role === "child" && revoked(link.principal)) link.close();
for (const link of [...this.#links]) {
if (link.role !== "child" || !revoked(link.principal)) continue;
link.close();
count++;
}
return count;
}
get activity(): Watchable<ActivityCounts> {
@ -1002,7 +1085,7 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
// The scope's ctx acts as `principal`, a `P`: an explicit `undefined` runs anonymous (an HTTP request nobody
// authenticated), only an omitted one takes the host's.
const principal = "principal" in options ? options.principal : this.principal;
return this.#roots.run(fn as (ctx: Ctx) => Promise<T>, principal, context);
return this.#roots.run(fn as (ctx: Ctx) => Promise<T>, principal, this.#counted(context));
}
/**
@ -1158,7 +1241,16 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
const placed = this.#destination.reference(Type, params.params, principal, context);
if (placed.kind === "path") {
const { caller, dependent } = binding;
const remote = new RemoteObject(this, Type, params, placed.address, caller, placed.path, dependent);
const remote = new RemoteObject(
this,
Type,
params,
placed.address,
caller,
placed.path,
dependent,
context.telemetry,
);
placed.path.attach(remote);
binding.bind(remote);
return remote;
@ -1180,8 +1272,11 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
});
}
// Checked above: served here at the caller's version.
const object = this.#object(served!, params, principal, context, NO_CHAIN, binding.dependent);
const object = this.#object(served!, params, principal, context.telemetry, context, NO_CHAIN, binding.dependent);
binding.bind(object);
// A getter waiting for a shared activation links to it (decision "Shared work").
const activation = object.activationSpan;
if (activation !== undefined && !untraced(context.telemetry)) context.telemetry.addLink({ context: activation });
return object;
}
@ -1207,7 +1302,9 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
const checked = checkParams(remote.contract, params, context);
const misplaced = this.#destination.misplaced(remote.contract, checked.params);
if (misplaced !== undefined) return { kind: "waiting", cause: { kind: "waiting", error: misplaced } };
const object = this.#object(remote, checked, principal, context, chain);
// The hold's carrier with this host's adapter: the first trigger of an object it creates.
const trigger = parentOf(request.trace, this.telemetry);
const object = this.#object(remote, checked, principal, trigger, context, chain);
const activation = object.activationId;
if (activation !== undefined && chain.includes(activation)) throw this.cycle(chain, activation, [object.label]);
return { kind: "object", object };
@ -1371,11 +1468,26 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
);
}
/**
* `context` for work this host does under it (a link's, a root scope's): one without a span carries this host's
* adapter's metrics (`countingOnly`), so the cost counters of that work reach the adapter (review L6).
*/
#counted(context: Context): Context {
const counting = this.#counting;
if (counting === undefined || context.telemetry !== NOOP_TELEMETRY_CONTEXT) return context;
return withTelemetry(counting, context);
}
/** A new link of `role`, registered with the heartbeat while open. */
#link(link: Link, role: LinkRole, options: LinkOptions<Principal>, context: Context): HostLink {
const { principal, trusted = false, codec = binaryCodec } = options;
const limits = linkLimits(trusted, options.limits);
const made = new HostLink(this, link, { role, principal, trusted, codec, limits }, withoutAbortSignal(context));
const made = new HostLink(
this,
link,
{ role, principal, trusted, codec, limits },
this.#counted(withoutAbortSignal(context)),
);
if (!made.open) return made;
this.#links.add(made);
if (this.#ticking === undefined) {
@ -1398,12 +1510,14 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
* The object for `params` (checked by L1) and, for a remote type, `principal` (its key is part of the identity),
* created if there is none; its first attempt starts at once, or when its identity's backoff window ends. A new one
* keeps the activation chain it is created for (Q5): `chain` (a hold's), or that of `dependent`'s activation when
* an activation declared it, so its own holds over links carry that chain on.
* an activation declared it, so its own holds over links carry that chain on. A new one's first activation span
* links to `trigger` (decision "Shared work").
*/
#object(
served: Served,
params: CheckedParams,
principal: Principal | undefined,
trigger: TelemetryContext,
context: Context,
chain: readonly string[] = NO_CHAIN,
dependent?: ChordObject,
@ -1420,7 +1534,17 @@ export class ChordHost<P extends Principal = Principal, R extends JsonValue = Js
// Shared by every getter: one getter's cancellation does not cancel it.
const owner = served.kind === "local" ? undefined : principal;
const created = dependent?.activationChain() ?? chain;
object = new ChordObject(this, served, checked, owner, key, identity, withoutAbortSignal(context), created);
object = new ChordObject(
this,
served,
checked,
owner,
key,
identity,
trigger,
withoutAbortSignal(context),
created,
);
this.#objects.set(identity, object);
if (!this.backoff.waiting(identity)) object.attempt();
}

2
packages/chord/src/host/internal.ts
View file

@ -3,7 +3,7 @@
export type { PinnedKey } from "./attempt.ts";
export { nextDelay } from "./backoff.ts";
export { CallContext, type Caller } from "./ctx.ts";
export { CallContext, type Caller, SpanCtx } from "./ctx.ts";
export type { AnyHost, ChordHost, Serving } from "./host.ts";
export type { ChordObject, Holder, Removal } from "./object.ts";
export { LIVE, LOADING, type RefState } from "./ref-state.ts";

51
packages/chord/src/host/native.ts
View file

@ -1,8 +1,10 @@
// Natives (§13): the handle `self.open` returns, a value opened during activation and closed with a reason when its
// attempt ends; `within`, which bounds a close or a drain by a timeout; and the drain's admission of running work.
import { type Context, withAbortSignal } from "../context/index.ts";
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import { type Context, withAbortSignal, withTelemetry } from "../context/index.ts";
import { ChordError } from "../data/index.ts";
import { chordSpans, ended, spanFailed, untraced } from "../telemetry.ts";
import type { HostError } from "./host.ts";
/** Why a native closes: its object ended or its attempt failed (`end`), the host closes (`close`), a reload (slice 7). */
@ -24,13 +26,16 @@ export type NativeOptions = {
export type CloseFailed = Extract<HostError, { readonly kind: "close_failed" }>;
/**
* Where a native belongs: its object's label and its position in declaration order (from 1) for errors and reports,
* the object's context (every close runs under it, never under the aborted opener's), and where it reports.
* Where a native belongs: its object's label, type and its position in declaration order (from 1) for errors, reports
* and spans, the object's context (every close runs under it, never under the aborted opener's), the host's telemetry
* adapter (a close is a root span), and where it reports.
*/
type NativeOwner = {
readonly object: string;
readonly type: string;
readonly position: number;
readonly context: Context;
readonly telemetry: TelemetryContext;
readonly report: (error: HostError) => void;
};
@ -78,10 +83,29 @@ export class NativeHandle<T> implements Native<T>, NativeSlot {
throw new ChordError({ code: "released", reason: "closed", message: `${name}: closed` });
}
/** Opens the value; one that arrives after its attempt was abandoned is closed at once, a failure reported. */
/**
* Opens the value in its `chord.open` span (under `context`'s, its attempt's); one that arrives after its attempt was
* abandoned is closed at once, a failure reported.
*/
async open(context: Context): Promise<void> {
this.#state = { kind: "opening" };
await this.#opened(await this.#open(context));
const parent = context.telemetry;
if (untraced(parent)) {
await this.#opened(await this.#open(context));
return;
}
const { type, position } = this.#owner;
await chordSpans(parent)("chord.open", { type, native: position }, async (span) => {
let value: T;
try {
value = await this.#open(withTelemetry(span, context));
} catch (error) {
// An open its attempt abandoned (a deadline, an end) was cancelled: no error.
ended(span, "open_failed", error, context.abortSignal);
throw error;
}
await this.#opened(value);
});
}
/** Closes the value if it is open (a pending open's value is closed when it arrives); resolves with a throw. */
@ -104,11 +128,22 @@ export class NativeHandle<T> implements Native<T>, NativeSlot {
}
/**
* Runs the close under the object's context, aborted at the close timeout, and waits for it up to then; longer is
* reported.
* Runs the close under the object's context (in a `chord.close` root span), aborted at the close timeout, and waits
* for it up to then; longer is reported.
*/
async #closeValue(value: T, reason: NativeCloseReason): Promise<CloseFailed | undefined> {
const { object, position, context, report } = this.#owner;
const { telemetry, 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 failure = await this.#closeWithin(value, reason, withTelemetry(span, this.#owner.context));
if (failure !== undefined) spanFailed(span, "close_failed", failure.error);
return failure;
});
}
/** `#closeValue`'s close under `context`. */
async #closeWithin(value: T, reason: NativeCloseReason, context: Context): Promise<CloseFailed | undefined> {
const { object, position, report } = this.#owner;
const at = { object, native: { kind: "native", position } } as const;
const timeout = new AbortController();
const closing = (async () => this.#close(value, reason, withAbortSignal(timeout.signal, context)))();

60
packages/chord/src/host/object.ts
View file

@ -9,6 +9,7 @@
// native restart after the drain, a retry on the new code, or its end by its type's removal, after which its
// references wait with their last values and follow the next object of the identity.
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import { awaitWithContext, type Context } from "../context/index.ts";
import type { Contract, ParamsOf } from "../contracts/index.ts";
import type { ContractShape } from "../contracts/internal.ts";
@ -22,6 +23,7 @@ import { CHAIN } from "../link/internal.ts";
import type { RegistryContribution } from "../registries/internal.ts";
import type { DeriveSource } from "../state/internal.ts";
import { LiveQueries } from "../store/live-query.ts";
import { chordMetrics } from "../telemetry.ts";
import { refusal } from "./adapted.ts";
import { Attempt, type PinnedKey, type Self } from "./attempt.ts";
import type { Caller } from "./ctx.ts";
@ -185,6 +187,13 @@ export class ChordObject implements Target {
readonly documents: Documents;
/** The context of every attempt: its creator's, without the creator's cancellation. */
readonly #context: Context;
/**
* What its next attempt's activation span links to: its first trigger (the span that created it, a hold's carrier),
* then the last attempt's span (a retry's trigger).
*/
#trigger: TelemetryContext;
/** Its attempts so far (the activation span's `attempt`). */
#attempts = 0;
/** Its job runs by job name, across its attempts. */
readonly #jobs = new Map<string, JobRecords>();
/** This instance's id (uuidv7), minted at its first attempt: a restarted object is a new instance (D4). */
@ -236,6 +245,7 @@ export class ChordObject implements Target {
principal: Principal | undefined,
key: string,
identity: string,
trigger: TelemetryContext,
context: Context,
chain: readonly string[],
) {
@ -247,6 +257,7 @@ export class ChordObject implements Target {
this.identity = identity;
this.label = key === "" ? served.contract.name : `${served.contract.name}(${key})`;
this.chain = chain;
this.#trigger = trigger;
this.#context = context;
const { store } = host;
this.documents = new Documents({
@ -258,6 +269,7 @@ export class ChordObject implements Target {
if (this.#state.kind === "live") this.failLive(this.#state.attempt, { kind: "broken", error });
},
report: (error) => host.report(error),
telemetry: host.telemetry,
});
}
@ -304,6 +316,11 @@ export class ChordObject implements Target {
return this.#lastFailure;
}
/** The span of the activation under way, when one runs and is recorded (getters waiting for it link to it). */
get activationSpan(): TelemetryContext | undefined {
return this.#state.kind === "activating" ? this.#state.attempt.activationSpan : undefined;
}
/** Its instance id while an attempt activates; `undefined` otherwise (a hold's chain names only activations). */
get activationId(): string | undefined {
return this.#state.kind === "activating" ? this.#instance : undefined;
@ -343,7 +360,7 @@ export class ChordObject implements Target {
const state = this.#state;
if (state.kind !== "waiting" && state.kind !== "failed") return undefined;
this.#instance ??= uuidv7();
const attempt = new Attempt(this, this.#context);
const attempt = this.#newAttempt();
this.#state = { kind: "activating", attempt, shown: LOADING };
if (state.kind === "failed") this.#notify();
void this.#run(attempt, this.host.endingOf(this.identity));
@ -381,11 +398,19 @@ export class ChordObject implements Target {
/**
* Calls a method of the live object for `caller`, bound at `version` (an older one maps its arguments and result,
* Q10). While an attempt activates (a reload's swap or restart), the call waits for its outcome (the gate).
* Q10), its `chord.method` span under `parent` (the caller's span on this host, a call's carrier over a link). While
* an attempt activates (a reload's swap or restart), the call waits for its outcome (the gate).
*/
async call(method: string, args: unknown, context: Context, caller: Caller, version: number): Promise<unknown> {
async call(
method: string,
args: unknown,
context: Context,
caller: Caller,
version: number,
parent?: TelemetryContext,
): Promise<unknown> {
if (this.#state.kind === "activating") await this.#gate(context);
return this.#live().call(method, args, context, caller, version);
return this.#live().call(method, args, context, caller, version, parent ?? context.telemetry);
}
/**
@ -659,7 +684,7 @@ export class ChordObject implements Target {
assertNoCycle(dependency: Target, context: Context): void {
const visited = new Set<Target>();
const cycle = dependency.pathTo(this, visited);
context.telemetry.metrics?.counter("chord.cycle.visits").add(visited.size);
chordMetrics(context.telemetry.metrics).counter("chord.cycle.visits").add(visited.size);
if (cycle === undefined) {
const across = dependency.activationId;
if (across === undefined || !this.chain.includes(across)) return;
@ -786,7 +811,7 @@ export class ChordObject implements Target {
// A swap starts from a live object (`reloadFate`).
const old = (this.#state as Extract<ObjectState, { readonly kind: "live" }>).attempt;
const ending = this.host.endingOf(this.identity);
const attempt = new Attempt(this, this.#context);
const attempt = this.#newAttempt();
const swap: Swap = { old, parked: false, done: Promise.withResolvers() };
this.#state = { kind: "activating", attempt, shown: LOADING, swap };
old.handOver();
@ -904,12 +929,17 @@ export class ChordObject implements Target {
/** A new attempt replacing the current one, holders told; its caller starts it (`#run`) after what it waits for. */
#replace(): Attempt {
const attempt = new Attempt(this, this.#context);
const attempt = this.#newAttempt();
this.#state = { kind: "activating", attempt, shown: LOADING };
this.#notify();
return attempt;
}
/** Its next attempt, its activation span linked to the trigger of the last (or its first trigger). */
#newAttempt(): Attempt {
return new Attempt(this, this.#context, { trigger: this.#trigger, attempt: ++this.#attempts });
}
/** The `released` error of an attempt a reload replaced. */
#reloaded(): ChordError {
return new ChordError({ code: "released", reason: "ended", message: `${this.label}: replaced by a reload` });
@ -923,13 +953,23 @@ export class ChordObject implements Target {
/** Runs `attempt`'s activation once `ending` (its predecessors' teardowns, if any) finished; takes its outcome. */
async #run(attempt: Attempt, ending: Promise<void> | undefined): Promise<void> {
const outcome = await attempt.activate(ending);
this.#trigger = attempt.activationSpan ?? this.#trigger;
// The object may have ended after the activation's last step.
if (this.#state.kind !== "activating" || this.#state.attempt !== attempt) return;
if (this.#state.kind !== "activating" || this.#state.attempt !== attempt) {
attempt.activated({ kind: "ended" });
return;
}
switch (outcome.kind) {
case "live":
return this.#wentLive(attempt);
this.#wentLive(attempt);
attempt.activated(outcome);
return;
case "failed":
return this.#failed(attempt, outcome.cause);
this.#failed(attempt, outcome.cause);
attempt.activated({ ...outcome, retryAt: this.host.backoff.until(this.identity) });
return;
case "ended":
attempt.activated(outcome);
}
}

55
packages/chord/src/host/route.ts
View file

@ -2,14 +2,17 @@
// makes the link of one address, at most once at a time. No timer (slice 10 R2): an address resolves for a new hold,
// on `RouteHandle.retry`, or once after its link dropped while held; a rejected `resolve` (or a link closed before its
// handshake) fails its holders `failed { waiting }` until then, and a suspended address resolves nothing while held.
// Each `resolve` is a `chord.resolve` root span linked to the hold that started it (slice 9).
import type { Context } from "../context/index.ts";
import type { TelemetrySpan } from "@earendil-works/pi-telemetry";
import { type Context, withTelemetry } from "../context/index.ts";
import type { Address, HostKind, KindShape } from "../contracts/index.ts";
import { kindParams, type ParamsData } from "../contracts/internal.ts";
import { ChordError, forbidden, type Principal } from "../data/index.ts";
import { asChordError, checkAddress } from "../data/internal.ts";
import type { Codec, Link, PartLimits } from "../link/index.ts";
import { type HostLink, Path, type PathEvent, type Upstream } from "../remote/internal.ts";
import { capped, OpenSpan, spanFailed, untraced } from "../telemetry.ts";
import type { AnyHost } from "./host.ts";
/** What `host.route` takes for a kind. */
@ -47,11 +50,16 @@ export type RouteHandle<K extends KindShape> = {
suspend(address: Address<K>): void;
};
/** One address of a route: its path, whether its `resolve` runs, why it fails its holders, whether it is suspended. */
/**
* One address of a route: its path, whether its `resolve` runs (and its span, when recorded), why it fails its holders,
* whether it is suspended.
*/
type Routed = {
readonly address: Address;
readonly path: Path;
resolving: boolean;
/** The running `resolve`'s span: holders attaching meanwhile link to it (decision "Shared work"). */
span: TelemetrySpan | undefined;
/** A rejected `resolve`, or a link closed before its handshake: its holders fail with it until the next resolve. */
failure: ChordError | undefined;
suspended: boolean;
@ -95,6 +103,7 @@ export class Route {
address,
path: new Path((event) => this.#changed(made, event)),
resolving: false,
span: undefined,
failure: undefined,
suspended: false,
};
@ -165,7 +174,8 @@ export class Route {
return;
case "attached":
if (routed.suspended) event.holder.unreachable(suspended(routed));
else if (!routed.resolving) void this.#resolve(routed);
else if (!routed.resolving) void this.#resolve(routed, event.holder.span);
else if (routed.span !== undefined) event.holder.span?.addLink({ context: routed.span });
return;
case "dropped":
if (!routed.path.held) this.#addresses.delete(routed.address.key);
@ -183,36 +193,51 @@ export class Route {
}
/**
* Runs `resolve` once for the address. A rejection, or a link closed already, fails its holders with the error until
* the next resolve; a link returned after the host closed is closed at once.
* Runs `resolve` once for the address, in a `chord.resolve` root span linked to `trigger` (the span of the hold that
* started it, which links back). A rejection, or a link closed already, fails its holders with the error until the
* next resolve; a link returned after the host closed is closed at once.
*/
async #resolve(routed: Routed): Promise<void> {
async #resolve(routed: Routed, trigger?: TelemetrySpan): Promise<void> {
const key = routed.address.key;
const adapter = this.#host.telemetry;
const span = untraced(adapter)
? undefined
: new OpenSpan(adapter, "chord.resolve", { kind: this.kind, address: capped(key) });
if (span !== undefined && trigger !== undefined) {
span.span.addLink({ context: trigger });
trigger.addLink({ context: span.span });
}
routed.resolving = true;
routed.span = span?.span;
let resolved: Awaited<ReturnType<RouteOptions<Principal, KindShape>["resolve"]>>;
try {
resolved = await this.#options.resolve(routed.address, this.#context);
const context = span === undefined ? this.#context : withTelemetry(span.span, this.#context);
resolved = await this.#options.resolve(routed.address, context);
} catch (error) {
routed.resolving = false;
routed.span = undefined;
resolveEnded(span, error);
if (this.#host.closing) return;
this.#host.report({ kind: "resolve_failed", address: key, error });
this.#settle(routed, asChordError(error, key));
return;
}
routed.resolving = false;
routed.span = undefined;
if (this.#host.closing) {
resolveEnded(span, new ChordError({ code: "released", reason: "closed", message: "the host is closed" }));
resolved.link.close();
return;
}
const { link: made, ...options } = resolved;
const link = this.#host.routeLink(made, options, this.#context);
if (!link.open) {
this.#settle(
routed,
new ChordError({ code: "unavailable", message: `${key}: the link closed before its handshake` }),
);
const error = new ChordError({ code: "unavailable", message: `${key}: the link closed before its handshake` });
resolveEnded(span, error);
this.#settle(routed, error);
return;
}
resolveEnded(span, undefined);
routed.failure = undefined;
// A peer that greeted first had its `hello` handled while the link was made, before it was registered here.
this.#links.set(link, { routed, greeted: link.greeted });
@ -233,6 +258,14 @@ export class Route {
}
}
/** A resolve's span ends: `linked`, or `failed` with `error`. */
function resolveEnded(span: OpenSpan<"chord.resolve"> | undefined, error: unknown): void {
if (span === undefined) return;
if (error !== undefined) spanFailed(span.span, "resolve_failed", error);
span.span.setAttributes({ outcome: error === undefined ? "linked" : "failed" });
span.end();
}
/** The failure holders of a suspended address see. */
function suspended(routed: Routed): ChordError {
return new ChordError({ code: "unavailable", message: `${routed.address.key}: suspended` });

94
packages/chord/src/host/routines.ts
View file

@ -1,12 +1,15 @@
// Routines (§14): the standing behaviour an object or a facet declares, `self.on(source, fn)` and `self.onLive(fn)`.
// They start once their owner went live and stop when it ends (their ctx aborted, the drain waits for running calls);
// each call gets its own ctx; a call that throws is reported and called again after a backoff.
// each call gets its own ctx and its own `chord.routine` root span; a call that throws is reported and called again
// after a backoff.
import type { Context } from "../context/index.ts";
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import { type Context, withTelemetry } from "../context/index.ts";
import type { Principal } from "../data/index.ts";
import { type Op, PendingOps } from "../delta/index.ts";
import type { JsonValue } from "../json.ts";
import { NativeSource, Source } from "../state/internal.ts";
import { capped, ended, OpenSpan, untraced } from "../telemetry.ts";
import {
NativeWatch,
type NativeWatchable,
@ -27,6 +30,8 @@ import { sleep } from "./sleep.ts";
*/
export type RoutineOwner = {
readonly label: string;
/** Its type's name (routine spans). */
readonly type: string;
readonly host: AnyHost;
readonly caller: Caller;
readonly context: Context;
@ -83,17 +88,23 @@ export interface RoutineDeclarations<P extends Principal = Principal> {
type Declaration =
| {
readonly kind: "on";
readonly at: Position;
readonly at: RoutinePosition;
readonly source: Watchable<unknown> | NativeWatchable<unknown>;
readonly fn: (...args: never[]) => void | Promise<void>;
}
| { readonly kind: "onLive"; readonly at: Position; readonly fn: OnLiveHandler };
| { readonly kind: "onLive"; readonly at: RoutinePosition; readonly fn: OnLiveHandler };
/** A routine's kind and position (`Position`, a routine's). */
type RoutinePosition = Position & { readonly kind: "on" | "onLive" };
/** How one routine call ended. */
type Called = { readonly kind: "done" } | { readonly kind: "failed"; readonly error: unknown };
const DONE: Called = { kind: "done" };
/** One routine call: how it ended, and its span, which its routine ends once it knows whether a retry follows. */
type CallEnd = { readonly called: Called; readonly span: OpenSpan<"chord.routine"> | undefined };
/** What `#failing` says of a source failed now. */
const FAILING = { kind: "failed" } as const;
@ -142,10 +153,15 @@ async function live(owner: RoutineOwner, { at, fn }: Extract<Declaration, { kind
let delay: number | undefined;
while (!owner.context.abortSignal?.aborted) {
const started = Date.now();
const called = await call(owner, fn);
if (called.kind === "done" || owner.context.abortSignal?.aborted) return;
const end = await call(owner, at, fn, undefined);
const { called } = end;
if (called.kind === "done" || owner.context.abortSignal?.aborted) {
callEnded(end, owner, undefined);
return;
}
failed(owner, at, called.error);
delay = nextDelay(Date.now() - started >= LONG_RUN ? undefined : delay);
callEnded(end, owner, delay);
try {
await sleep(delay, owner.context);
} catch {
@ -155,17 +171,33 @@ async function live(owner: RoutineOwner, { at, fn }: Extract<Declaration, { kind
}
/**
* Runs one routine call under its own ctx (its `ctx.get` references released when it settles), admitted to the owner's
* drain before the handler runs: a handler may end its own owner before its first await. Resolves with how it ended;
* never rejects.
* Runs one routine call under its own ctx (its `ctx.get` references released when it settles) in its `chord.routine`
* root span, linked to `trigger` (the span of the commit that changed its source, when known), admitted to the owner's
* drain before the handler runs: a handler may end its own owner before its first await. Resolves with how it ended and
* its span, still open (`callEnded`); never rejects.
*/
function call(owner: RoutineOwner, invoke: (ctx: Ctx) => void | Promise<void>): Promise<Called> {
const ctx = new CallContext(owner.context, owner.caller, owner.host);
const settled = Promise.withResolvers<Called>();
function call(
owner: RoutineOwner,
at: RoutinePosition,
invoke: (ctx: Ctx) => void | Promise<void>,
trigger: TelemetryContext | undefined,
): Promise<CallEnd> {
const { host, context } = owner;
const span = untraced(host.telemetry)
? undefined
: new OpenSpan(host.telemetry, "chord.routine", {
type: owner.type,
object: capped(owner.label),
routine: at.kind,
position: at.position,
});
if (span !== undefined && trigger !== undefined && !untraced(trigger)) span.span.addLink({ context: trigger });
const ctx = new CallContext(span === undefined ? context : withTelemetry(span.span, context), owner.caller, host);
const settled = Promise.withResolvers<CallEnd>();
owner.admit(settled.promise, () => ctx.settle());
const finish = (called: Called): void => {
ctx.settle();
settled.resolve(called);
settled.resolve({ called, span });
};
// Plugin code: a synchronous throw becomes the rejection.
(async () => invoke(ctx))().then(
@ -175,6 +207,22 @@ function call(owner: RoutineOwner, invoke: (ctx: Ctx) => void | Promise<void>):
return settled.promise;
}
/**
* A routine call's span ends: `ok`, `aborted` (a cancel), or `error` with `routine_failed` and, when its routine calls
* again after a backoff, a `chord.retry` event with that delay.
*/
function callEnded({ called, span }: CallEnd, owner: RoutineOwner, backoff: number | undefined): void {
if (span === undefined) return;
if (called.kind === "done") {
span.span.setAttributes({ outcome: "ok" });
} else {
const outcome = ended(span.span, "routine_failed", called.error, owner.context.abortSignal);
if (outcome === "error" && backoff !== undefined) span.span.addEvent("chord.retry", { backoff });
span.span.setAttributes({ outcome });
}
span.end();
}
/** Reports a failed routine call or source. */
function failed(owner: RoutineOwner, routine: Position, error: unknown): void {
owner.host.report({ kind: "routine_failed", object: owner.label, routine, error });
@ -222,6 +270,8 @@ class OnRoutine {
#delay: number | undefined;
/** The source failed after its last value: no call until its next value (a retry waits too). */
#failed = false;
/** The span of the commit that made the newest frame (a frame's context), linked from the next call's span. */
#trigger: TelemetryContext | undefined;
constructor(owner: RoutineOwner, declaration: Extract<Declaration, { kind: "on" }>) {
this.#owner = owner;
@ -256,8 +306,8 @@ class OnRoutine {
void watch.closed.then((end) => this.#end(end));
try {
// Both listeners return at once.
watch.start((call: WatchCall<unknown> | NativeWatchCall<unknown>) => {
if (call.kind === "value") this.#frame(call);
watch.start((call: WatchCall<unknown> | NativeWatchCall<unknown>, frame: Context) => {
if (call.kind === "value") this.#frame(call, frame.telemetry);
else this.#failure();
return Promise.resolve();
});
@ -348,11 +398,12 @@ class OnRoutine {
* A frame of the watch: kept as the newest; it is called at once when nothing runs or waits, during a backoff too
* (the backoff ends); while a call runs or settles it waits for the next call.
*/
#frame(call: WatchValueCall<unknown> | NativeWatchValueCall<unknown>): void {
#frame(call: WatchValueCall<unknown> | NativeWatchValueCall<unknown>, trigger: TelemetryContext): void {
const state = this.#state;
if (state.kind === "ended") return;
this.#failed = false;
this.#pending = { value: call.value };
this.#trigger = trigger;
if (!this.#native) {
// A JSON watch's call, as its class decided.
const { ops, retired } = call as WatchValueCall<unknown>;
@ -374,7 +425,9 @@ class OnRoutine {
const { value } = pending;
this.#state = { kind: "calling" };
this.#last = value;
void call(this.#owner, this.#invocation(value)).then((called) => this.#called(called));
const trigger = this.#trigger;
this.#trigger = undefined;
void call(this.#owner, this.#declaration.at, this.#invocation(value), trigger).then((end) => this.#called(end));
}
/**
@ -401,7 +454,10 @@ class OnRoutine {
* arrived during the call (a handler that changes its own source and throws would feed itself otherwise); its timer
* calls with the newest value, or the last call's, as a whole value.
*/
#called(called: Called): void {
#called(end: CallEnd): void {
const { called } = end;
if (this.#state.kind === "ended" || called.kind === "done" || this.#aborted())
callEnded(end, this.#owner, undefined);
if (this.#state.kind === "ended") return;
if (called.kind === "done") {
this.#basis = "last";
@ -418,9 +474,11 @@ class OnRoutine {
this.#delay = nextDelay(this.#delay);
// The source failed meanwhile: the retry waits for its next value, never the stale last one.
if (this.#failed) {
callEnded(end, this.#owner, undefined);
this.#state = { kind: "idle" };
return;
}
callEnded(end, this.#owner, this.#delay);
const timer = setTimeout(() => {
this.#pending ??= { value: this.#last };
this.#next();

1
packages/chord/src/index.ts
View file

@ -51,3 +51,4 @@ export type { StagedWrite, Step } from "./store/step.ts";
/** @internal */
export type { ChordStore, SeriesCommit, SeriesResult } from "./store/store.ts";
export * from "./surfaces/index.ts";
export { CHORD_TELEMETRY_SCHEMA, type ChordSpanName } from "./telemetry.ts";

107
packages/chord/src/jobs/job.ts
View file

@ -1,15 +1,18 @@
// Jobs (§15), in memory: the handle `self.job` returns, one per attempt, over the job's records on its object. It
// holds the implementation and the invocations: `run` runs outside transactions, `finish` in one with the cleanup,
// both on the attempt that is live; the attempt's seal cuts its invocations off (slice 6a §1.3).
// both on the attempt that is live; the attempt's seal cuts its invocations off (slice 6a §1.3). Each phase of a run
// (its start's intent, its run, its finish) is a `chord.job` span, under the run's stored carrier or its starter's span.
import { type Context, withAbortSignal, withoutAbortSignal } from "../context/index.ts";
import type { TelemetrySpan } from "@earendil-works/pi-telemetry";
import { type Context, withAbortSignal, withoutAbortSignal, withTelemetry } from "../context/index.ts";
import { ChordError, isChordError, PluginError, type Principal } from "../data/index.ts";
import type { Draft } from "../delta/index.ts";
import type { CommitPersistence, JsonObject, Tx } from "../documents/index.ts";
import type { Documents, SealToken, Transaction } from "../documents/internal.ts";
import { type Ctx, sleep } from "../host/index.ts";
import { type AnyHost, CallContext, type Caller, nextDelay } from "../host/internal.ts";
import { type AnyHost, CallContext, type Caller, nextDelay, SpanCtx } from "../host/internal.ts";
import type { JsonValue } from "../json.ts";
import { capped, chordSpans, ended, OpenSpan, parentOf, spanFailed, untraced } from "../telemetry.ts";
import type { Watchable } from "../watch.ts";
import type { JobDefinition, Outcome } from "./definition.ts";
import type { JobRecords, Settled } from "./records.ts";
@ -146,7 +149,21 @@ export class Job implements JobHandle<JsonValue, unknown, JsonValue | undefined>
async start(args: JsonValue, context: Context, options: StartOptions = {}): Promise<Run<AnyOutcome>> {
const { documents, token } = this.#owner;
return documents.tx((tx) => this.stage(tx, args, context, options), token, context);
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;
return chordSpans(parent)("chord.job", attributes, async (span) => {
const traced = withTelemetry(span, context);
try {
const run = await documents.tx((tx) => this.stage(tx, args, traced, options), token, traced);
span.setAttributes({ outcome: "ok", "job.id": run.id });
return run;
} catch (error) {
span.setAttributes({ outcome: ended(span, "job_failed", error, context.abortSignal) });
throw error;
}
});
}
outcome(id: string, context: Context): Promise<AnyOutcome> {
@ -264,12 +281,17 @@ export class Job implements JobHandle<JsonValue, unknown, JsonValue | undefined>
this.#owner.admit(reserving);
}
/** Starts `invocation` of `run` on this attempt: its ctx and its settling act for this invocation only. */
/**
* Starts `invocation` of `run` on this attempt, in its run phase's span: its ctx and its settling act for this
* invocation only.
*/
#start(run: JobRun, invocation: Invocation): void {
const { context, caller, host } = this.#owner;
const signal = invocation.abort.signal;
const span = this.#phaseSpan(run, "run");
const scope = withAbortSignal(signal, context);
const ctx = new JobContext(
withAbortSignal(signal, context),
span === undefined ? scope : withTelemetry(span.span, scope),
caller,
host,
run.id,
@ -294,6 +316,23 @@ export class Job implements JobHandle<JsonValue, unknown, JsonValue | undefined>
)
.finally(() => invocation.ended())
.then(work.resolve);
span?.endWhen(running, "job_failed", signal);
}
/**
* The span of `run`'s phase `phase`, under its start's carrier (a persisted run resumed in a new attempt or process
* too: the same trace; without one the adapter's root); none when nothing records.
*/
#phaseSpan(run: JobRun, phase: "run" | "finish"): OpenSpan<"chord.job"> | undefined {
const { host, documents } = this.#owner;
const parent = parentOf(run.trace, host.telemetry);
if (untraced(parent)) return undefined;
return new OpenSpan(parent, "chord.job", {
job: this.#definition.name,
phase,
object: capped(documents.label),
"job.id": run.id,
});
}
/**
@ -326,14 +365,35 @@ export class Job implements JobHandle<JsonValue, unknown, JsonValue | undefined>
this.#records.settled(run, ended);
}
/**
* `run`'s finish phase in its span: each failed try a `chord.retry` event with its backoff; ends `ok`, `error`
* (blocked) or `aborted` (the attempt's seal).
*/
async #finish(run: JobRun): Promise<void> {
const { documents, token, context, signal } = this.#owner;
const span = this.#phaseSpan(run, "finish");
const { context } = this.#owner;
let outcome: "ok" | "error" | "aborted" = "error";
try {
outcome = await this.#finishTries(run, span, span === undefined ? context : withTelemetry(span.span, context));
} finally {
span?.span.setAttributes({ outcome });
span?.end();
}
}
/** The tries of `run`'s finish under `context`, retried with backoff; how the phase ended. */
async #finishTries(
run: JobRun,
span: OpenSpan<"chord.job"> | undefined,
context: Context,
): Promise<"ok" | "error" | "aborted"> {
const { documents, token, signal } = this.#owner;
this.#finishing.add(run);
let delay: number | undefined;
try {
for (;;) {
try {
return await documents.tx(
await documents.tx(
async (tx) => {
const staging = this.#records.staging(tx);
staging.finishing = run;
@ -343,20 +403,24 @@ export class Job implements JobHandle<JsonValue, unknown, JsonValue | undefined>
token,
context,
);
return "ok";
} catch (error) {
if (this.#state === "sealed") return;
if (this.#state === "sealed") return "aborted";
this.#records.report({ kind: "job_finish_failed", id: run.id, error });
// The count is the run's (stored for a persisted job): failures count across a crash.
const finishFailures = run.finishFailures + 1;
if (finishFailures >= FINISH_ATTEMPTS) {
return await this.#records.record(run, { kind: "block", run, reason: "finish_failed" });
if (span !== undefined) spanFailed(span.span, "job_failed", error);
await this.#records.record(run, { kind: "block", run, reason: "finish_failed" });
return "error";
}
await this.#records.record(run, { kind: "update", run, fields: { finishFailures } });
delay = nextDelay(delay);
span?.span.addEvent("chord.retry", { backoff: delay });
try {
await sleep(delay, withAbortSignal(signal, context));
} catch {
return;
return "aborted";
}
}
}
@ -457,4 +521,25 @@ export class JobContext extends CallContext {
this.jobId = jobId;
if (state !== undefined) this.state = state;
}
/** Its child under `span` (`ctx.trace`): a job's ctx still, its id and state kept. */
override traced(span: TelemetrySpan): Ctx {
return new JobSpanContext(this, span, this.jobId, this.state);
}
}
/** A run's ctx under a child span (`ctx.trace`): its parent's members, its run's id and state. */
class JobSpanContext extends SpanCtx {
readonly jobId: string;
declare readonly state: RunState<JsonObject> | undefined;
constructor(parent: Ctx, span: TelemetrySpan, jobId: string, state: RunState<JsonObject> | undefined) {
super(parent, span);
this.jobId = jobId;
if (state !== undefined) this.state = state;
}
override traced(span: TelemetrySpan): Ctx {
return new JobSpanContext(this, span, this.jobId, this.state);
}
}

4
packages/chord/src/jobs/records.ts
View file

@ -18,6 +18,7 @@ import { uuidv7 } from "../host/internal.ts";
import type { JsonValue } from "../json.ts";
import type { StagedWrite } from "../store/step.ts";
import type { ChordStore } from "../store/store.ts";
import { carrierOf } from "../telemetry.ts";
import type { JobDefinition, JobError } from "./definition.ts";
import type { CutReason, Job, StartOptions } from "./job.ts";
import { type LoadedRecord, PersistedRuns } from "./persisted.ts";
@ -343,7 +344,8 @@ export class JobRecords {
throw new ChordError({ code: "unavailable", reason: "busy", message });
}
const persisted = this.#persisted !== undefined;
const trace = persisted ? context.telemetry.propagation?.inject(context.telemetry) : undefined;
// Its starter's carrier: its later phases are children of it (a persisted run stores it, for a later process).
const trace = carrierOf(context.telemetry);
// Checked above: the args are JSON (the definition refuses bytes).
const run = new JobRun(
uuidv7(),

6
packages/chord/src/jobs/run.ts
View file

@ -73,7 +73,11 @@ export class JobRun {
/** A persisted run cut off by a crash or a clean stop, to be resumed per its job's `resume` (no new start). */
resuming = false;
blocked: BlockedReason | undefined;
/** The start's trace carrier, when the adapter propagates (stored, slice 9 uses it). */
/**
* The start's trace carrier, when the adapter propagates (stored for a persisted run): its run and finish spans are
* children of it, in a new attempt and a new process too (a carrier, not the span: a settled span starts no
* recorded children).
*/
readonly trace: { readonly [key: string]: string } | undefined;
/** What it ended with, once recorded (finishing and blocked). */
outcome: AnyOutcome | undefined;

26
packages/chord/src/link/binary.ts
View file

@ -1,4 +1,5 @@
// The binary codec (2b): a kind byte (its high bit set when an origin follows as a varint), then the kind's fields as
// The binary codec (2b): a kind byte (its high bit set when an origin follows as a varint, the next one when a trace
// carrier follows as JSON, slice 9), then the kind's fields as
// unsigned varints, length-prefixed UTF-8 strings, raw incarnation (16 bytes) and fingerprint (8 bytes), parts as
// length-prefixed bytes whose prefix also says whether the part is deflated (decoded as views of the message, never
// parsed or inflated here), and byte segments only beside payloads marked as carrying bytes. No outer length: links
@ -45,6 +46,9 @@ const KIND_BYTES = new Map<string, number>(KINDS.map((kind, byte) => [kind, byte
/** The kind byte's flag for an origin. */
const ORIGIN = 0x80;
/** The kind byte's flag for a trace carrier (a `hold`'s or `call`'s; the message schema refuses it elsewhere). */
const TRACE = 0x40;
/** A payload's flags: present, and carrying byte segments. */
const PRESENT = 1;
@ -68,25 +72,27 @@ export const binaryCodec: Codec = {
encode(message) {
const writer = new Writer();
const origin = "origin" in message ? message.origin : undefined;
if (origin === undefined) {
writer.byte(KIND_BYTES.get(message.kind)!);
} else {
writer.byte(KIND_BYTES.get(message.kind)! | ORIGIN);
writer.varint(origin);
}
const trace = message.kind === "hold" || message.kind === "call" ? message.trace : undefined;
writer.byte(
KIND_BYTES.get(message.kind)! | (origin === undefined ? 0 : ORIGIN) | (trace === undefined ? 0 : TRACE),
);
if (origin !== undefined) writer.varint(origin);
if (trace !== undefined) writer.json(trace);
encodeFields(message, writer);
return writer.finish();
},
decode(bytes) {
const reader = new Reader(bytes);
const byte = reader.byte();
const origin = byte & ORIGIN ? reader.varint() : undefined;
const kind = KINDS[byte & ~ORIGIN];
const kind = KINDS[byte & ~(ORIGIN | TRACE)];
if (kind === undefined) throw new Error("binary: an unknown kind");
const origin = byte & ORIGIN ? reader.varint() : undefined;
const trace = byte & TRACE ? reader.json() : undefined;
const message = decodeFields(kind, reader);
reader.end();
// A fresh object; the message schema refuses an origin on a kind without one.
// A fresh object; the message schema refuses an origin or a trace on a kind without one, and checks the trace.
if (origin !== undefined) (message as { origin?: number }).origin = origin;
if (trace !== undefined) (message as { trace?: unknown }).trace = trace;
return message;
},
};

16
packages/chord/src/link/channel.ts
View file

@ -1,9 +1,10 @@
// A host's end of a link (§3, §22, 2b): the handshake, the link's codec, the checks of every message (skipped on a
// trusted link), the heartbeat, and messages handled in order while one waits for an asynchronous inflate; a protocol
// error closes the link.
// error closes the link. The bytes of every message it encodes and receives are counted (`chord.link.bytes`).
import type { Context } from "../context/index.ts";
import { PROTOCOL_VERSION } from "../data/internal.ts";
import type { ChordCounter, ChordMetrics } from "../telemetry.ts";
import type { Link } from "./link.ts";
import { type Codec, checkMessage, type Message } from "./message.ts";
@ -32,8 +33,15 @@ type ChannelOptions = {
readonly trusted: boolean;
/** Where protocol errors go. */
readonly report: (error: unknown) => void;
/** The host's instruments: the bytes of every encoded message sent and received (`chord.link.bytes`). */
readonly metrics: ChordMetrics;
};
/** `chord.link.bytes`' attributes, made once. */
const SENT = { direction: "sent" } as const;
const RECEIVED = { direction: "received" } as const;
/**
* Where a channel stands: `greeting` until the peer's `hello`, with what this end sent meanwhile; `open` with the
* peer's incarnation and call window.
@ -73,9 +81,12 @@ export class Channel {
/** Whether a message is being handled asynchronously: the held ones wait. */
#waiting = false;
readonly #hello: Uint8Array;
/** Counts the bytes of the encoded messages (sizes the channel has). */
readonly #bytes: ChordCounter<"chord.link.bytes">;
constructor(link: Link, handler: ChannelHandler, options: ChannelOptions, context: Context) {
this.#link = link;
this.#bytes = options.metrics.counter("chord.link.bytes");
this.#codec = options.codec;
this.#handler = handler;
this.#report = options.report;
@ -94,6 +105,7 @@ export class Channel {
* calls `closed` now; so the handler is complete before it starts.
*/
start(): void {
this.#bytes.add(this.#hello.byteLength, SENT);
this.#link.send(this.#hello);
this.#link.onMessage((bytes) => this.#receive(bytes));
this.#link.onClose(() => this.#closed());
@ -122,6 +134,7 @@ export class Channel {
const state = this.#state;
if (state.kind === "closed") return;
const bytes = this.#codec.encode(message);
this.#bytes.add(bytes.byteLength, SENT);
if (state.kind === "greeting") state.queued.push(bytes);
else this.#link.send(bytes);
}
@ -148,6 +161,7 @@ export class Channel {
#receive(bytes: Uint8Array): void {
if (this.#state.kind === "closed") return;
this.#bytes.add(bytes.byteLength, RECEIVED);
this.#lastReceived = Date.now();
this.#pinged = false;
if (this.#held === undefined) this.#handle(bytes);

45
packages/chord/src/link/message.ts
View file

@ -1,10 +1,11 @@
// Messages (§22, R1, R4, 2b): the one `Message` type every link carries, defined as a schema and checked after every
// decode, and the codecs that turn it into bytes.
import { obj as openObj, type Schema } from "@earendil-works/pi-schema";
import { map, obj as openObj, type Schema } from "@earendil-works/pi-schema";
import type { Context } from "../context/index.ts";
import { arr, int, lit, obj, oneOf, opt, type Static, str, union, unknown } from "../contracts/index.ts";
import { validatorFor } from "../data/internal.ts";
import { chordMetrics } from "../telemetry.ts";
import type { Part } from "./part.ts";
/** A link-local id, chosen by its origin: a counter, unique per link, direction and origin while in use. */
@ -38,8 +39,17 @@ const part = unknown() as Schema<Part>;
*/
const segments = opt(unknown() as Schema<readonly Uint8Array[]>);
/**
* The longest name a message carries (a type's, a host kind's): a relay records them in its spans unparsed, so a peer
* cannot hand it an unbounded string (slice 9 review M1).
*/
export const NAME_LENGTH = 256;
/** A type's or a host kind's name. */
const name = str({ max: NAME_LENGTH });
/** An address as a hold names it: its host kind and params, checked against the kind where it is routed. */
const address = obj({ kind: str(), params: unknown() });
const address = obj({ kind: name, params: unknown() });
/** A principal on a hold: JSON with a `kind`, honoured only on a parent link. */
const principal = openObj({ kind: str() }, { open: true });
@ -47,6 +57,21 @@ const principal = openObj({ kind: str() }, { open: true });
/** A uuidv7 as text. */
const incarnation = str({ pattern: "^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$" });
/** The most keys a trace carrier has, and the longest key or value (R5). */
export const CARRIER = { keys: 8, length: 256 } as const;
/**
* The caller's trace carrier on a `hold` or `call` (R5, slice 9): an adapter's opaque string record, bounded, of
* printable ASCII only (keys without spaces), as W3C's headers and Chord's adapters are; anything else fails this schema
* as any malformed header does, so no control character becomes a stored trace or span id (review M2). The provider
* extracts it with its own adapter (absent or unknown: the adapter's root).
*/
const trace = opt({
...map(str({ max: CARRIER.length, pattern: "^[\\x20-\\x7e]*$" })),
propertyNames: { maxLength: CARRIER.length, pattern: "^[\\x21-\\x7e]+$" },
maxProperties: CARRIER.keys,
} as Schema<Record<string, string>>);
/** The longest activation chain a hold carries (Q5): a longer one keeps its last entries. */
export const CHAIN = 32;
@ -64,7 +89,7 @@ const MESSAGE = union([
kind: lit("hold"),
origin: opt(origin),
hold: id,
type: str(),
type: name,
version: int({ min: 1 }),
fingerprint: str({ pattern: "^[0-9a-f]{16}$" }),
params: part,
@ -77,9 +102,19 @@ const MESSAGE = union([
chain: opt(arr(incarnation, { max: CHAIN })),
// The decoded limit per part of the link the hold was admitted on (Q2); read only on a parent link.
limit: opt(int({ min: 0 })),
trace,
}),
obj({ kind: lit("release"), origin: opt(origin), hold: id }),
obj({ kind: lit("call"), origin: opt(origin), call: id, hold: id, method: index, args: opt(part), segments }),
obj({
kind: lit("call"),
origin: opt(origin),
call: id,
hold: id,
method: index,
args: opt(part),
segments,
trace,
}),
obj({ kind: lit("abort"), origin: opt(origin), call: id }),
// Asks the provider for an attempt of a failed hold's object now (`ref.retry()`); `hops` is its budget: the host
// there passes it on to its remote dependencies with one less, never at 0, so a waiting ring of hosts stops. Relays
@ -184,7 +219,7 @@ const MESSAGE_SCHEMA = { schema: MESSAGE };
* `chord.link.checks`.
*/
export function checkMessage(message: unknown, context: Context): Message {
context.telemetry.metrics?.counter("chord.link.checks").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.link.checks").add(1);
if (!validatorFor(MESSAGE_SCHEMA, context).check(message)) throw new Error("message: fails the message schema");
// The check above establishes the type.
return message as Message;

7
packages/chord/src/link/part.ts
View file

@ -4,6 +4,7 @@
import type { Context } from "../context/index.ts";
import { ChordError } from "../data/index.ts";
import { chordMetrics } from "../telemetry.ts";
/**
* A part (R1): a value as JSON text at its origin (and after a text decode), its UTF-8 bytes once a binary codec
@ -82,7 +83,7 @@ export function originPart(json: string, compression: Compression | undefined, c
if (compression === undefined || json.length * 3 <= COMPRESS_ABOVE) return json;
const bytes = UTF8.encode(json);
if (bytes.byteLength <= COMPRESS_ABOVE) return bytes;
context.telemetry.metrics?.counter("chord.link.deflates").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.link.deflates").add(1);
const deflated = compression.deflate(bytes);
return deflated.byteLength < bytes.byteLength ? new DeflatedPart(deflated) : bytes;
}
@ -121,7 +122,7 @@ export function openPart(
let inflated = part.inflated;
if (inflated === undefined) {
if (compression === undefined) throw new Error("part: a deflated part this host did not inflate");
context.telemetry.metrics?.counter("chord.link.inflates").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.link.inflates").add(1);
inflated = compression.inflate(part.bytes, limits.decoded);
}
switch (inflated.kind) {
@ -145,7 +146,7 @@ export async function inflateAsync(
signal: AbortSignal,
context: Context,
): Promise<void> {
context.telemetry.metrics?.counter("chord.link.inflates").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.link.inflates").add(1);
const reader = new Blob([part.bytes as Uint8Array<ArrayBuffer>])
.stream()
.pipeThrough(new DecompressionStream("deflate-raw"))

43
packages/chord/src/link/text.ts
View file

@ -4,7 +4,8 @@
// segments of a payload marked as carrying bytes follow the tuple after a newline (JSON text never contains a raw
// one), their lengths the tuple's last field. A message with an origin is wrapped: `["@", origin, tuple]`. Every part
// is tagged with its codec, so no JSON value is reserved: `[0, json]`, or `[1, base64]` for a part its origin deflated
// (the text codec itself never compresses).
// (the text codec itself never compresses). A `hold`'s or `call`'s trace carrier is an optional element after its
// other fields (slice 9).
import {
type BoundEntry,
@ -73,18 +74,25 @@ function ownTuple(message: Message): string {
case "hello":
return json(["h", message.protocol, message.incarnation, message.calls]);
case "hold": {
const { address, principal, incarnation, chain, limit } = message;
const { address, principal, incarnation, chain, limit, trace } = message;
const head = json(["H", message.hold, message.type, message.version, message.fingerprint]).slice(0, -1);
// Optional trailing fields: an absent one in the middle is null, absent ones at the end are left out.
const optional = [principal ?? null, incarnation ?? null, chain ?? null, limit ?? null];
const optional = [principal ?? null, incarnation ?? null, chain ?? null, limit ?? null, trace ?? null];
while (optional.length > 0 && optional.at(-1) === null) optional.pop();
const rest = optional.map((field) => `,${json(field)}`).join("");
return `${head},${partText(message.params)},${json([address.kind, address.params])}${rest}]`;
}
case "release":
return json(["R", message.hold]);
case "call":
return withPayload(json(["c", message.call, message.hold, message.method]), message.args, message.segments);
case "call": {
const head = json(["c", message.call, message.hold, message.method]);
const { args, segments, trace } = message;
if (trace === undefined) return withPayload(head, args, segments);
// With a trace the payload's fields are positional (null when absent), the carrier last.
const lengths = segments === undefined ? "null" : json(segments.map((segment) => segment.byteLength));
const part = args === undefined ? "null" : partText(args);
return `${head.slice(0, -1)},${part},${lengths},${json(trace)}]`;
}
case "abort":
return json(["x", message.call]);
case "bound":
@ -183,10 +191,10 @@ function fromFields(fields: unknown[], rest: Uint8Array): Message {
arity(3);
return { kind: "hello", protocol: field(0), incarnation: field(1), calls: field(2) };
case "H": {
arity(6, 7, 8, 9, 10);
arity(6, 7, 8, 9, 10, 11);
const address = list(f[5]);
if (address.length !== 2) throw new Error("text: an address is a pair");
const [principal, incarnation, chain, limit] = [6, 7, 8, 9].map((index) => f[index] ?? null);
const [principal, incarnation, chain, limit, trace] = [6, 7, 8, 9, 10].map((index) => f[index] ?? null);
return {
kind: "hold",
hold: field(0),
@ -199,20 +207,25 @@ function fromFields(fields: unknown[], rest: Uint8Array): Message {
...(incarnation === null ? {} : { incarnation: incarnation as string }),
...(chain === null ? {} : { chain: chain as string[] }),
...(limit === null ? {} : { limit: limit as number }),
...(trace === null ? {} : { trace: trace as Record<string, string> }),
};
}
case "R":
arity(1);
return { kind: "release", hold: field(0) };
case "c":
arity(3, 4, 5);
return {
case "c": {
arity(3, 4, 5, 6);
const call = {
kind: "call",
call: field(0),
hold: field(1),
method: field(2),
...payload("args", f.slice(3), rest),
};
call: field<number>(0),
hold: field<number>(1),
method: field<number>(2),
} as const;
if (f.length < 6) return { ...call, ...payload("args", f.slice(3), rest) };
// With a trace: the payload's fields positional, null when absent.
const fields = f[3] === null ? [] : f[4] === null ? [f[3]] : [f[3], f[4]];
return { ...call, ...payload("args", fields, rest), trace: f[5] as Record<string, string> };
}
case "x":
arity(1);
return { kind: "abort", call: field(0) };

9
packages/chord/src/node/app/app.ts
View file

@ -5,6 +5,7 @@
// and gives the app the controls it needs: the owner link, `applyChanges`, installs, export and import per address.
import { join, resolve } from "node:path";
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
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";
@ -113,6 +114,11 @@ export type AppOptions<P extends Principal> = {
readonly web?: AppWeb;
/** 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.
*/
readonly telemetry?: TelemetryContext;
readonly onError: (error: AppError) => void;
} & (OwnerPrincipal extends P ? unknown : { readonly "the app's principal type must have { kind: 'owner' }": never });
@ -200,10 +206,12 @@ export async function startServer<P extends Principal>(options: AppOptions<P>, c
);
const { onError, api, limits = {} } = options;
const sessions = createSessions<P>(cookieSecret, { maxEphemeral: limits.ephemeralSessions });
const { telemetry } = options;
const host = createHost<P>({
address: Server(),
principal: options.principal.server,
store,
telemetry,
onError: (error) => onError({ kind: "host", error }),
});
const http = createHttp(
@ -211,6 +219,7 @@ export async function startServer<P extends Principal>(options: AppOptions<P>, c
{
listen: options.listen ?? { host: "127.0.0.1", port: 0 },
links: { path: "/chord", opened: sessions.opened },
telemetry,
onError: (error) => onError({ kind: "http", error }),
},
context,

8
packages/chord/src/node/app/worker.ts
View file

@ -4,6 +4,7 @@
// (`WorkerInfo`, `Files`, `Translations` for a worker that renders final text).
import { join } from "node:path";
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import type { Principal } from "../../data/index.ts";
import { createHost } from "../../host/index.ts";
import type { JsonValue } from "../../json.ts";
@ -24,6 +25,12 @@ export type WorkerOptions = {
readonly kinds: Readonly<Record<string, AppKind>>;
/** Extra keep-alive counts of the app (a record of numbers, all zero when idle). */
readonly busy?: Watchable<Readonly<Record<string, number>>>;
/**
* 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;
/** The worker host's errors (`HostError`) and a failed start's. */
readonly onError: (error: unknown) => void;
};
@ -48,6 +55,7 @@ export function startWorker<P extends Principal>(options: WorkerOptions): void {
address,
principal: kit.principal as unknown as P,
store,
telemetry: options.telemetry,
onError: options.onError,
});
onClose((ctx) => host.close(ctx));

62
packages/chord/src/node/http/http.ts
View file

@ -4,15 +4,24 @@
// `fetch`, from the registries its facet serves (`Http`, `Authenticators`), an upgrade adapter for Node (`upgrade`), and
// the facet, whose host-lifetime listener object is Chord's own Node server. Every request is admitted (provenance), routed,
// checked for foreign origins, authenticated unless foreign, and served in one `host.root` scope with its principal
// that lasts until its body is delivered; every answer carries the default headers.
// that lasts until its body is delivered (a routed one in a `chord.http` span with an adapter, slice 9); every answer
// carries the default headers.
import type { IncomingMessage } from "node:http";
import type { Duplex } from "node:stream";
import { awaitWithContext, type Context, withAbortSignal, withoutAbortSignal } from "../../context/index.ts";
import type { TelemetryCarrier, TelemetryContext } from "@earendil-works/pi-telemetry";
import {
awaitWithContext,
type Context,
withAbortSignal,
withoutAbortSignal,
withTelemetry,
} from "../../context/index.ts";
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 {
type Admitted,
admit,
@ -39,6 +48,11 @@ export type HttpOptions = {
readonly links?: LinksOptions;
/** How long `close` waits for running requests and closing sockets: 30 s by default. */
readonly closeTimeout?: number;
/**
* The telemetry adapter (the host's): each routed request is a `chord.http` root span, its scope's `ctx` under it; a
* W3C `traceparent` is extracted only from a request a contributed relay verified. NOOP by default.
*/
readonly telemetry?: TelemetryContext;
readonly onError: (error: HttpError) => void;
};
@ -264,6 +278,8 @@ class Component<P extends Principal> implements HttpComponent<P>, Handler {
// Deny by default (decision "The app kit, point 3"): no plugin code runs for nobody unless the route is public.
if (principal === undefined && !match.public) return { answer: this.refusal(401, admission, router, head) };
const answered = Promise.withResolvers<Answer>();
const span = this.#span(request, match, admission);
const base = withAbortSignal(controller.signal, this.#base);
const scope = this.#host
.root(
async (ctx) => {
@ -271,14 +287,36 @@ class Component<P extends Principal> implements HttpComponent<P>, Handler {
// The scope lasts until the body is written or abandoned (a `bytes` body reads in it).
await finished;
},
withAbortSignal(controller.signal, this.#base),
span === undefined ? base : withTelemetry(span.span, base),
{ principal },
)
.catch(() => {
// The scope was sealed (a disconnect, `close`) before it answered: the request is over.
answered.resolve(this.refusal(503, admission, router, head));
});
return { answer: await answered.promise, scope };
const answer = await answered.promise;
if (span !== undefined) {
span.span.setAttributes({ status: answer.status });
if (answer.status >= 500) spanFailed(span.span, "http_failed", `status ${answer.status}`);
void scope.then(() => span.end());
}
return { answer, scope };
}
/**
* A routed request's `chord.http` span (its method and route pattern; its path never: it may carry ids or secrets):
* a root of the adapter, or the child of a W3C `traceparent` (and its `tracestate`) of a request a contributed relay
* verified, never a browser's; none without an adapter that records.
*/
#span(request: Incoming, match: RouteMatch, admission: Admitted): OpenSpan<"chord.http"> | undefined {
const adapter = this.#options.telemetry;
if (adapter === undefined || untraced(adapter)) return undefined;
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 });
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 });
}
/** Runs the wraps and the route in the request's scope `ctx`, and makes its answer (a failure: a reported 500). */
@ -527,6 +565,22 @@ function tracked(stream: ReadableStream<Uint8Array>, finished: () => void): Read
);
}
/**
* The longest W3C trace header taken from a relayed request (`traceparent` is 55 characters, `tracestate` at most 512):
* the relay forwards what the browser sent unless it strips them, so they are bounded as a link's carrier is (review L2).
*/
const TRACE_HEADERS = { traceparent: 256, tracestate: 512 } as const;
/** Printable ASCII, as a link's carrier. */
const PRINTABLE = /^[\x20-\x7e]*$/;
/** A W3C trace header of `request`, when present, within its bound and printable; otherwise none (ignored). */
function traceHeader(request: Incoming, name: keyof typeof TRACE_HEADERS): string | undefined {
const value = request.header(name);
if (value === null || value.length > TRACE_HEADERS[name] || !PRINTABLE.test(value)) return undefined;
return value;
}
/** Refuses an upgrade with `status` and closes its connection. */
function refuse(stream: Duplex, status: number): void {
stream.end(`HTTP/1.1 ${status} ${STATUS[status] ?? ""}\r\nConnection: close\r\nContent-Length: 0\r\n\r\n`);

17
packages/chord/src/remote/consumer.ts
View file

@ -4,6 +4,7 @@
// origin's provider side. On a host without a compressor, the deflated parts of this host's own holds and calls are
// inflated asynchronously first, and the message is handled once they are.
import type { TelemetryCarrier } from "@earendil-works/pi-telemetry";
import type { Context } from "../context/index.ts";
import { type MethodData, takesNoArgs } from "../contracts/internal.ts";
import { ChordError, isChordError } from "../data/index.ts";
@ -19,6 +20,7 @@ import {
payloadPart,
type StateEntry,
} from "../link/internal.ts";
import { carrierOf } from "../telemetry.ts";
import { CallWindow } from "./calls.ts";
import { actingFor } from "./hold.ts";
import type { HostLink } from "./host-link.ts";
@ -37,6 +39,8 @@ type OutgoingCall = {
readonly method: number;
readonly args: Part | undefined;
readonly segments: readonly Uint8Array[] | undefined;
/** The caller's trace carrier (its `chord.call` span's), when its adapter propagates. */
readonly trace: TelemetryCarrier | undefined;
readonly resolve: (value: unknown) => void;
readonly reject: (error: unknown) => void;
id: number | undefined;
@ -61,9 +65,9 @@ export class ConsumerSide {
/**
* Holds `holder` on this link and returns its new id: its first hold, or a re-hold on a new link; `chain`: the
* activation chain it is held for, if any (Q5).
* activation chain it is held for, if any (Q5); `trace`: this hold's carrier, if any.
*/
attach(holder: RemoteObject, chain: string[] | undefined): number {
attach(holder: RemoteObject, chain: string[] | undefined, trace: TelemetryCarrier | undefined): number {
const id = this.#nextHold++;
this.#entries.set(id, holder);
const acting = actingFor(this.#link, holder.caller);
@ -73,6 +77,7 @@ export class ConsumerSide {
...holder.request,
...acting,
...(chain === undefined ? {} : { chain }),
...(trace === undefined ? {} : { trace }),
});
return id;
}
@ -80,8 +85,8 @@ export class ConsumerSide {
/**
* Calls method `method` (an index into the bound variant) on hold `hold` with `args`: left out for a method without
* arguments, with byte segments when its argument schema has a `bytes()` leaf, deflated above the threshold except on
* the parent link. The result is parsed here. The caller's cancellation rejects it at once and sends `abort` when it
* is in flight.
* the parent link; with the carrier of `context`'s span when its adapter propagates. The result is parsed here. The
* caller's cancellation rejects it at once and sends `abort` when it is in flight.
*/
call(hold: number, method: number, data: MethodData, args: unknown, context: Context): Promise<unknown> {
const signal = context.abortSignal;
@ -103,6 +108,7 @@ export class ConsumerSide {
method,
args: part,
segments: payload?.segments,
trace: carrierOf(context.telemetry),
resolve: (value) => {
done();
resolve(value);
@ -188,7 +194,7 @@ export class ConsumerSide {
const id = this.#nextCall++;
call.id = id;
this.#calls.set(id, call);
const { hold, method, args, segments } = call;
const { hold, method, args, segments, trace } = call;
this.#link.send({
kind: "call",
call: id,
@ -196,6 +202,7 @@ export class ConsumerSide {
method,
...(args === undefined ? {} : { args }),
...(segments === undefined ? {} : { segments }),
trace,
});
}

18
packages/chord/src/remote/hold.ts
View file

@ -8,6 +8,7 @@
// bound or a removed type leaves it waiting unbound. A hold of an older version follows its object's adapted members
// (Q10).
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import type { Context } from "../context/index.ts";
import { type VariantData, type VariantNames, variantNames, variantOrder, variantsAt } from "../contracts/internal.ts";
import { ChordError, type FailureCause, isChordError, type Principal } from "../data/index.ts";
@ -36,6 +37,7 @@ import {
wireError,
} from "../link/internal.ts";
import { type DeriveSource, Source, type Subscriber } from "../state/internal.ts";
import { chordMetrics } from "../telemetry.ts";
import type { HostLink } from "./host-link.ts";
import type { ProviderSide } from "./provider.ts";
import { RelayedHold } from "./relay.ts";
@ -144,6 +146,7 @@ export class Hold implements Holder, UnboundRequest {
this.caller = caller;
this.limits = limits;
provider.link.host.count("references", 1);
provider.link.host.metrics.upDownCounter("chord.holds.active").add(1);
}
/** Whether the hold is bound: its members' changes are sent. */
@ -350,9 +353,9 @@ export class Hold implements Holder, UnboundRequest {
this.start(request);
}
/** Calls a method of the held object as the hold's caller. */
call(method: string, args: unknown, context: Context): Promise<unknown> {
return this.#object!.call(method, args, context, this.caller, this.contract.version);
/** Calls a method of the held object as the hold's caller, its span under `parent` (the call's carrier, extracted). */
call(method: string, args: unknown, parent: TelemetryContext, context: Context): Promise<unknown> {
return this.#object!.call(method, args, context, this.caller, this.contract.version, parent);
}
/**
@ -408,7 +411,7 @@ export class Hold implements Holder, UnboundRequest {
this.#changes = [];
this.#failed = [];
this.#retired = NO_RETIRED;
context.telemetry.metrics?.counter("chord.link.encodes").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.link.encodes").add(1);
return { hold: this.id, variant: variantOrder(contract).indexOf(variant), members, failed };
}
@ -464,7 +467,10 @@ export class Hold implements Holder, UnboundRequest {
host.unindex(state.request.type, this);
}
this.#state = { kind: "released" };
if (this.#counted) host.count("references", -1);
if (this.#counted) {
host.count("references", -1);
host.metrics.upDownCounter("chord.holds.active").add(-1);
}
this.#counted = false;
}
@ -576,7 +582,7 @@ export class Hold implements Holder, UnboundRequest {
retired = retired.filter((index) => !kept.includes(index));
}
}
context.telemetry.metrics?.counter("chord.link.encodes").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.link.encodes").add(1);
return { hold: this.id, members, failed, retired };
}

4
packages/chord/src/remote/host-link.ts
View file

@ -79,8 +79,9 @@ export class HostLink implements ChannelHandler {
this.consumer = new ConsumerSide(this);
const { codec, trusted } = options;
const report = (error: unknown): void => host.report({ kind: "protocol_error", error });
const channel = { codec, incarnation: host.incarnation, calls: CALLS, trusted, report };
const channel = { codec, incarnation: host.incarnation, calls: CALLS, trusted, report, metrics: host.metrics };
this.#channel = new Channel(link, this, channel, context);
host.metrics.upDownCounter("chord.links.open").add(1);
// Last: a link closed already calls `closed` at once.
this.#channel.start();
}
@ -211,6 +212,7 @@ export class HostLink implements ChannelHandler {
}
closed(): void {
this.host.metrics.upDownCounter("chord.links.open").add(-1);
this.#closing.abort();
for (const provider of this.#providers.values()) provider.closed();
this.#providers.clear();

87
packages/chord/src/remote/provider.ts
View file

@ -1,8 +1,10 @@
// The provider side of one origin on a link (§3, §22, W1; decision "Relay flow control per origin"): the holds the
// peer sent for that origin, served here or relayed, by their ids; the calls on them, at most this side's N at once;
// and the window: at most K unacknowledged `bound` and `state` messages of this host's own, with what waits meanwhile,
// and the sender of every message in flight, so each `ack` reaches the host that sent its message.
// and the sender of every message in flight, so each `ack` reaches the host that sent its message. A served call's
// method runs under the call's carrier (slice 9).
import type { TelemetryContext } from "@earendil-works/pi-telemetry";
import { type Context, withAbortSignal } from "../context/index.ts";
import { ChordError, isChordError, type Principal } from "../data/index.ts";
import type { Caller } from "../host/internal.ts";
@ -19,9 +21,10 @@ import {
type StateEntry,
wireError,
} from "../link/internal.ts";
import { type OpenSpan, parentOf } from "../telemetry.ts";
import { Hold } from "./hold.ts";
import type { HostLink } from "./host-link.ts";
import type { RelayedHold } from "./relay.ts";
import { type RelayedHold, relayEnded } from "./relay.ts";
/**
* A call being handled: on a hold served here, with whether its result carries byte segments and the abort of its
@ -29,7 +32,8 @@ import type { RelayedHold } from "./relay.ts";
*/
type RunningCall =
| { readonly kind: "served"; readonly hold: Hold; readonly bytes: boolean; readonly abort: AbortController }
| { readonly kind: "relayed"; readonly hold: RelayedHold };
/** `span`: its `chord.relay` span while its reply is awaited, when this host records. */
| { readonly kind: "relayed"; readonly hold: RelayedHold; span?: OpenSpan<"chord.relay"> };
/** Who sent a `bound` or `state` message in flight: this host, or the upstream link a relay forwarded it from. */
type Sender = "local" | HostLink;
@ -68,6 +72,8 @@ export class ProviderSide {
#bindingTurn = false;
/** Set once a hold of this origin is relayed. */
#relay: Relay | undefined;
/** When state began waiting for a slot (`performance.now()`), while some waits: `chord.backpressure.wait`. */
#waitingSince: number | undefined;
constructor(link: HostLink, origin: number, limit: number) {
this.link = link;
@ -110,7 +116,10 @@ export class ProviderSide {
const entries = [...this.#entries.values()];
this.#entries.clear();
const closed = new ChordError({ code: "unavailable", message: "the link closed" });
for (const call of this.#calls.values()) if (call.kind === "served") call.abort.abort(closed);
for (const call of this.#calls.values()) {
if (call.kind === "served") call.abort.abort(closed);
else if (call.span !== undefined) relayEnded(call.span, undefined);
}
this.#calls.clear();
// While the host closes, it ends its objects itself.
for (const entry of entries) {
@ -229,6 +238,7 @@ export class ProviderSide {
if (call.hold !== hold) continue;
this.#calls.delete(id);
if (call.kind === "served") call.abort.abort(reason);
else if (call.span !== undefined) relayEnded(call.span, undefined);
}
if (hold.kind === "served") this.unbind(hold);
this.#settle();
@ -236,8 +246,11 @@ export class ProviderSide {
/** A call ended with `reply` (a result or an error): its slot is free; nothing is sent for one already gone. */
reply(id: number, reply: Extract<OriginMessage, { readonly kind: "result" | "error" }>): void {
if (!this.#calls.delete(id)) return;
const call = this.#calls.get(id);
if (call === undefined) return;
this.#calls.delete(id);
this.send(reply);
if (call.kind === "relayed" && call.span !== undefined) relayEnded(call.span, reply);
this.#settle();
}
@ -262,6 +275,8 @@ export class ProviderSide {
unbind(hold: Hold): void {
this.#waiting.delete(hold);
this.#binding.delete(hold);
// Nothing waits any more: no wait to record.
if (this.#waiting.size === 0) this.#waitingSince = undefined;
}
/**
@ -383,8 +398,10 @@ export class ProviderSide {
this.#refuse(message.call, error);
return;
}
this.#calls.set(message.call, { kind: "relayed", hold });
hold.call(message);
const relayed: RunningCall = { kind: "relayed", hold };
this.#calls.set(message.call, relayed);
// Registered first: a hold without an upstream link answers at once.
relayed.span = hold.call(message);
return;
}
if (!hold.callable) {
@ -406,32 +423,44 @@ export class ProviderSide {
const args = json === undefined ? null : parsePayload(json, segments);
const call = { kind: "served", hold, bytes: method.resultBytes, abort: new AbortController() } as const;
this.#calls.set(message.call, call);
void this.#run(message.call, call, method.name, args);
// The caller's span over the link: its carrier with this host's adapter (absent or unknown: the adapter's root).
const parent = parentOf(message.trace, this.link.host.telemetry);
this.#run(message.call, call, method.name, args, parent);
}
/**
* Runs a call and sends its result (absent when `null`) or error, unless it was aborted, released or gone
* meanwhile. A result that cannot be encoded is sent as its error.
*/
async #run(
#run(
id: number,
call: Extract<RunningCall, { readonly kind: "served" }>,
method: string,
args: unknown,
): Promise<void> {
let reply: Extract<OriginMessage, { readonly kind: "result" | "error" }>;
parent: TelemetryContext,
): void {
const context = withAbortSignal(call.abort.signal, this.link.context);
let running: Promise<unknown>;
try {
// A link's context has no abort signal, so this is the call's own signal: no `AbortSignal.any` per call.
const result = await call.hold.call(method, args, withAbortSignal(call.abort.signal, this.link.context));
// Results are not validated: they are the provider's.
reply =
result === null || result === undefined
? { kind: "result", call: id }
: this.#result(id, result, call.bytes, this.link.context);
running = call.hold.call(method, args, parent, context);
} catch (error) {
reply = { kind: "error", call: id, error: wireError(error) };
running = Promise.reject(error);
}
this.reply(id, reply);
running.then(
(result) => {
let reply: Extract<OriginMessage, { readonly kind: "result" | "error" }>;
try {
reply =
result === null || result === undefined
? { kind: "result", call: id }
: this.#result(id, result, call.bytes, this.link.context);
} catch (error) {
reply = { kind: "error", call: id, error: wireError(error) };
}
this.reply(id, reply);
},
(error: unknown) => this.reply(id, { kind: "error", call: id, error: wireError(error) }),
);
}
/** Answers call `id` with `error` before it was admitted: it took no slot. */
@ -443,8 +472,12 @@ export class ProviderSide {
const call = this.#calls.get(id);
if (call === undefined) return;
this.#calls.delete(id);
if (call.kind === "relayed") call.hold.abort(id);
else call.abort.abort(new ChordError({ code: "aborted", message: `call ${id}: aborted by its caller` }));
if (call.kind === "served") {
call.abort.abort(new ChordError({ code: "aborted", message: `call ${id}: aborted by its caller` }));
return;
}
call.hold.abort(id);
if (call.span !== undefined) relayEnded(call.span, undefined);
}
/**
@ -484,6 +517,7 @@ export class ProviderSide {
if (!hold.bound) continue;
hold.queue();
this.#waiting.add(hold);
this.#waitingSince ??= performance.now();
}
}
@ -509,6 +543,7 @@ export class ProviderSide {
} else if (this.#waiting.size > 0) {
const holds = [...this.#waiting];
this.#waiting.clear();
this.#waited();
this.#bindingTurn = this.#binding.size > 0;
this.#sendOwn({ kind: "state", holds: holds.map((hold) => hold.pendingEntry(context)) });
} else {
@ -532,10 +567,18 @@ export class ProviderSide {
return { kind: "result", call: id, value, ...(segments === undefined ? {} : { segments }) };
}
/** The waiting state went out (or its holds left): how long it waited for its slot is recorded. */
#waited(): void {
if (this.#waitingSince === undefined) return;
this.link.host.metrics.histogram("chord.backpressure.wait").record(performance.now() - this.#waitingSince);
this.#waitingSince = undefined;
}
/** Sends one of this host's own `bound` or `state` messages, taking a slot. */
#sendOwn(message: Extract<OriginMessage, { readonly kind: "bound" | "state" }>): void {
this.#inFlight++;
this.#sent.push("local");
if (message.kind === "state") this.link.host.metrics.counter("chord.link.state_messages").add(1);
this.send(message);
}
}

119
packages/chord/src/remote/relay.ts
View file

@ -1,11 +1,14 @@
// Relayed holds (§4, §22, R1; decision "Relay flow control per origin"): a hold that arrived on one link (downstream)
// and that this host neither serves nor parses, held again on its path's link (upstream) with the same id under its
// downstream origin's number there; messages are forwarded between the two with the origin rewritten and parts
// untouched.
// untouched. Forwarding a hold or a call is a `chord.relay` span under the arriving carrier, whose own carrier goes
// upstream (slice 9).
import type { TelemetryCarrier, TelemetrySpan } from "@earendil-works/pi-telemetry";
import { ChordError } from "../data/index.ts";
import type { Caller } from "../host/internal.ts";
import { type Message, wireError } from "../link/internal.ts";
import { errorFromWire, type Message, type OriginMessage, wireError } from "../link/internal.ts";
import { capped, carrierOf, ended, OpenSpan, parentOf, spanFailed, untraced } from "../telemetry.ts";
import { actingFor, type HoldRequest } from "./hold.ts";
import type { HostLink } from "./host-link.ts";
import type { Path } from "./path.ts";
@ -31,18 +34,39 @@ export class RelayedHold {
readonly #path: Path;
/** The upstream link while the path has one, and the downstream origin's number on it. */
#upstream: { readonly link: HostLink; readonly origin: number } | undefined;
/** Its `chord.relay` span until it is first held upstream (or dropped); none when this host records nothing. */
#relaying: OpenSpan<"chord.relay"> | undefined;
/**
* The carrier of its first upstream hold: the relay span's, or the arriving one as it came when this host records
* nothing; a re-hold's span links to it.
*/
readonly #trace: TelemetryCarrier | undefined;
/** How many times it was held upstream. */
#holds = 0;
constructor(id: number, downstream: ProviderSide, request: HoldRequest, caller: Caller, path: Path) {
this.id = id;
this.#downstream = downstream;
const { params } = request;
const { params, trace, ...fields } = request;
// Params are never deflated: the provider side refused deflated ones.
const owned = typeof params === "string" ? params : (params as Uint8Array).slice();
this.#request = { ...request, params: owned };
this.#request = { ...fields, params: owned };
this.#trace = trace;
const adapter = downstream.link.host.telemetry;
if (!untraced(adapter)) {
this.#relaying = new OpenSpan(parentOf(trace, adapter), "chord.relay", this.#attributes("hold"));
// Upstream the hold carries the relay's span (a relay that records nothing passes the carrier on as it came).
this.#trace = carrierOf(this.#relaying.span) ?? trace;
}
this.caller = caller;
this.#path = path;
}
/** Its `chord.relay` span until it is held upstream (a route's resolve links to it); none when not recorded. */
get span(): TelemetrySpan | undefined {
return this.#relaying?.span;
}
/** Takes the pending hold's place downstream and holds upstream (now, or when the path has a link). */
start(): void {
this.#downstream.relayed(this);
@ -58,7 +82,38 @@ export class RelayedHold {
attach(link: HostLink): void {
const origin = this.#downstream.relayTo(link);
this.#upstream = { link, origin };
link.send({ kind: "hold", origin, hold: this.id, ...this.#request, ...actingFor(link, this.caller) });
const trace = this.#holdTrace(link);
link.send({
kind: "hold",
origin,
hold: this.id,
...this.#request,
...(trace === undefined ? {} : { trace }),
...actingFor(link, this.caller),
});
this.#relayed("ok");
}
/**
* The carrier of this upstream hold: the first one's; a re-hold after an upstream drop is a fresh `chord.relay` root
* linked to the first (none when this host records nothing), never the first's again (review L1).
*/
#holdTrace(link: HostLink): TelemetryCarrier | undefined {
if (this.#holds++ === 0) return this.#trace;
const adapter = link.host.telemetry;
if (this.#trace === undefined || untraced(adapter)) return undefined;
const again = new OpenSpan(adapter, "chord.relay", this.#attributes("hold"));
again.span.addLink({ context: parentOf(this.#trace, adapter) });
const carrier = carrierOf(again.span);
again.span.setAttributes({ outcome: "ok" });
again.end();
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 } {
const { type, address } = this.#request;
return { 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. */
@ -70,6 +125,7 @@ export class RelayedHold {
/** Its path's address cannot be reached for now: downstream it fails `waiting` with `error` until the next link. */
unreachable(error: ChordError): void {
this.#relayed("error", error);
this.#downstream.send({ kind: "failed", hold: this.id, cause: { kind: "waiting", error: wireError(error) } });
}
@ -98,14 +154,26 @@ export class RelayedHold {
* A call from downstream (registered there under its id), forwarded upstream at once; its reply comes back by the
* origin. Without an upstream link it is answered `unavailable` at once (it crossed the `loading` notice).
*/
call(message: Extract<Message, { readonly kind: "call" }>): void {
call(message: Extract<Message, { readonly kind: "call" }>): OpenSpan<"chord.relay"> | undefined {
const upstream = this.#upstream;
if (upstream !== undefined) {
upstream.link.send({ ...message, origin: upstream.origin });
return;
if (upstream === undefined) {
const error = new ChordError({ code: "unavailable", message: `hold ${this.id}: its upstream link is down` });
this.#downstream.reply(message.call, { kind: "error", call: message.call, error: wireError(error) });
return undefined;
}
const error = new ChordError({ code: "unavailable", message: `hold ${this.id}: its upstream link is down` });
this.#downstream.reply(message.call, { kind: "error", call: message.call, error: wireError(error) });
const adapter = upstream.link.host.telemetry;
if (untraced(adapter)) {
upstream.link.send({ ...message, origin: upstream.origin });
return undefined;
}
const span = new OpenSpan(
parentOf(message.trace, adapter),
"chord.relay",
this.#attributes(`#${message.method}`),
);
const trace = carrierOf(span.span) ?? message.trace;
upstream.link.send({ ...message, origin: upstream.origin, ...(trace === undefined ? {} : { trace }) });
return span;
}
/** A downstream `abort` of call `id`, forwarded. */
@ -129,7 +197,36 @@ export class RelayedHold {
/** No later link holds it (gone, or its downstream origin closed, which `closed` tells the upstream links). */
drop(): void {
this.#relayed("aborted");
this.#upstream = undefined;
this.#path.detach(this);
}
/** It was held upstream, failed or dropped first: its `chord.relay` span ends with `outcome`. */
#relayed(outcome: "ok" | "error" | "aborted", error?: ChordError): void {
const relaying = this.#relaying;
if (relaying === undefined) return;
this.#relaying = undefined;
if (error !== undefined) spanFailed(relaying.span, "relay_failed", error);
relaying.span.setAttributes({ outcome });
relaying.end();
}
}
/**
* A relayed call's `chord.relay` span ends with its `reply` forwarded downstream (`ok`, or the error's: `aborted` for
* a cancel), or `aborted` without one (an abort, a release, a closed link).
*/
export function relayEnded(
span: OpenSpan<"chord.relay">,
reply: Extract<OriginMessage, { readonly kind: "result" | "error" }> | undefined,
): void {
const outcome =
reply === undefined
? "aborted"
: reply.kind === "result"
? "ok"
: ended(span.span, "relay_failed", errorFromWire(reply.error), undefined);
span.span.setAttributes({ outcome });
span.end();
}

94
packages/chord/src/remote/remote-object.ts
View file

@ -1,8 +1,10 @@
// An object held over a link (§7): what one remote reference is bound to on the consumer, across the links of its path
// (the parent, or a route address). Its state, the replicas of its last bound variant (kept while its link is down),
// its hold on the path's current link and calls through it.
// its hold on the path's current link and calls through it: its hold in a `chord.hold` span until bound, each call in a
// `chord.call` span, their carriers on the wire (slice 9).
import { BACKGROUND_CONTEXT, type Context } from "../context/index.ts";
import type { TelemetryCarrier, TelemetryContext, TelemetrySpan } from "@earendil-works/pi-telemetry";
import { BACKGROUND_CONTEXT, type Context, withTelemetry } from "../context/index.ts";
import type { Contract, ParamsOf } from "../contracts/index.ts";
import {
currentVariants,
@ -39,6 +41,7 @@ import {
type WireAddress,
} from "../link/internal.ts";
import type { DeriveSource } from "../state/internal.ts";
import { capped, carrierOf, chordSpans, ended, OpenSpan, parentOf, spanFailed, untraced } from "../telemetry.ts";
import type { ConsumerSide } from "./consumer.ts";
import type { HoldRequest } from "./hold.ts";
import type { HostLink } from "./host-link.ts";
@ -81,6 +84,12 @@ export class RemoteObject implements Target {
#hold: { readonly side: ConsumerSide; readonly id: number } | undefined;
#binding: Binding | undefined;
#lastFailure: ChordError | undefined;
/** Its current `chord.hold` span until its hold's `bound` or failure; none when nothing records. */
#holding: OpenSpan<"chord.hold"> | undefined;
/** The carrier of its first hold's span: a re-hold's span links to it. */
#firstHold: TelemetryCarrier | undefined;
/** How many times it was held (on the links of its path). */
#holds = 0;
constructor(
host: AnyHost,
@ -90,18 +99,22 @@ export class RemoteObject implements Target {
caller: Caller,
path: Path,
dependent: ChordObject | undefined,
holder: TelemetryContext,
) {
this.#host = host;
this.contract = contract;
this.label = key === "" ? contract.name : `${contract.name}(${key})`;
const { name: type, version, fingerprint } = contract;
this.request = {
type,
version,
fingerprint,
params: jsonPart(params),
address,
};
// 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", {
type,
object: capped(this.label),
"address.kind": address.kind,
});
this.#firstHold = carrierOf(this.#holding.span);
}
this.request = { type, version, fingerprint, params: jsonPart(params), address };
this.caller = caller;
this.#params = params;
this.#path = path;
@ -112,6 +125,11 @@ export class RemoteObject implements Target {
return this.#state;
}
/** Its `chord.hold` span until its first `bound` or failure (a route's resolve links to it); none when not recorded. */
get span(): TelemetrySpan | undefined {
return this.#holding?.span;
}
/** An object over a link is no blocker of this host's first pass. */
get blocksFirstPass(): false {
return false;
@ -150,7 +168,28 @@ export class RemoteObject implements Target {
*/
attach(link: HostLink): void {
const chain = this.#dependent?.activationChain();
this.#hold = { side: link.consumer, id: link.consumer.attach(this, chain) };
this.#hold = { side: link.consumer, id: link.consumer.attach(this, chain, this.#holdTrace()) };
}
/**
* The carrier of this hold: the first one's span's (a child of its holder's span); a re-hold on a later link (a
* reconnect, days later for a page kept open) is a fresh `chord.hold` root of this host's adapter linked to the first,
* so nothing keeps adding children under a span long ended (review L1).
*/
#holdTrace(): TelemetryCarrier | undefined {
if (this.#holds++ === 0) return this.#firstHold;
const adapter = this.#host.telemetry;
if (this.#firstHold === undefined || untraced(adapter)) return undefined;
// A hold that dropped before it was bound ends here.
this.#held("ended");
const attributes = {
type: this.contract.name,
object: capped(this.label),
"address.kind": this.request.address.kind,
};
this.#holding = new OpenSpan(adapter, "chord.hold", attributes);
this.#holding.span.addLink({ context: parentOf(this.#firstHold, adapter) });
return carrierOf(this.#holding.span);
}
/**
@ -159,6 +198,7 @@ export class RemoteObject implements Target {
*/
unreachable(error: ChordError): void {
this.#lastFailure = error;
this.#held("failed", error);
if (this.#state.kind !== "ended")
this.#move({ kind: "failed", cause: { kind: "waiting", error }, retryAt: undefined });
}
@ -180,8 +220,26 @@ export class RemoteObject implements Target {
if (data === undefined) {
throw invalid("member", `${this.label} (variant ${bound.variant}) has no method "${method}"`);
}
const index = bound.names.methods.indexOf(method);
// Arguments are checked by the provider.
return hold.side.call(hold.id, bound.names.methods.indexOf(method), data, args, context);
const parent = context.telemetry;
if (untraced(parent)) return hold.side.call(hold.id, index, data, args, context);
const attributes = {
type: this.contract.name,
member: method,
object: capped(this.label),
"address.kind": this.request.address.kind,
};
return chordSpans(parent)("chord.call", attributes, async (span) => {
try {
const result = await hold.side.call(hold.id, index, data, args, withTelemetry(span, context));
span.setAttributes({ outcome: "ok" });
return result;
} catch (error) {
span.setAttributes({ outcome: ended(span, "call_failed", error, context.abortSignal) });
throw error;
}
});
}
/**
@ -300,6 +358,7 @@ export class RemoteObject implements Target {
/** Fails broken with `error`: no automatic retry. */
#fail(error: ChordError): void {
this.#lastFailure = error;
this.#held("failed", error);
this.#move({ kind: "failed", cause: { kind: "broken", error }, retryAt: undefined });
}
@ -355,6 +414,7 @@ export class RemoteObject implements Target {
/** After a `bound` message's batch: the reference goes live (its parked calls are sent, a parked dependent goes on). */
wentLive(): void {
this.#lastFailure = undefined;
this.#held("bound");
this.#move(LIVE);
}
@ -367,6 +427,7 @@ export class RemoteObject implements Target {
// A plugin's error a provider failed with is this object's failure, as a ChordError.
const error = asChordError(errorFromWire(message.cause.error), this.label);
this.#lastFailure = error;
this.#held("failed", error);
const retryAt = message.retryIn === undefined ? undefined : Date.now() + message.retryIn;
this.#move({ kind: "failed", cause: { kind: message.cause.kind, error }, retryAt });
}
@ -441,6 +502,7 @@ export class RemoteObject implements Target {
/** Ends the object: detached from its path, waits rejected, replicas ended; keeps nothing of its reference. */
#end(error: ChordError): void {
this.#held("ended");
const bound = this.#bound;
this.#state = { kind: "ended", error };
this.#binding = undefined;
@ -451,6 +513,16 @@ export class RemoteObject implements Target {
for (const replica of bound?.replicas.values() ?? []) replica.end(error);
}
/** Its first `bound` or failure (or its end before either): its `chord.hold` span ends with `outcome`. */
#held(outcome: "bound" | "failed" | "ended", error?: ChordError): void {
const holding = this.#holding;
if (holding === undefined) return;
this.#holding = undefined;
if (error !== undefined) spanFailed(holding.span, "hold_failed", error);
holding.span.setAttributes({ outcome });
holding.end();
}
/**
* Loading again until the next binding; the members keep their last values. A drop while it is loading already
* changes nothing: a dependent parked on it goes on waiting for the next link's binding (a drop is not a dependency

7
packages/chord/src/state/batch.ts
View file

@ -4,6 +4,7 @@
import type { TelemetryMetrics } from "@earendil-works/pi-telemetry";
import type { Context } from "../context/index.ts";
import { invalid } from "../data/internal.ts";
import { type ChordMetrics, chordMetrics } from "../telemetry.ts";
/** What a batch reports: a watch listener that threw, or a frame delivery that threw (a derive's value is no JSON). */
export type BatchError =
@ -21,7 +22,7 @@ export class Batch {
/** Reports a throwing watch listener's error (to the host's `onError`); what watches get as their `report`. */
readonly reportListener: (error: unknown) => void;
readonly #report: (error: BatchError) => void;
readonly #metrics: TelemetryMetrics | undefined;
readonly #metrics: ChordMetrics;
/** Set while adopting, delivering or computing a derive; one flag per host. */
#running = false;
/** Set while a pure compute runs (a derive's, a registry's `compose`): nothing may change a source then. */
@ -40,7 +41,7 @@ export class Batch {
constructor(report: (error: BatchError) => void, metrics: TelemetryMetrics | undefined) {
this.#report = report;
this.reportListener = (error) => report({ kind: "listener_error", error });
this.#metrics = metrics;
this.#metrics = chordMetrics(metrics);
}
/** Whether a commit's adoption, a delivery or a derive compute runs now: a change made now lands in this batch. */
@ -178,6 +179,6 @@ export class Batch {
| "chord.registry.adapts"
| "chord.contract.adapts",
): void {
this.#metrics?.counter(counter).add(1);
this.#metrics.counter(counter).add(1);
}
}

5
packages/chord/src/store/archive.ts
View file

@ -18,6 +18,7 @@ import {
unknown,
} from "../contracts/index.ts";
import { invalid, validatorFor } from "../data/internal.ts";
import { chordMetrics } from "../telemetry.ts";
import type { DocumentWrite } from "./engine.ts";
import type { TableWrite } from "./table-writes.ts";
import type { StoreWrite } from "./writes.ts";
@ -169,7 +170,7 @@ const WRITE_SCHEMA = { schema: WRITE };
/** Checks one imported part against the archive schema (a trust boundary); `invalid/args` naming its position. */
export function checkPart(part: unknown, position: number, context: Context): ArchivePart {
context.telemetry.metrics?.counter("chord.data.validations").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.validations").add(1);
if (!validatorFor(PART_SCHEMA, context).check(part)) {
throw invalid("args", `import: part ${position}: not an archive part`);
}
@ -179,7 +180,7 @@ export function checkPart(part: unknown, position: number, context: Context): Ar
/** Checks one write of a batch's commit against the write schema (a trust boundary); `what` names its place. */
export function checkWrite(write: unknown, what: string, context: Context): StoreWrite {
context.telemetry.metrics?.counter("chord.data.validations").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.validations").add(1);
if (!validatorFor(WRITE_SCHEMA, context).check(write)) throw invalid("args", `${what}: not a store write`);
// The check above establishes the type, the nodes aside (the applier checks them).
return write as StoreWrite;

3
packages/chord/src/store/json-column.ts
View file

@ -10,6 +10,7 @@ import { snapshotSchema } from "../contracts/snapshot.ts";
import { ChordError } from "../data/index.ts";
import { validatorFor } from "../data/internal.ts";
import type { JsonValue } from "../json.ts";
import { chordMetrics } from "../telemetry.ts";
/** What `json(...)` takes besides the schema. */
export type JsonColumnOptions<T> = {
@ -65,7 +66,7 @@ export class JsonColumn {
} catch (error) {
throw refused(`${what}: migrate from version ${version} threw`, error);
}
context.telemetry.metrics?.counter("chord.data.validations").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.data.validations").add(1);
if (!validatorFor(this, context).check(migrated)) {
throw refused(`${what}: migrate from version ${version} does not match the schema`);
}

3
packages/chord/src/store/live-query.ts
View file

@ -11,6 +11,7 @@ import { diffRevisions, type Op } from "../delta/index.ts";
import type { JsonValue } from "../json.ts";
import type { SqliteValue } from "../sqlite/index.ts";
import { type Batch, handedOut, Source, type WatchStart } from "../state/internal.ts";
import { chordMetrics } from "../telemetry.ts";
import type { Query } from "./query.ts";
import type { Statement } from "./sql.ts";
import type { StagedWrite, Step } from "./step.ts";
@ -268,7 +269,7 @@ export class LiveQuery extends Source {
/** One run, counted where it happens (the cost guard: a commit not writing the table runs none). */
#count(context: Context): void {
context.telemetry.metrics?.counter("chord.query.runs").add(1);
chordMetrics(context.telemetry.metrics).counter("chord.query.runs").add(1);
}
/**

13
packages/chord/src/store/store.ts
View file

@ -9,6 +9,7 @@ import { ChordError } from "../data/index.ts";
import { invalid } from "../data/internal.ts";
import type { SqliteDatabase, SqliteExecutor } from "../sqlite/index.ts";
import type { Batch } from "../state/internal.ts";
import { chordMetrics } from "../telemetry.ts";
import { IdAllocator } from "./allocator.ts";
import type { ArchivePart } from "./archive.ts";
import type { Backend } from "./backend.ts";
@ -453,9 +454,9 @@ export class ChordStore implements Store {
this.#lastSeq = seq;
this.#committedNextId = nextId;
for (const [name, record] of step.tables) this.#catalog.set(name, record);
const metrics = context.telemetry.metrics;
metrics?.counter("chord.store.commits").add(1);
metrics?.counter("chord.store.statements").add(step.statements);
const metrics = chordMetrics(context.telemetry.metrics);
metrics.counter("chord.store.commits").add(1);
metrics.counter("chord.store.statements").add(step.statements);
try {
fence.adopt(seq, step.created);
} catch (error) {
@ -507,9 +508,9 @@ export class ChordStore implements Store {
this.#committedNextId = last.nextId;
for (const [name, record] of last.tables) this.#catalog.set(name, record);
}
const metrics = context.telemetry.metrics;
metrics?.counter("chord.store.commits").add(written);
metrics?.counter("chord.store.statements").add(statements);
const metrics = chordMetrics(context.telemetry.metrics);
metrics.counter("chord.store.commits").add(written);
metrics.counter("chord.store.statements").add(statements);
try {
for (const [index, { seq, created }] of stored.entries()) receive(index, seq, created);
} catch (error) {

4
packages/chord/src/telemetry-sqlite/index.ts
View file

@ -1,3 +1,7 @@
// 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.
import {
type InstrumentOptions,
NOOP_TELEMETRY_CONTEXT,

17
packages/chord/src/telemetry-sqlite/store.ts
View file

@ -1,3 +1,5 @@
// The reads of the SQLite telemetry store (`TelemetryStore`): complete traces by query or id, metric rows by query.
import type {
MetricQuery,
SpanAttributes,
@ -63,14 +65,22 @@ 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).
*/
const SPAN_ORDER = "started_ms, 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<StoredTrace | undefined> {
const rows = await db.all<SpanRow>(
"SELECT * FROM telemetry_spans WHERE trace_id = ? ORDER BY started_ms, id",
`SELECT * FROM telemetry_spans WHERE trace_id = ? ORDER BY ${SPAN_ORDER}`,
traceId,
);
return rows.length ? { traceId, spans: rows.map(storedSpan) } : undefined;
}
/** Complete traces matching `query`, newest first, paged by an opaque cursor. */
export async function findTraces(
db: SqliteDatabase,
query: TraceQuery = {},
@ -80,7 +90,7 @@ export async function findTraces(
const params: SqliteValue[] = [];
if (query.name !== undefined) {
conditions.push(
"(SELECT name FROM telemetry_spans WHERE trace_id = heads.trace_id ORDER BY started_ms, id LIMIT 1) = ?",
`(SELECT name FROM telemetry_spans WHERE trace_id = heads.trace_id ORDER BY ${SPAN_ORDER} LIMIT 1) = ?`,
);
params.push(query.name);
}
@ -117,7 +127,7 @@ export async function findTraces(
if (more) heads.pop();
if (!heads.length) return { traces: [] };
const rows = await tx.all<SpanRow>(
"SELECT * FROM telemetry_spans WHERE trace_id IN (SELECT value FROM json_each(?)) ORDER BY started_ms, id",
`SELECT * FROM telemetry_spans WHERE trace_id IN (SELECT value FROM json_each(?)) ORDER BY ${SPAN_ORDER}`,
JSON.stringify(heads.map((head) => head.trace_id)),
);
const grouped = new Map<string, StoredSpan[]>();
@ -134,6 +144,7 @@ export async function findTraces(
});
}
/** The stored metric rows (per series and 10 s interval) matching `query`. */
export async function findMetrics(db: SqliteDatabase, query: MetricQuery): Promise<readonly StoredMetric[]> {
const params: SqliteValue[] = [query.name];
const conditions = ["name = ?"];

514
packages/chord/src/telemetry.ts Normal file
View file

@ -0,0 +1,514 @@
// Chord's telemetry (§29, slice 9): its typed schema (every span, event and metric Chord records, with their
// attributes), and how its sites record through it: no span and no attribute object under the NOOP context, spans kept
// open until an event ends them, failures with a fixed category, carriers for links, and the instruments of an
// adapter's metrics made once.
import {
createTypedMetrics,
createTypedSpanStarter,
defineTelemetrySchema,
NOOP_TELEMETRY_CONTEXT,
NOOP_TELEMETRY_METRICS,
type SchemaTelemetryCounter,
type SchemaTelemetrySpan,
type TelemetryCarrier,
type TelemetryContext,
type TelemetryMetrics,
type TelemetrySchemaSpanName,
type TelemetrySchemaSpanStartAttributes,
type TelemetrySpan,
type TypedSpanStarter,
type TypedTelemetryMetrics,
} from "@earendil-works/pi-telemetry";
import { isChordError } from "./data/index.ts";
/** A span of Chord's schema, its end attributes and events typed. */
export type ChordSpan<N extends ChordSpanName> = SchemaTelemetrySpan<typeof CHORD_TELEMETRY_SCHEMA, N>;
/** The names of Chord's spans. */
export type ChordSpanName = TelemetrySchemaSpanName<typeof CHORD_TELEMETRY_SCHEMA>;
/** Chord's instruments on one adapter's metrics, typed by its schema. */
export type ChordMetrics = TypedTelemetryMetrics<readonly [typeof CHORD_TELEMETRY_SCHEMA]>;
/** One of Chord's counters (or up/down counters), its attributes typed. */
export type ChordCounter<N extends keyof (typeof CHORD_TELEMETRY_SCHEMA)["metrics"]> = SchemaTelemetryCounter<
(typeof CHORD_TELEMETRY_SCHEMA)["metrics"][N]
>;
const type = { type: "string", required: true, description: "The object type's name." } as const;
const object = {
type: "string",
required: true,
description: "The object: its type, and its params key when it has params.",
cardinality: "high",
} as const;
const member = { type: "string", required: true, description: "The method's name." } as const;
const outcome = (values: readonly string[]) =>
({ type: "string", values, description: "How it ended; a cancel is no error (status ok)." }) as const;
const commit = {
description: "A commit of the span's object (documents and tables) inside the span's work.",
attributes: {
documents: { type: "number", required: true, description: "Documents the commit adopted." },
ops: { type: "number", required: true, description: "Ops of the documents' prepared changes." },
duration: {
type: "number",
required: true,
description: "Milliseconds from the commit's start to its adoption.",
},
},
} as const;
const retry = {
description: "A transient failure: the next attempt waits for its backoff.",
attributes: { backoff: { type: "number", required: true, description: "Milliseconds until the next attempt." } },
} as const;
const park = {
description: "The attempt parked on a dependency that is not live.",
attributes: { cause: { type: "string", required: true, description: "`loading`, or the waiting cause's message." } },
} as const;
const fate = {
description: "One object's fate in a reload.",
attributes: {
object,
fate: {
type: "string",
required: true,
values: ["swapped", "restarted", "ended", "parked", "retried"],
description: "What the object did.",
},
},
} as const;
/** Failed spans: `status: "error"` with one of these categories and the error's message (at most 500 characters). */
const ERRORS =
"The error's category (`call_failed`, `method_failed`, `relay_failed`, `hold_failed`, `activation_failed`, " +
"`open_failed`, `close_failed`, `load_failed`, `reload_failed`, `resolve_failed`, `routine_failed`, `job_failed`, " +
"`http_failed`, `trace_failed` for `ctx.trace`) and its message, " +
"at most 500 characters; a cancel keeps status ok.";
/** Chord's span, event and metric vocabulary (§29). Ids (objects, holds, calls, address keys) are span attributes only. */
export const CHORD_TELEMETRY_SCHEMA = defineTelemetrySchema({
version: 1,
spans: {
"chord.call": {
description: "A consumer's call of a remote object's method, from the call until its reply.",
parents: { kind: "any" },
startAttributes: {
type,
member,
object,
"address.kind": { type: "string", required: true, description: "The kind of the provider's host." },
},
endAttributes: { outcome: outcome(["ok", "error", "aborted"]) },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.method": {
description:
"A provider running a method: under the call's carrier (over a link) or the caller's span (same host).",
parents: { kind: "any" },
startAttributes: {
type,
member,
object,
"principal.kind": { type: "string", required: true, description: "The ctx's principal kind, or `none`." },
},
endAttributes: { outcome: outcome(["ok", "error", "aborted"]) },
events: { "chord.commit": commit },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.relay": {
description:
"A relay forwarding a hold (until it is held upstream) or a call (until its reply came back), under the arriving carrier.",
parents: { kind: "root_or_external" },
startAttributes: {
type,
member: {
type: "string",
required: true,
description: "`hold`, or a call's method as `#<index>` (a relay never knows names).",
},
"upstream.kind": { type: "string", required: true, description: "The kind of the upstream host." },
},
endAttributes: { outcome: outcome(["ok", "error", "aborted"]) },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.hold": {
description: "A consumer's hold of a remote object, until its first `bound` or failure.",
parents: { kind: "any" },
startAttributes: {
type,
object,
"address.kind": { type: "string", required: true, description: "The kind of the provider's host." },
},
endAttributes: { outcome: outcome(["bound", "failed", "ended"]) },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.activate": {
description:
"One activation attempt until it is live, failed, parked or ended (a parked one resumes in a new span); linked to its object's first trigger.",
parents: { kind: "root_or_external" },
startAttributes: {
type,
object,
attempt: { type: "number", required: true, description: "The object's attempt, from 1." },
},
endAttributes: { outcome: outcome(["live", "failed", "parked", "ended"]) },
events: { "chord.park": park, "chord.retry": retry },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.open": {
description: "One native's open, under its attempt's span.",
parents: { kind: "spans", spans: ["chord.activate"] },
startAttributes: {
type,
native: { type: "number", required: true, description: "The native's position, from 1." },
},
endAttributes: {},
status: { default: "ok", errorWhen: ERRORS },
},
"chord.close": {
description: "One native's close (a root: it runs at its attempt's teardown).",
parents: { kind: "root_or_external" },
startAttributes: {
type,
native: { type: "number", required: true, description: "The native's position, from 1." },
reason: { type: "string", required: true, values: ["end", "close", "reload"], description: "Why." },
},
endAttributes: {},
status: { default: "ok", errorWhen: ERRORS },
},
"chord.load": {
description: "A host's `load`: the setups, the publication and the start barrier.",
parents: { kind: "any" },
startAttributes: {
plugins: { type: "number", required: true, description: "Plugins given." },
},
endAttributes: { failed: { type: "number", description: "Plugins left out." } },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.reload": {
description: "A host's `reload`: staging, the commit and every object's fate.",
parents: { kind: "any" },
startAttributes: {
plugins: { type: "number", required: true, description: "Plugins given." },
},
endAttributes: {
added: { type: "number", description: "Plugins added." },
changed: { type: "number", description: "Plugins changed." },
removed: { type: "number", description: "Plugins removed." },
failed: { type: "number", description: "Plugins whose new code failed." },
fates: { type: "number", description: "Objects that took a fate." },
},
events: { "chord.reload.fate": fate },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.resolve": {
description: "A route resolving an address (a worker start included), linked to its first trigger.",
parents: { kind: "root_or_external" },
startAttributes: {
kind: { type: "string", required: true, description: "The host kind." },
address: { type: "string", required: true, description: "The address key.", cardinality: "high" },
},
endAttributes: { outcome: outcome(["linked", "failed"]) },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.revoke": {
description: "A revocation on this host.",
parents: { kind: "any" },
startAttributes: {},
endAttributes: { count: { type: "number", description: "Objects it ended and child links it closed." } },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.routine": {
description:
"One routine call (`self.on`, `self.onLive`), a root linked to the span of the commit that changed its source (when known); a throw's backoff a `chord.retry` event.",
parents: { kind: "root_or_external" },
startAttributes: {
type,
object,
routine: { type: "string", required: true, values: ["on", "onLive"], description: "Its kind." },
position: { type: "number", required: true, description: "Its position among its kind, from 1." },
},
endAttributes: { outcome: outcome(["ok", "error", "aborted"]) },
events: { "chord.commit": commit, "chord.retry": retry },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.job": {
description:
"One phase of a job run: the intent (the start's transaction), the run, the finish; under the stored carrier (persisted) or the starter's span.",
parents: { kind: "any" },
startAttributes: {
job: { type: "string", required: true, description: "The job's name." },
phase: { type: "string", required: true, values: ["intent", "run", "finish"], description: "The phase." },
object,
"job.id": { type: "string", required: false, description: "The run's id.", cardinality: "high" },
},
endAttributes: {
outcome: outcome(["ok", "error", "aborted"]),
"job.id": { type: "string", description: "The run's id, once the intent made it.", cardinality: "high" },
},
events: { "chord.commit": commit, "chord.retry": retry },
status: { default: "ok", errorWhen: ERRORS },
},
"chord.http": {
description: "An HTTP request routed to a contributed route (`chord/http`); its path is never recorded.",
parents: { kind: "root_or_external" },
startAttributes: {
method: { type: "string", required: true, description: "The request's method." },
route: { type: "string", required: true, description: "The route's pattern." },
},
endAttributes: { status: { type: "number", description: "The response's status." } },
events: { "chord.commit": commit },
status: { default: "ok", errorWhen: ERRORS },
},
},
metrics: {
"chord.data.compilations": { kind: "counter", description: "Schemas compiled.", attributes: {} },
"chord.data.validations": { kind: "counter", description: "Values validated against a schema.", attributes: {} },
"chord.data.walks": { kind: "counter", description: "Full-value walks.", attributes: {} },
"chord.link.checks": {
kind: "counter",
description: "Messages checked against the message schema.",
attributes: {},
},
"chord.link.deflates": { kind: "counter", description: "Parts deflated.", attributes: {} },
"chord.link.inflates": { kind: "counter", description: "Parts inflated.", attributes: {} },
"chord.link.encodes": {
kind: "counter",
description: "Member values and ops encoded for a hold.",
attributes: {},
},
"chord.store.loads": { kind: "counter", description: "Persisted documents loaded.", attributes: {} },
"chord.store.commits": { kind: "counter", description: "Store commits.", attributes: {} },
"chord.store.statements": { kind: "counter", description: "SQL statements of store commits.", attributes: {} },
"chord.query.runs": { kind: "counter", description: "Live query runs.", attributes: {} },
"chord.cycle.visits": { kind: "counter", description: "Objects a cycle check visited.", attributes: {} },
"chord.derive.computes": { kind: "counter", description: "Derive computations.", attributes: {} },
"chord.derive.diffs": { kind: "counter", description: "Derive diffs.", attributes: {} },
"chord.registry.composes": { kind: "counter", description: "Registry compositions.", attributes: {} },
"chord.registry.adapts": {
kind: "counter",
description: "Registry values mapped for an older reader.",
attributes: {},
},
"chord.contract.adapts": { kind: "counter", description: "State mapped for an older consumer.", attributes: {} },
"chord.link.state_messages": {
kind: "counter",
description: "`state` messages this host sent of its own.",
attributes: {},
},
"chord.link.bytes": {
kind: "counter",
unit: "By",
description: "Bytes of encoded messages on this host's links (WebSocket frames, IPC messages).",
attributes: {
direction: { type: "string", required: true, values: ["sent", "received"], description: "Which way." },
},
},
"chord.commit.duration": {
kind: "histogram",
unit: "ms",
description: "Commits of an object's documents and tables, from their start to their adoption.",
attributes: {},
},
"chord.calls.in_flight": {
kind: "upDownCounter",
description: "Method calls running on this host.",
attributes: {},
},
"chord.holds.active": {
kind: "upDownCounter",
description: "Holds arriving over links and placed on this host.",
attributes: {},
},
"chord.links.open": { kind: "upDownCounter", description: "Open links of this host.", attributes: {} },
"chord.park.duration": {
kind: "histogram",
unit: "ms",
description: "How long an activation attempt stayed parked on its dependencies.",
attributes: {},
},
"chord.backpressure.wait": {
kind: "histogram",
unit: "ms",
description: "How long a link origin's state waited for a slot of its window.",
attributes: {},
},
},
});
/**
* Whether nothing under `parent` can be recorded: it starts spans as the NOOP context does (a host without an adapter, a
* context without a span, `countingOnly`'s). Span sites then start no span, build no attributes and inject no carrier
* (§30's cost: one call).
*/
export function untraced(parent: TelemetryContext): boolean {
return parent.startSpan === NOOP_TELEMETRY_CONTEXT.startSpan;
}
/**
* A span recording nothing but carrying `metrics` (a host's adapter's): the telemetry of work a host does under a context
* without a span (its links' accepted by an app with `BACKGROUND_CONTEXT`), so the cost counters counted through that
* work's context reach the host's adapter (review L6). It starts no span: span sites treat it as untraced.
*/
export function countingOnly(metrics: TelemetryMetrics): TelemetrySpan {
return { ...NOOP_TELEMETRY_CONTEXT, metrics };
}
/** Chord's typed span starter under `parent` (for a recorded parent: it allocates). */
export function chordSpans(parent: TelemetryContext): TypedSpanStarter<readonly [typeof CHORD_TELEMETRY_SCHEMA]> {
return createTypedSpanStarter(parent, [CHORD_TELEMETRY_SCHEMA]);
}
/**
* A span of work whose end is an event, not a return (a hold until bound, an attempt until its outcome, a call until
* its handler settled): open until `end`. Its `span` is the NOOP span until the adapter started it (Chord's adapters
* call back at once).
*/
export class OpenSpan<N extends ChordSpanName> {
#span: TelemetrySpan = NOOP_TELEMETRY_CONTEXT;
readonly #done = Promise.withResolvers<void>();
#ended = false;
constructor(
parent: TelemetryContext,
name: N,
attributes: TelemetrySchemaSpanStartAttributes<typeof CHORD_TELEMETRY_SCHEMA, N>,
) {
void parent.startSpan({ name, attributes }, (span) => {
this.#span = span;
return this.#done.promise;
});
}
/** The span, typed by its schema entry. */
get span(): ChordSpan<N> {
// The adapter's span, recorded under `N`.
return this.#span as unknown as ChordSpan<N>;
}
/** Whether `end` ran. */
get ended(): boolean {
return this.#ended;
}
/** Ends the span (once; later calls do nothing). */
end(): void {
if (this.#ended) return;
this.#ended = true;
this.#done.resolve();
}
/**
* Ends the span when `work` settles, its `outcome` set: `ok`, `aborted` (a cancel, `signal`'s or `aborted`: status
* ok) or `error` with `category`.
*/
endWhen(work: Promise<unknown>, category: string, signal: AbortSignal | undefined): void {
work.then(
() => this.#close("ok"),
(error: unknown) => this.#close(ended(this.#span, category, error, signal)),
);
}
#close(outcome: "ok" | "aborted" | "error"): void {
this.#span.setAttributes({ outcome });
this.end();
}
}
/**
* The longest string attribute Chord records that a peer chose (an object's label with its params key, an address key, a
* principal's kind): stores keep it for days (slice 9 review M1).
*/
const ATTRIBUTE_LENGTH = 256;
/** `text` as a span attribute: its first 256 characters. */
export function capped(text: string): string {
return text.length > ATTRIBUTE_LENGTH ? text.slice(0, ATTRIBUTE_LENGTH) : text;
}
/** The longest message a span's error or event carries (decision "Errors in telemetry"). */
export const MAX_MESSAGE = 500;
/** Marks `span` failed with `category` and `error`'s message (at most `MAX_MESSAGE` characters). */
export function spanFailed(span: TelemetrySpan, category: string, error: unknown): void {
const message = error instanceof Error ? error.message : String(error);
span.setStatus({ status: "error", error: { name: category, message: message.slice(0, MAX_MESSAGE) } });
}
/**
* How work under `span` that threw `error` ended: `aborted` for a cancel (`signal` aborted, or Chord's `aborted`), its
* status set ok explicitly (an adapter marks a span failed when its callback throws); else `error`, the span failed
* with `category`. The outcome attribute is the caller's to set.
*/
export function ended(
span: TelemetrySpan,
category: string,
error: unknown,
signal: AbortSignal | undefined,
): "aborted" | "error" {
if (signal?.aborted === true || isChordError(error, "aborted")) {
span.setStatus({ status: "ok" });
return "aborted";
}
spanFailed(span, category, error);
return "error";
}
/** The carrier of `span` for a link, when its adapter propagates; none under the NOOP context. */
export function carrierOf(span: TelemetryContext): TelemetryCarrier | undefined {
return untraced(span) ? undefined : span.propagation?.inject(span);
}
/** The parent `carrier` names on `adapter` (a host's), its root when absent or malformed; never throws. */
export function parentOf(carrier: TelemetryCarrier | undefined, adapter: TelemetryContext): TelemetryContext {
if (untraced(adapter)) return adapter;
return adapter.propagation?.extract(carrier) ?? adapter;
}
/** Chord's instruments on the NOOP metrics, shared: no adapter, nothing made per use. */
const NOOP_METRICS = createTypedMetrics(NOOP_TELEMETRY_METRICS, [CHORD_TELEMETRY_SCHEMA]);
/** Chord's instruments by the metrics object they record to (an adapter's), each made by its first use. */
const instruments = new WeakMap<TelemetryMetrics, ChordMetrics>();
/** Chord's instruments on `metrics` (an adapter's, or none: NOOP), made once per metrics object and name. */
export function chordMetrics(metrics: TelemetryMetrics | undefined): ChordMetrics {
if (metrics === undefined || metrics === NOOP_TELEMETRY_METRICS) return NOOP_METRICS;
let made = instruments.get(metrics);
if (made === undefined) {
made = cachedMetrics(createTypedMetrics(metrics, [CHORD_TELEMETRY_SCHEMA]));
instruments.set(metrics, made);
}
return made;
}
/** `typed` with each instrument made once per name. */
function cachedMetrics(typed: ChordMetrics): ChordMetrics {
const made = new Map<string, unknown>();
const once = <T>(name: string, make: () => T): T => {
// Each name has one kind in the schema, so one instrument per name.
let instrument = made.get(name) as T | undefined;
if (instrument === undefined) {
instrument = make();
made.set(name, instrument);
}
return instrument;
};
// The instruments `typed` makes, typed by its own signatures.
return {
counter: ((name: Parameters<ChordMetrics["counter"]>[0]) =>
once(name, () => typed.counter(name))) as ChordMetrics["counter"],
upDownCounter: ((name: Parameters<ChordMetrics["upDownCounter"]>[0]) =>
once(name, () => typed.upDownCounter(name))) as ChordMetrics["upDownCounter"],
histogram: ((name: Parameters<ChordMetrics["histogram"]>[0]) =>
once(name, () => typed.histogram(name))) as ChordMetrics["histogram"],
};
}

195
packages/chord/test/bench/telemetry.ts Normal file
View file

@ -0,0 +1,195 @@
// Benchmark of slice 9's cost (§30): a call over a memory link with the NOOP adapter (to compare with the same script
// run on the code before slice 9: within noise is the target) and with the in-memory adapter on both hosts (spans,
// carriers and metrics recorded); and the container-width benchmark of R24 (§12): one item of a flat array of 1,000,
// 10,000 and 100,000 changed per commit, alone and with a `mapShared` derive over it (allocations and element visits per
// change). Median µs per operation over bursts, and heap allocated per operation (growth plus what the collections during
// the burst freed).
// Run by hand from packages/chord (not in CI), pinned for comparisons; `--noop` measures only the NOOP call (the part
// that runs on the code before slice 9 too, copied there):
// taskset -c 10 node --conditions=source --experimental-strip-types --expose-gc test/bench/telemetry.ts
import { performance } from "node:perf_hooks";
import { GCProfiler } from "node:v8";
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { BACKGROUND_CONTEXT, type Context, withTelemetry } from "../../src/context/index.ts";
import { arr, hostKind, int, local, method, obj, remote, str } from "../../src/contracts/index.ts";
import { defineState } from "../../src/documents/index.ts";
import { createHost, defineFacet } from "../../src/host/index.ts";
import { memoryLinkPair } from "../../src/link/index.ts";
import { mapShared } from "../../src/state/index.ts";
const BURSTS = 9;
const gc = (globalThis as { gc?: () => void }).gc!;
/** Median µs per operation over the bursts (after one warm-up burst), and heap bytes allocated per operation. */
async function measure(runs: number, operation: (i: number) => Promise<unknown>): Promise<string> {
const times: number[] = [];
let bytes = 0;
let counted = 0;
for (let burst = -1; burst < BURSTS; burst++) {
gc();
const before = process.memoryUsage().heapUsed;
const profiler = new GCProfiler();
profiler.start();
const started = performance.now();
for (let i = 0; i < runs; i++) await operation(i);
const elapsed = performance.now() - started;
const after = process.memoryUsage().heapUsed;
let freed = 0;
for (const { beforeGC, afterGC } of profiler.stop().statistics) {
freed += beforeGC.heapStatistics.usedHeapSize - afterGC.heapStatistics.usedHeapSize;
}
if (burst < 0) continue;
times.push((elapsed * 1000) / runs);
bytes += after - before + freed;
counted += runs;
}
times.sort((a, b) => a - b);
return `${times[Math.floor(times.length / 2)]!.toFixed(2)} µs, ${Math.round(bytes / counted)} B allocated`;
}
const Server = hostKind("server");
type P = { kind: "owner" } | { kind: "server" };
/** A remote counter: `bump` returns at once, `add` commits one document change. */
const Counter = remote("bench.counter", {
version: 1,
params: {},
hostAddress: () => Server(),
variants: { owner: { state: { n: int() }, methods: { bump: method(), add: method(int(), int()) } } },
});
const Count = defineState("bench.count", { schema: obj({ n: int() }), version: 1, initial: () => ({ n: 0 }) });
/** A server serving `Counter` and a client connected to it over a memory link, both recording to `telemetry`. */
async function linked(telemetry: InMemoryTelemetryContext | undefined) {
const server = createHost<P>({
address: Server(),
principal: { kind: "server" },
telemetry,
onError: (error) => console.log("server", error.kind),
});
await server.load(
[
{
name: "@bench/counter",
facet: defineFacet<P>((h) =>
h.serve(Counter, (_params, _principal, self) => {
const count = self.state(Count);
return {
variant: "owner",
members: {
n: self.derive([count], ([c]) => c.n),
bump: async () => null,
add: async (n, ctx) => {
await count.change((draft) => {
draft.n += n;
}, ctx);
return count.value.n;
},
},
};
}),
),
},
],
BACKGROUND_CONTEXT,
);
const client = createHost<P>({ telemetry, onError: (error) => console.log("client", error.kind) });
await client.load([], BACKGROUND_CONTEXT);
const [a, b] = memoryLinkPair();
server.accept(a, { principal: { kind: "owner" } }, BACKGROUND_CONTEXT);
client.connect(b, { principal: { kind: "server" } }, BACKGROUND_CONTEXT);
const counter = await client.get(Counter, {}, BACKGROUND_CONTEXT);
return { counter, close: () => Promise.all([client.close(BACKGROUND_CONTEXT), server.close(BACKGROUND_CONTEXT)]) };
}
/** A call over the link, and a call that commits, under `context`. */
async function calls(label: string, telemetry: InMemoryTelemetryContext | undefined, context: Context) {
const { counter, close } = await linked(telemetry);
console.log(`${label} call over a link:`, await measure(5_000, () => counter.bump(context)));
console.log(`${label} call that commits:`, await measure(5_000, () => counter.add(1, context)));
await close();
}
await calls("NOOP adapter,", undefined, BACKGROUND_CONTEXT);
if (!process.argv.includes("--noop")) {
// A fresh adapter per measurement keeps the recorded spans from growing across them.
const telemetry = new InMemoryTelemetryContext();
await telemetry.startSpan({ name: "bench" }, (span) =>
calls("in-memory adapter,", telemetry, withTelemetry(span, BACKGROUND_CONTEXT)),
);
console.log(" spans recorded:", telemetry.getSpans().length, "measurements:", telemetry.getMetrics().length);
await containerWidth();
}
/** R24: one item of a flat array of `size` changed per commit, alone and under a `mapShared` derive. */
async function containerWidth(): Promise<void> {
const Item = obj({ id: int(), text: str() });
const Shape = obj({ items: arr(Item) });
const Items = defineState("bench.items", { schema: Shape, version: 1, initial: () => ({ items: [] }) });
const Wide = local("bench.wide", {
version: 1,
params: { size: int() },
members: { visible: arr(Item), fill: method(int()), edit: method(int()) },
});
let visits = 0;
// Every edit writes a new text: an unchanged value would commit nothing.
let edits = 0;
const host = createHost({ onError: (error) => console.log("host", error.kind) });
await host.load(
[
{
name: "@bench/wide",
facet: defineFacet((h) =>
h.serve(Wide, (_params, self) => {
const items = self.state(Items);
const visible = mapShared((item: { id: number; text: string }) => {
visits++;
return { id: item.id, text: item.text };
});
return {
visible: self.derive([items], ([value]) => visible(value.items)),
fill: async (size, ctx) => {
await items.change((draft) => {
for (let id = 0; id < size; id++) draft.items.push({ id, text: `item ${id}` });
}, ctx);
return null;
},
edit: async (index, ctx) => {
await items.change((draft) => {
draft.items[index]!.text = `edit ${++edits}`;
}, ctx);
return null;
},
};
}),
),
},
],
BACKGROUND_CONTEXT,
);
for (const size of [1_000, 10_000, 100_000]) {
const wide = await host.get(Wide, { size }, BACKGROUND_CONTEXT);
await wide.fill(size, BACKGROUND_CONTEXT);
const runs = size >= 100_000 ? 200 : 2_000;
console.log(
`width ${size}, one item changed:`,
await measure(runs, (i) => wide.edit(i % size, BACKGROUND_CONTEXT)),
);
const watch = await wide.visible.watch(BACKGROUND_CONTEXT);
watch.start(async () => {});
visits = 0;
const result = await measure(runs, (i) => wide.edit(i % size, BACKGROUND_CONTEXT));
const perChange = visits / ((BURSTS + 1) * runs);
console.log(
`width ${size}, under a watched mapShared derive:`,
result,
`${perChange.toFixed(1)} mapper runs per change`,
);
await watch.stop();
wide.release();
}
await host.close(BACKGROUND_CONTEXT);
}

43
packages/chord/test/documents/documents.test.ts
View file

@ -1,5 +1,6 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
import { BACKGROUND_CONTEXT as context, withCancel } from "../../src/context/index.ts";
import { BACKGROUND_CONTEXT as context, withCancel, withTelemetry } from "../../src/context/index.ts";
import { arr, int, local, method, obj, str } from "../../src/contracts/index.ts";
import { defineState, type KeyedHandle, type SingletonHandle } from "../../src/documents/index.ts";
import { delivered, framesOf, loaded, rejection } from "../support.ts";
@ -171,3 +172,43 @@ describe('transactions their context\'s end cancelled (decision "Mistakes that w
await host.close(context);
});
});
describe("commits in telemetry (slice 9)", () => {
it("records a commit's documents, ops and duration as an event of its context's span, and its duration metric", async () => {
const telemetry = new InMemoryTelemetryContext();
let list: SingletonHandle<{ items: string[] }> | undefined;
const { host } = await loaded(
(h) =>
h.serve(Owner, (_, self) => {
list = self.state(List);
return { list, touch: async () => null };
}),
{ telemetry },
);
await host.get(Owner, { id: 1 }, context);
await telemetry.startSpan({ name: "work" }, async (span) => {
const traced = withTelemetry(span, context);
await list!.change((draft) => {
draft.items.push("a", "b");
}, traced);
// A transaction that changes nothing commits nothing: no event.
await list!.change(() => {}, traced);
});
const work = telemetry.getSpans().find(({ name }) => name === "work");
expect(work!.events).toEqual([
{ name: "chord.commit", attributes: { documents: 1, ops: 1, duration: expect.any(Number) } },
]);
expect(telemetry.getMetrics().map(({ name, unit }) => [name, unit])).toContainEqual([
"chord.commit.duration",
"ms",
]);
});
it("times nothing when nothing records", async () => {
const { list } = await owner();
const now = vi.spyOn(performance, "now");
await list.change((draft) => void draft.items.push("a"), context);
expect(now).not.toHaveBeenCalled();
now.mockRestore();
});
});

7
packages/chord/test/examples/62-telemetry/app/principals.ts Normal file
View file

@ -0,0 +1,7 @@
// The tally app's principals: its server and workers, and the kit's owner.
/** Who someone is in the tally app. */
export type TallyPrincipal =
| { readonly kind: "server" }
| { readonly kind: "owner" }
| { readonly kind: "worker"; readonly tally: string };

17
packages/chord/test/examples/62-telemetry/app/v1.ts Normal file
View file

@ -0,0 +1,17 @@
// The tally app's API, version 1 (`@tally/app/v1`): the part of Chord its plugins use, its host kind (a tally, one
// worker per tally) and the counter a tally's worker serves (clients hold it by its id; the server relays).
import { hostKind, int, method, remote, str } from "../../../../src/index.ts";
export { defineFacet, defineState, int, local, method, obj, str } from "../../../../src/index.ts";
/** A tally: its own worker process and store. */
export const Tally = hostKind("tally", { id: str() });
/** A tally's counter, served by its worker: the total, and `add` (a positive count; the new total). */
export const Counter = remote("tally.counter", {
version: 1,
params: { id: str() },
hostAddress: ({ id }) => Tally({ id }),
variants: { main: { state: { total: int() }, methods: { add: method(int(), int()) } } },
});

79
packages/chord/test/examples/62-telemetry/main.ts Normal file
View file

@ -0,0 +1,79 @@
// 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
// 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.
// Run from packages/chord:
// node --conditions=source --experimental-strip-types test/examples/62-telemetry/main.ts
import { mkdir, mkdtemp, readFile, rm } from "node:fs/promises";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { renderTrace } from "@earendil-works/pi-telemetry/render";
import { WebSocket } from "ws";
import { BACKGROUND_CONTEXT as context, withTelemetry } from "../../../src/context/index.ts";
import { createHost, type WebSocketLike, webSocketLink } from "../../../src/index.ts";
import type { TallyPrincipal } from "./app/principals.ts";
import { Counter } from "./app/v1.ts";
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.
await mkdir(dataDir, { mode: 0o700 });
const telemetry = await openTelemetry(telemetryFile(dataDir));
const app = await startTally(dataDir, telemetry, context);
const url = new URL(app.ownerLink()).origin;
console.log("1. tally app at", url, "recording to", "telemetry.sqlite");
// 2. The owner's client host (a terminal client, a page) connects over the links endpoint with the owner token. It
// records to the same adapter here (it runs in this process); a page would export to its own.
const token = (await readFile(app.ownerTokenFile, "utf8")).trim();
const client = createHost<TallyPrincipal>({ telemetry, onError: (error) => console.error("client:", error) });
await client.load([], context);
const socket = new WebSocket(`${url.replace(/^http/, "ws")}/chord`, { headers: { authorization: `Bearer ${token}` } });
client.connect(webSocketLink(socket as unknown as WebSocketLike), { principal: { kind: "server" } }, context);
console.log("2. the owner's client connected over /chord");
// 3. One click in the client is one trace: its root span, then the call through the relay into the worker's method.
const total = await telemetry.startSpan({ name: "tally.click" }, async (span) => {
const clicked = withTelemetry(span, context);
const counter = await client.get(Counter, { id: "t1" }, clicked);
return counter.add(3, clicked);
});
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 });
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<string, string>();
for (const trace of (await telemetry.findTraces({ limit: 100 })).traces) {
for (const span of trace.spans) names.set(span.id, span.name);
}
const rendered = renderTrace(traces[0]?.spans ?? [])
.replaceAll(/ \(\+?[\d.]+ms\)/g, "")
.replaceAll(/ duration=([\d.]+)/g, (_, ms: string) => ` duration=${Number(ms).toFixed(1)}`)
.replaceAll(/link trace \S+ span (\S+)/g, (_, id: string) => `link to ${names.get(id) ?? id}`);
for (const line of rendered.split("\n")) console.log(` ${line}`);
// 5. Metrics are aggregated per series and 10 s: the server's encoded bytes on its links, by direction.
await client.close(context);
await app.close(context);
await telemetry.close();
for (const direction of ["sent", "received"]) {
const rows = await telemetry.findMetrics({ name: "chord.link.bytes", attributes: { direction } });
const bytes = rows.reduce((sum, row) => sum + row.sum, 0);
console.log(
`5. chord.link.bytes ${direction}: ${bytes} bytes in ${rows.reduce((sum, row) => sum + row.count, 0)} messages`,
);
}
// The cost counters count the work they guard through the host's adapter too: messages checked against the schema.
const checks = await telemetry.findMetrics({ name: "chord.link.checks" });
console.log(`5. chord.link.checks: ${checks.reduce((sum, row) => sum + row.sum, 0)} messages checked`);
await rm(join(dataDir, ".."), { recursive: true, force: true });
console.log("6. closed");

5
packages/chord/test/examples/62-telemetry/plugins/tally/package.json Normal file
View file

@ -0,0 +1,5 @@
{
"name": "@tally/tally",
"private": true,
"type": "module"
}

46
packages/chord/test/examples/62-telemetry/plugins/tally/worker.ts Normal file
View file

@ -0,0 +1,46 @@
// The tally plugin's worker facet: the total in a persisted document, kept by the worker's one store object, and the
// counter clients call. `add` checks its argument in a child span of its own (`ctx.trace`) and commits through the
// store: its trace shows both.
import { Counter, defineFacet, defineState, int, local, method, obj } from "@tally/app/v1";
const Total = defineState("tally.total", {
schema: obj({ total: int() }),
version: 1,
initial: () => ({ total: 0 }),
persist: true,
checkpointWhen: (_value, _ops, { deltasSinceBase }) => deltasSinceBase >= 20,
});
/** The worker's total, one per worker. */
const Store = local("tally.store", { version: 1, params: {}, members: { total: int(), add: method(int(), int()) } });
export default defineFacet((host) => {
host.serve(Store, (_params, self) => {
const total = self.state(Total);
return {
total: self.derive([total], ([value]) => value.total),
add: async (n, ctx) => {
await total.change((draft) => {
draft.total += n;
}, ctx);
return total.value.total;
},
};
});
host.serve(Counter, (_params, _principal, self) => {
const store = self.get(Store, {});
return {
variant: "main",
members: {
total: self.derive([store.total], ([value]) => value),
add: async (n, ctx) => {
await ctx.trace("tally.check", { n }, async () => {
if (!Number.isSafeInteger(n) || n <= 0) throw new Error("add a positive count");
});
return store.add(n, ctx);
},
},
};
});
});

61
packages/chord/test/examples/62-telemetry/start.ts Normal file
View file

@ -0,0 +1,61 @@
// 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.
import { join } from "node:path";
import { fileURLToPath } from "node:url";
import type { Context } from "../../../src/context/index.ts";
import { type App, startServer } from "../../../src/node/app/index.ts";
import { openNodeSqliteDatabase } from "../../../src/sqlite/node.ts";
import { createSqliteTelemetry, type SqliteTelemetry } from "../../../src/telemetry-sqlite/index.ts";
import type { TallyPrincipal } from "./app/principals.ts";
import * as v1 from "./app/v1.ts";
/** The app's API: its name, versions and this process's modules (the worker's entry has the same). */
export const API = { name: "@tally/app", versions: ["v1"], modules: { "@tally/app/v1": v1 } };
/** The app's facet kinds. */
export const KINDS = { server: { platform: "node" }, worker: { platform: "node" } } as const;
/** The telemetry store every process of the app at `dataDir` records to. */
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). */
export async function openTelemetry(path: string): Promise<SqliteTelemetry> {
return createSqliteTelemetry(await openNodeSqliteDatabase(path));
}
/** Starts the tally app on a free loopback port with its data in `dataDir`, recording to `telemetry`. */
export function startTally(
dataDir: string,
telemetry: SqliteTelemetry,
context: Context,
): Promise<App<TallyPrincipal>> {
return startServer<TallyPrincipal>(
{
name: "tally",
dataDir,
root: fileURLToPath(new URL("./plugins/", import.meta.url)),
listen: { host: "127.0.0.1", port: 0 },
api: API,
kinds: KINDS,
principal: { server: { kind: "server" }, worker: (address) => ({ kind: "worker", tally: address.key }) },
telemetry,
workers: [
{
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",
},
],
onError: (error) => console.error("app:", error.kind, error.error),
},
context,
);
}

9
packages/chord/test/examples/62-telemetry/worker.ts Normal file
View file

@ -0,0 +1,9 @@
// 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.
import { startWorker } from "../../../src/node/app/index.ts";
import { API, KINDS, openTelemetry } from "./start.ts";
const telemetry = await openTelemetry(process.env.TALLY_TELEMETRY!);
startWorker({ api: API, kinds: KINDS, telemetry, onError: (error) => console.error("worker:", error) });

131
packages/chord/test/host/attempt.test.ts
View file

@ -1,6 +1,7 @@
import { createHook } from "node:async_hooks";
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { afterEach, beforeEach, describe, expect, expectTypeOf, it, vi } from "vitest";
import { type Context, BACKGROUND_CONTEXT as context, withCancel } 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, opt, remote, str } from "../../src/contracts/index.ts";
import { broken, ChordError, isChordError } from "../../src/data/index.ts";
import { defineState, type SingletonHandle } from "../../src/documents/index.ts";
@ -995,3 +996,131 @@ describe("parked attempts (dependency model §3)", () => {
view.release();
});
});
describe("activation spans (slice 9)", () => {
const Dep = local("app.dep", { version: 1, params: { id: int() }, members: { n: int() } });
describe("a transient failure and its retry", () => {
fakeTimers();
it("is a root of the host's adapter, linked to its first trigger; a retry's links to the attempt before", async () => {
const telemetry = new InMemoryTelemetryContext();
let fail = true;
const { host } = await loaded(
(h) =>
h.serve(Page, ({ id }, self) => {
self.open(
async () => {
if (fail) throw new Error("flaky");
},
() => {},
);
return { label: constant(`p${id}`), slow: async () => null };
}),
{ telemetry },
);
await telemetry.startSpan({ name: "getter" }, async (span) => {
const getting = host.get(Page, { id: 1 }, withTelemetry(span, context));
await vi.advanceTimersByTimeAsync(0);
fail = false;
await vi.advanceTimersByTimeAsync(1_000);
await getting;
});
const spans = telemetry.getSpans();
const getter = spans.find(({ name }) => name === "getter")!;
const [first, second] = spans.filter(({ name }) => name === "chord.activate");
expect(first!.parentId).toBeNull();
expect(first!.links.map(({ context: carrier }) => carrier)).toEqual([getter.context]);
expect(first!.attributes).toMatchObject({
type: "app.page",
object: "app.page(1)",
attempt: 1,
outcome: "failed",
});
expect(first!.status).toMatchObject({ status: "error", error: { name: "activation_failed" } });
expect(first!.events).toEqual([{ name: "chord.retry", attributes: { backoff: 1_000 } }]);
expect(second!.links.map(({ context: carrier }) => carrier)).toEqual([first!.context]);
expect(second!.attributes).toMatchObject({ attempt: 2, outcome: "live" });
// The getter waited for the shared activation: it links to it.
expect(getter.links.map(({ context: carrier }) => carrier)).toEqual([first!.context]);
});
});
it("ends `parked` with the cause, records the park's duration, and resumes in a new span linked to it", async () => {
const telemetry = new InMemoryTelemetryContext();
const opened = Promise.withResolvers<void>();
const { host } = await loaded(
(h) => {
h.serve(Dep, (_, self) => {
self.open(
() => opened.promise,
() => {},
);
return { n: constant(1) };
});
h.serve(Page, ({ id }, self) => ({
label: self.derive([self.get(Dep, { id }).n], ([n]) => `${n}`),
slow: async () => null,
}));
},
{ telemetry },
);
const getting = host.get(Page, { id: 1 }, context);
await flushed();
opened.resolve();
await getting;
const pages = telemetry
.getSpans()
.filter(({ name, attributes }) => name === "chord.activate" && attributes.type === "app.page");
expect(pages.map(({ attributes }) => [attributes.attempt, attributes.outcome])).toEqual([
[1, "parked"],
[1, "live"],
]);
expect(pages[0]!.events).toEqual([{ name: "chord.park", attributes: { cause: "loading" } }]);
expect(pages[1]!.links.map(({ context: carrier }) => carrier)).toEqual([pages[0]!.context]);
expect(telemetry.getMetrics().filter(({ name }) => name === "chord.park.duration")).toHaveLength(1);
});
it("records how a parked attempt ended in a short span linked to the parked one (review L4)", async () => {
const telemetry = new InMemoryTelemetryContext();
const { host } = await loaded(
(h) => {
h.serve(Dep, (_, self) => {
self.open(
() => new Promise(() => {}),
() => {},
);
return { n: constant(1) };
});
h.serve(Page, ({ id }, self) => ({
label: self.derive([self.get(Dep, { id }).n], ([n]) => `${n}`),
slow: async () => null,
}));
},
{ telemetry },
);
const page = host.hold(Page, { id: 1 }, context);
await flushed();
page.release();
await flushed();
const pages = telemetry
.getSpans()
.filter(({ name, attributes }) => name === "chord.activate" && attributes.type === "app.page");
expect(pages.map(({ attributes, settled }) => [attributes.outcome, settled])).toEqual([
["parked", true],
["ended", true],
]);
expect(pages[1]!.links.map(({ context: carrier }) => carrier)).toEqual([pages[0]!.context]);
await host.close(context);
});
it("starts nothing without an adapter that records", async () => {
const { host } = await loaded((h) =>
h.serve(Page, ({ id }) => ({ label: constant(`p${id}`), slow: async () => null })),
);
const ref = await host.get(Page, { id: 1 }, context);
expect(ref.label.value).toBe("p1");
const object = objects.at(-1)!.deref()!;
expect(object.activationSpan).toBeUndefined();
});
});

103
packages/chord/test/host/ctx.test.ts
View file

@ -1,5 +1,6 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it } from "vitest";
import { BACKGROUND_CONTEXT as context, withAbortSignal } from "../../src/context/index.ts";
import { BACKGROUND_CONTEXT as context, withAbortSignal, withTelemetry } from "../../src/context/index.ts";
import { int, local, method, remote, str } from "../../src/contracts/index.ts";
import { withLinkedAbortSignal } from "../../src/host/ctx.ts";
import type { ChordHost } from "../../src/host/host.ts";
@ -212,3 +213,103 @@ describe("linked abort signals", () => {
linked.release();
});
});
describe("ctx.trace (C11, slice 9)", () => {
const Traced = local("app.traced", {
version: 1,
params: {},
members: { work: method(undefined, int()), failing: method() },
});
/** A host recording to `telemetry`, serving `Traced`, whose `work` runs two child spans and gets an item in one. */
async function traced(telemetry: InMemoryTelemetryContext | undefined) {
const seen: { inner?: Ctx; outer?: Ctx; item?: Reference<typeof Item> } = {};
const { host } = await loaded(
(h) => {
h.serve(Item, ({ id }) => ({ id: constant(id) }));
h.serve(Traced, () => ({
work: async (ctx) => {
seen.outer = ctx;
return ctx.trace("app.step", { n: 1 }, async (inner) => {
seen.inner = inner;
seen.item = await inner.get(Item, { id: 3 });
return inner.trace("app.deeper", {}, async () => seen.item!.id.value);
});
},
failing: async (ctx) => {
await ctx.trace("app.fails", {}, async () => {
throw new Error("broke");
});
return null;
},
}));
},
{ telemetry },
);
return { host, seen };
}
it("runs fn in a child span of the handler's, with a child ctx: the same principal, signal and references", async () => {
const telemetry = new InMemoryTelemetryContext();
const { host, seen } = await traced(telemetry);
const ref = await host.get(Traced, {}, context);
await telemetry.startSpan({ name: "caller" }, async (span) => {
expect(await ref.work(withTelemetry(span, context))).toBe(3);
});
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.deeper").parentId).toBe(byName("app.step").id);
expect(seen.inner).not.toBe(seen.outer);
expect(seen.inner!.principal).toBe(seen.outer!.principal);
expect(seen.inner!.incarnation).toBe(seen.outer!.incarnation);
// The child's references are the handler's: released when the handler settled.
expect(seen.item!.state.value.kind).toBe("ended");
await expect(seen.inner!.get(Item, { id: 3 })).rejects.toMatchObject({ code: "released" });
});
it("marks its span failed (`trace_failed`) and rethrows", async () => {
const telemetry = new InMemoryTelemetryContext();
const { host } = await traced(telemetry);
const ref = await host.get(Traced, {}, context);
await telemetry.startSpan({ name: "caller" }, async (span) => {
await expect(ref.failing(withTelemetry(span, context))).rejects.toThrow("broke");
});
const failed = telemetry.getSpans().find(({ name }) => name === "app.fails")!;
expect(failed.status).toEqual({ status: "error", error: { name: "trace_failed", message: "broke" } });
});
it("rejects, never throws, when fn throws synchronously, recorded or not (review L5)", async () => {
for (const telemetry of [new InMemoryTelemetryContext(), undefined]) {
const { host } = await loaded(
(h) =>
h.serve(Traced, () => ({
work: async (ctx) => {
const traced = ctx.trace("app.sync", {}, (() => {
throw new Error("sync");
}) as () => Promise<number>);
return traced.catch(() => 7);
},
failing: async () => null,
})),
{ telemetry },
);
const ref = await host.get(Traced, {}, context);
const work = (caller: typeof context) => ref.work(caller);
const result =
telemetry === undefined
? await work(context)
: await telemetry.startSpan({ name: "caller" }, (span) => work(withTelemetry(span, context)));
expect(result).toBe(7);
if (telemetry !== undefined) expect(telemetry.getSpans().map(({ name }) => name)).toContain("app.sync");
}
});
it("gives fn the handler's own ctx when nothing records", async () => {
const { host, seen } = await traced(undefined);
const ref = await host.get(Traced, {}, context);
expect(await ref.work(context)).toBe(3);
expect(seen.inner).toBe(seen.outer);
});
});

76
packages/chord/test/host/host.test.ts
View file

@ -1,5 +1,6 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
import { BACKGROUND_CONTEXT as context, withAbortSignal, withCancel } from "../../src/context/index.ts";
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";
import { broken } from "../../src/data/index.ts";
import { type Ctx, createHost, defineFacet, type FacetHost, type HostError, type Self } from "../../src/host/index.ts";
@ -1672,3 +1673,76 @@ describe("reload: an abort while staging (fix round 1)", () => {
expect(actual).toBe(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();
const host = createHost({ telemetry, onError: () => {} });
const ok = defineFacet((h) => h.serve(Info, () => ({ title: constant("t") })));
const failing = defineFacet(() => {
throw new Error("setup");
});
await telemetry.startSpan({ name: "start" }, (span) =>
host.load(
[
{ name: "@test/ok", facet: ok },
{ name: "@test/failing", facet: failing },
],
withTelemetry(span, context),
),
);
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 });
const activation = spans.find(({ name }) => name === "chord.activate")!;
expect(activation.links.map(({ context: carrier }) => carrier)).toEqual([load.context]);
});
it("traces a reload with one event per object's fate", async () => {
const telemetry = new InMemoryTelemetryContext();
const host = createHost({ telemetry, onError: () => {} });
const facet = (title: string) => defineFacet((h) => h.serve(Info, () => ({ title: constant(title) })));
await host.load([{ name: "@test/app", facet: facet("a") }], context);
await telemetry.startSpan({ name: "apply" }, (span) =>
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.events).toEqual([
{ name: "chord.reload.fate", attributes: { object: "app.info", fate: "swapped" } },
]);
});
it("counts the cost counters of its links' and roots' work on its adapter, under contexts without a span (review L6)", async () => {
const telemetry = new InMemoryTelemetryContext();
const { server, client } = await linked((h) => void serveNotes(h), { telemetry });
const notes = await client.get(Notes, { session: "S1" }, context);
if (notes.variant !== "editor") throw new Error("expected the editor");
await notes.add({ text: "a" }, context);
await server.root(async (ctx) => (await ctx.get(Notes, { session: "S1" })).release(), context);
const counted = new Set(telemetry.getMetrics().map(({ name }) => name));
expect(counted).toContain("chord.link.checks");
expect(counted).toContain("chord.data.validations");
expect(counted).toContain("chord.link.encodes");
});
it("records a revocation's count after it under the caller's span", async () => {
const telemetry = new InMemoryTelemetryContext();
const host = createHost<TestPrincipal, string>({
address: Server(),
principal: { kind: "server" },
telemetry,
revokedBy: (principal) => (principal.kind === "guest" ? [principal.session] : []),
onError: () => {},
});
await host.load([], context);
const [a] = memoryLinkPair();
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 });
host.revoke("S1", context);
expect(telemetry.getSpans().filter(({ name }) => name === "chord.revoke")).toHaveLength(1);
});
});

86
packages/chord/test/host/native.test.ts
View file

@ -1,3 +1,4 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, expectTypeOf, it, vi } from "vitest";
import { type Context, BACKGROUND_CONTEXT as context, withCancel } from "../../src/context/index.ts";
import { int, local } from "../../src/contracts/index.ts";
@ -242,3 +243,88 @@ describe("facets", () => {
expectTypeOf<FacetHost>().not.toHaveProperty("open");
});
});
describe("spans (slice 9)", () => {
it("opens each native in a `chord.open` span of its attempt's, and closes it in a `chord.close` root", async () => {
const telemetry = new InMemoryTelemetryContext();
const { host } = await loaded(
(h) =>
h.serve(Res, (_, self) => {
self.open(
async (opening) => {
await opening.telemetry.startSpan({ name: "app.connect" }, () => {});
return 1;
},
() => {},
);
self.open(
async () => {
throw new Error("no socket");
},
() => {},
);
return { n: constant(1) };
}),
{ telemetry },
);
await rejection(host.get(Res, { id: 1 }, context, { readyTimeout: 50 }));
await flushed();
const spans = telemetry.getSpans();
const [activation] = spans.filter(({ name }) => name === "chord.activate");
const opens = spans.filter(({ name }) => name === "chord.open");
expect(opens.map(({ attributes, parentId, status }) => [attributes.native, parentId, status.status])).toEqual([
[1, activation!.id, "ok"],
[2, activation!.id, "error"],
]);
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" }]);
await host.close(context);
});
it("keeps an open its attempt abandoned (cancelled) ok (review L3)", async () => {
const telemetry = new InMemoryTelemetryContext();
const { host } = await loaded(
(h) =>
h.serve(Res, (_, self) => {
self.open(
(opening) =>
new Promise((_resolve, reject) =>
opening.abortSignal!.addEventListener("abort", () => reject(opening.abortSignal!.reason)),
),
() => {},
);
return { n: constant(1) };
}),
{ telemetry, readyTimeout: 30 },
);
await rejection(host.get(Res, { id: 1 }, context, { readyTimeout: 100 }));
await flushed();
const open = telemetry.getSpans().find(({ name }) => name === "chord.open")!;
expect([open.settled, open.status]).toEqual([true, { status: "ok" }]);
await host.close(context);
});
it("marks a close that threw failed", async () => {
const telemetry = new InMemoryTelemetryContext();
const { host } = await loaded(
(h) =>
h.serve(Res, (_, self) => {
self.open(
async () => 1,
() => {
throw new Error("stuck");
},
);
return { n: constant(1) };
}),
{ telemetry },
);
await host.get(Res, { id: 1 }, context);
await rejection(host.close(context));
const close = telemetry.getSpans().find(({ name }) => name === "chord.close")!;
expect(close.attributes.reason).toBe("close");
expect(close.status).toEqual({ status: "error", error: { name: "close_failed", message: "stuck" } });
});
});

35
packages/chord/test/host/route.test.ts
View file

@ -1,5 +1,11 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
import { BACKGROUND_CONTEXT as context, createContextKey, withContextValue } from "../../src/context/index.ts";
import {
BACKGROUND_CONTEXT as context,
createContextKey,
withContextValue,
withTelemetry,
} from "../../src/context/index.ts";
import { hostKind, int, method, remote, str } from "../../src/contracts/index.ts";
import { createHost, defineFacet, type Host } from "../../src/host/index.ts";
import { memoryLinkPair } from "../../src/link/index.ts";
@ -489,3 +495,30 @@ forEachCodec(() => {
});
});
});
describe("resolve spans (slice 9)", () => {
it("marks a resolve that rejected failed (`resolve_failed`), a root linked to the hold that started it", async () => {
const telemetry = new InMemoryTelemetryContext();
const { tab } = await relayed({
telemetry: { tab: telemetry, server: telemetry },
resolve: async () => {
throw new Error("no worker");
},
});
await telemetry.startSpan({ name: "request" }, async (span) => {
await rejection(tab.get(PlacedNotes, { session: "S1" }, withTelemetry(span, context), { readyTimeout: 50 }));
});
const spans = telemetry.getSpans();
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.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]);
expect(relay.status).toEqual({
status: "error",
error: { name: "relay_failed", message: "session|S1: no worker" },
});
});
});

60
packages/chord/test/host/routines.test.ts
View file

@ -2,8 +2,9 @@
// with the whole value, retirements, the source ending or failing, native sources, facets), `onLive` (returning,
// retries, the backoff reset after a long run, aborts), the drain and `host.close`, and what routines leave behind.
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, expectTypeOf, it, vi } from "vitest";
import { type Context, BACKGROUND_CONTEXT as context } from "../../src/context/index.ts";
import { type Context, BACKGROUND_CONTEXT as context, withTelemetry } from "../../src/context/index.ts";
import { int, local, method, obj, remote } from "../../src/contracts/index.ts";
import type { Op } from "../../src/delta/index.ts";
import { defineState, type SingletonHandle } from "../../src/documents/index.ts";
@ -57,7 +58,7 @@ const Item = local("app.item", { version: 1, params: { id: int() }, members: { n
/** Loads a host serving `Store`; `declare` declares its routines over its document. */
async function store(
declare: (doc: SingletonHandle<{ n: number }>, self: Self) => void,
options: { readonly closeTimeout?: number } = {},
options: { readonly closeTimeout?: number; readonly telemetry?: InMemoryTelemetryContext } = {},
) {
const loadedHost = await loaded(
(h) =>
@ -1154,3 +1155,58 @@ describe("routines and the end", () => {
refs = [];
});
});
describe("routine spans (slice 9)", () => {
it("traces each routine call as a root, its commits events of it, a throw `routine_failed`", async () => {
const telemetry = new InMemoryTelemetryContext();
const seen: number[] = [];
const { ref } = await store(
(doc, self) => {
self.on(doc, async ({ value }) => {
seen.push(value.n);
if (value.n === 1) throw new Error("odd");
});
self.onLive(async (ctx) => {
await bump(doc, ctx);
});
},
{ telemetry },
);
await flushed();
await settled();
expect(seen).toContain(1);
const routines = telemetry.getSpans().filter(({ name }) => name === "chord.routine");
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" },
]);
expect(live.events.map(({ name }) => name)).toEqual(["chord.commit"]);
const ons = routines.filter(({ attributes }) => attributes.routine === "on");
expect(ons.map(({ attributes, status }) => [attributes.outcome, status.status])).toContainEqual([
"error",
"error",
]);
const failedCall = ons.find(({ status }) => status.status === "error")!;
expect(failedCall.status).toEqual({ status: "error", error: { name: "routine_failed", message: "odd" } });
// Its backoff (review L7), and the commit that changed its source: the `onLive` call's.
expect(failedCall.events).toEqual([{ name: "chord.retry", attributes: { backoff: 1_000 } }]);
expect(failedCall.links.map(({ context: carrier }) => carrier)).toEqual([live.context]);
// The first call (the current value) has no trigger.
expect(ons[0]!.links).toEqual([]);
expect(ref).toBeDefined();
});
it("links a call to the method span whose commit changed its source (review L7)", async () => {
const telemetry = new InMemoryTelemetryContext();
const { ref } = await store((doc, self) => self.on(doc, async () => {}), { telemetry });
await flushed();
await telemetry.startSpan({ name: "request" }, (span) => ref.bump(withTelemetry(span, context)));
await flushed();
await settled();
const spans = telemetry.getSpans();
const bumped = spans.find(({ name, attributes }) => name === "chord.method" && attributes.member === "bump")!;
const calls = spans.filter(({ name }) => name === "chord.routine");
expect(calls.map(({ links }) => links.map(({ context: carrier }) => carrier))).toEqual([[], [bumped.context]]);
});
});

101
packages/chord/test/jobs/job.test.ts
View file

@ -2,8 +2,15 @@
// (the ctx, the state document and its fence, throws and aborts), finishes (cleanup, retries, blocked, dropped),
// `running`, keep-alive, the object's end, cost guards and GC.
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, expectTypeOf, it, vi } from "vitest";
import { type Context, BACKGROUND_CONTEXT as context, withAbortSignal, withCancel } from "../../src/context/index.ts";
import {
type Context,
BACKGROUND_CONTEXT as context,
withAbortSignal,
withCancel,
withTelemetry,
} from "../../src/context/index.ts";
import { arr, int, local, obj, remote, str, unknown } from "../../src/contracts/index.ts";
import { ChordError, PluginError, type Principal } from "../../src/data/index.ts";
import type { Op } from "../../src/delta/index.ts";
@ -1384,3 +1391,95 @@ expectTypeOf<Outcome<{ command: string }, { exit: number }, { output: string }>[
command: string;
}>();
void (null as unknown as Context);
describe("phase spans (slice 9)", () => {
fakeTimers();
it("traces the intent under the starter, the run and the finish under the intent; a failed finish try is a retry", async () => {
const telemetry = new InMemoryTelemetryContext();
let fails = 1;
const { job } = await declared(
Echo,
(_, log) => ({
run: async ({ text }) => text,
finish: async (outcome, tx) => {
if (fails-- > 0) throw new Error("not yet");
(await tx.draft(log)).list.push(outcome.kind);
},
}),
{ telemetry },
);
const run = await telemetry.startSpan({ name: "request" }, (span) =>
job.start({ text: "hi" }, withTelemetry(span, context)),
);
await vi.advanceTimersByTimeAsync(1_000);
await run.outcome(context);
const spans = telemetry.getSpans();
const request = spans.find(({ name }) => name === "request")!;
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" },
]);
expect(finish!.events.map(({ name, attributes }) => [name, attributes])).toEqual([
["chord.retry", { backoff: 1_000 }],
["chord.commit", expect.objectContaining({ documents: 1, ops: 1 })],
]);
});
it("keeps a run's ctx a job's under `ctx.trace`: its id and state, recorded or not (review L5)", async () => {
for (const telemetry of [new InMemoryTelemetryContext(), undefined]) {
const seen: { jobId?: string; output?: string; traced?: boolean }[] = [];
const { job } = await declared(
Shell,
() => ({
run: async (_args, ctx) =>
ctx.trace("app.step", {}, async (inner) => {
const job = inner as typeof ctx;
await job.state.change((draft) => {
draft.output = "half";
}, job);
seen.push({ jobId: job.jobId, output: job.state.value.output, traced: inner !== ctx });
return { exit: 0 };
}),
}),
{ telemetry },
);
const run = await job.start({ command: "ls" }, context);
await run.outcome(context);
expect(seen).toEqual([{ jobId: run.id, output: "half", traced: telemetry !== undefined }]);
}
});
it("marks a run that threw failed (`job_failed`), and an aborted one ok", async () => {
const telemetry = new InMemoryTelemetryContext();
const { job } = await declared(
Echo,
() => ({
run: async ({ text }, ctx) => {
if (text === "throw") throw new Error("boom");
await untilAborted(ctx);
throw new Error("stopped");
},
}),
{ telemetry },
);
await telemetry.startSpan({ name: "request" }, async (span) => {
const traced = withTelemetry(span, context);
const threw = await job.start({ text: "throw" }, traced);
await threw.outcome(context);
const aborted = await job.start({ text: "wait" }, traced);
await vi.advanceTimersByTimeAsync(0);
await job.abort(aborted.id, context);
await aborted.outcome(context);
});
const runs = telemetry
.getSpans()
.filter(({ name, attributes }) => name === "chord.job" && attributes.phase === "run");
expect(runs.map(({ attributes, status }) => [attributes.outcome, status])).toEqual([
["error", { status: "error", error: { name: "job_failed", message: "boom" } }],
["aborted", { status: "ok" }],
]);
});
});

42
packages/chord/test/jobs/persisted.test.ts
View file

@ -6,8 +6,9 @@
import { mkdtemp, rm } from "node:fs/promises";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { afterEach, describe, expect, it, vi } from "vitest";
import { BACKGROUND_CONTEXT as context, withCancel } from "../../src/context/index.ts";
import { BACKGROUND_CONTEXT as context, withCancel, withTelemetry } from "../../src/context/index.ts";
import { arr, int, local, num, obj, str } from "../../src/contracts/index.ts";
import { ChordError } from "../../src/data/index.ts";
import { MAX_PENDING_OPS } from "../../src/delta/pending.ts";
@ -105,10 +106,11 @@ async function opened(
run: JobImplementation<ImportArgs, ImportResult, { done: number }>["run"],
finish?: (outcome: ImportOutcome) => void,
declared: typeof Import = Import,
telemetry?: InMemoryTelemetryContext,
): Promise<Opened> {
const errors: HostError[] = [];
const finished: ImportOutcome[] = [];
const host = createHost({ store, onError: (error) => errors.push(error), closeTimeout: 200 });
const host = createHost({ store, telemetry, onError: (error) => errors.push(error), closeTimeout: 200 });
let found: Pick<Opened, "imports" | "abandoned" | "self"> | undefined;
await host.load(
[
@ -282,6 +284,42 @@ describe("crashes and restarts (D6)", () => {
});
});
describe("trace (slice 9)", () => {
it("runs, resumed after a crash in a new attempt and host, and finishes under its start's stored carrier", async () => {
const telemetry = new InMemoryTelemetryContext();
const open = await storeFile();
let jobs = await opened(await open(), () => new Promise(() => {}), undefined, Import, telemetry);
const run = await telemetry.startSpan({ name: "request" }, (span) =>
jobs.imports.start({ path: "a" }, withTelemetry(span, context)),
);
await delivered();
expect(await record(jobs.store, run.id)).toHaveProperty("trace");
await jobs.crash();
jobs = await opened(await open(), async () => ({ count: 1 }), undefined, Import, telemetry);
await delivered();
await delivered();
expect(jobs.finished).toMatchObject([{ kind: "done", result: { count: 1 } }]);
const spans = telemetry.getSpans();
const request = spans.find(({ name }) => name === "request")!;
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 },
request.id,
]);
// The run cut off by the crash (never settled), the rerun and the finish: one trace, children of the intent.
expect(phases.slice(1).map(({ attributes, parentId, settled }) => [attributes.phase, parentId, settled])).toEqual(
[
["run", intent!.id, false],
["run", intent!.id, true],
["finish", intent!.id, true],
],
);
expect(new Set(phases.map(({ context: carrier }) => carrier["pi-memory-trace"])).size).toBe(1);
await jobs.close();
});
});
describe("versions", () => {
it.each([
["another version", ImportV2],

2
packages/chord/test/link/channel.test.ts
View file

@ -8,6 +8,7 @@ import { PROTOCOL_VERSION } from "../../src/data/internal.ts";
import { createHost, type HostError } from "../../src/host/index.ts";
import { memoryLinkPair } from "../../src/link/index.ts";
import { binaryCodec, Channel, type Message, textCodec } from "../../src/link/internal.ts";
import { chordMetrics } from "../../src/telemetry.ts";
import {
bindNext,
expectCollected,
@ -290,6 +291,7 @@ describe("in-order handling", () => {
calls: 1,
trusted: true,
report: (e: unknown) => reports.push(e),
metrics: chordMetrics(undefined),
};
new Channel(a, handler, options, context).start();
const peer = new RawPeer(b);

103
packages/chord/test/link/message.test.ts
View file

@ -176,8 +176,38 @@ const EVERY_KIND: Message[] = [
{ kind: "revoke", revocation: { grant: "g1" } },
{ kind: "ping" },
{ kind: "pong" },
// Trace carriers (R5, slice 9) on a hold and a call, with and without an origin, arguments and other fields.
{
kind: "hold",
hold: 5,
type: "app.notes",
version: 1,
fingerprint: "0123456789abcdef",
params: "{}",
address: server,
trace: { "pi-memory-span": "1", "pi-memory-trace": "s:1" },
},
{
kind: "hold",
origin: 3,
hold: 6,
type: "app.notes",
version: 1,
fingerprint: "0123456789abcdef",
params: "{}",
address: server,
limit: 10,
trace: { traceparent: "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01" },
},
{ kind: "call", call: 7, hold: 0, method: 1, args: '{"text":"x"}', trace: { a: "b" } },
{ kind: "call", origin: 2, call: 8, hold: 3, method: 0, trace: {} },
];
/** A carrier at the bounds: 8 keys, keys and values of 256 characters. */
const LARGEST_CARRIER = Object.fromEntries(
Array.from({ length: 8 }, (_, index) => [`${index}`.padEnd(256, "k"), "v".repeat(256)]),
);
/** A decoded message with every part as its text, to compare with one built from text parts. */
function plain(message: Message): Message {
switch (message.kind) {
@ -291,6 +321,63 @@ forEachCodec(() => {
expect(() => checkMessage(codec.decode(closed), context)).toThrow("message schema");
});
it("carry a trace carrier up to its bounds; past them, of another shape or on another kind, the schema refuses it", () => {
const codec = testCodec();
const check = (message: unknown) => () =>
checkMessage(codec.decode(codec.encode(message as Message)), context);
const call = { kind: "call", call: 0, hold: 0, method: 0 } as const;
expect(check({ ...call, trace: LARGEST_CARRIER })()).toEqual({ ...call, trace: LARGEST_CARRIER });
expect(check({ ...call, trace: { ...LARGEST_CARRIER, nine: "x" } })).toThrow("message schema");
expect(check({ ...call, trace: { ["k".repeat(257)]: "v" } })).toThrow("message schema");
expect(check({ ...call, trace: { k: "v".repeat(257) } })).toThrow("message schema");
expect(check({ ...call, trace: { k: 1 } })).toThrow("message schema");
expect(check({ ...call, trace: ["k"] })).toThrow("message schema");
// Printable ASCII only (review M2): no control character, no space in a key; a value may hold one (W3C's
// `tracestate`).
expect(check({ ...call, trace: { k: "a\u001b[2J" } })).toThrow("message schema");
expect(check({ ...call, trace: { "k\u0007": "v" } })).toThrow("message schema");
expect(check({ ...call, trace: { "a b": "v" } })).toThrow("message schema");
expect(check({ ...call, trace: { k: "é" } })).toThrow("message schema");
expect(check({ ...call, trace: { k: "a=1, b=2" } })()).toEqual({ ...call, trace: { k: "a=1, b=2" } });
// The codecs write it only on a hold or a call; a decoder's forgery fails the schema.
expect(() => checkMessage({ kind: "abort", call: 0, trace: { k: "v" } }, context)).toThrow("message schema");
});
it("carry a trace carrier beside a call's byte segments", () => {
const codec = testCodec();
const { json, segments } = payloadPart({ data: new Uint8Array([1, 2, 3]) }, true);
const message: Message = {
kind: "call",
call: 0,
hold: 0,
method: 0,
args: json,
segments,
trace: { a: "b" },
};
const decoded = codec.decode(codec.encode(message)) as Extract<Message, { kind: "call" }>;
expect(decoded.trace).toEqual({ a: "b" });
expect(decoded.segments).toEqual(segments);
});
it("refuse a type or host kind past 256 characters (review M1: a relay records them unparsed)", () => {
const codec = testCodec();
const check = (message: unknown) => () =>
checkMessage(codec.decode(codec.encode(message as Message)), context);
const hold = {
kind: "hold",
hold: 0,
type: "t".repeat(256),
version: 1,
fingerprint: "0123456789abcdef",
params: "{}",
address: { kind: "k".repeat(256), params: {} },
};
expect(check(hold)).not.toThrow();
expect(check({ ...hold, type: "t".repeat(257) })).toThrow("message schema");
expect(check({ ...hold, address: { kind: "k".repeat(257), params: {} } })).toThrow("message schema");
});
it("keep a leading U+FEFF in strings and parts (it is data, not a byte order mark)", () => {
const codec = testCodec();
const message: Message = {
@ -401,6 +488,14 @@ describe("the binary codec", () => {
expect(() => binaryCodec.decode(state)).toThrow("a varint does not fit");
});
it("flags a trace carrier in the kind byte (0x40) and writes it as JSON after the origin", () => {
const call = binaryCodec.encode({ kind: "call", origin: 2, call: 0, hold: 0, method: 0, trace: { a: "b" } });
const json = new TextEncoder().encode('{"a":"b"}');
expect([...call.subarray(0, 3 + json.byteLength)]).toEqual([3 | 0x80 | 0x40, 2, json.byteLength, ...json]);
const plainCall = binaryCodec.encode({ kind: "call", call: 0, hold: 0, method: 0 });
expect(plainCall[0]).toBe(3);
});
it("refuses unknown hold flags", () => {
const hold = binaryCodec.encode({
kind: "hold",
@ -521,6 +616,14 @@ describe("the text codec", () => {
expect(text(hold)).toBe(`${head}]`);
expect(text({ ...hold, incarnation })).toBe(`${head},null,"${incarnation}"]`);
expect(text({ ...hold, limit: 5 })).toBe(`${head},null,null,null,5]`);
expect(text({ ...hold, trace: { a: "b" } })).toBe(`${head},null,null,null,null,{"a":"b"}]`);
});
it("writes a call's trace carrier last, its payload's fields positional then (null when absent)", () => {
const call = { kind: "call", call: 0, hold: 1, method: 2 } as const;
expect(text({ ...call, trace: { a: "b" } })).toBe('["c",0,1,2,null,null,{"a":"b"}]');
expect(text({ ...call, args: "[1]", trace: { a: "b" } })).toBe('["c",0,1,2,[0,[1]],null,{"a":"b"}]');
expect(text({ ...call, args: "[1]" })).toBe('["c",0,1,2,[0,[1]]]');
});
it("puts byte segments after the tuple and a newline, their lengths the tuple's last field", () => {

89
packages/chord/test/node/http/http.test.ts
View file

@ -5,6 +5,7 @@
// component's own answers, throwing routes and wraps, a reload swapping a route while a request runs, `close` (also
// while authenticating), a mounted handler, and requests' scopes collected.
import { InMemoryTelemetryContext, type TelemetryCarrier, type TelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
import { withAbortSignal } from "../../../src/context/index.ts";
import { arr, local, method, str } from "../../../src/contracts/index.ts";
@ -944,3 +945,91 @@ describe("GC", () => {
await server.close();
});
});
describe("request spans (slice 9)", () => {
/** An adapter reading a W3C `traceparent` as the carrier of `parent`, its first span. */
class W3cTelemetry extends InMemoryTelemetryContext {
parent: TelemetryCarrier | undefined;
readonly extracted: (TelemetryCarrier | undefined)[] = [];
override extract(carrier: TelemetryCarrier | undefined): TelemetryContext {
this.extracted.push(carrier);
if (carrier?.traceparent !== TRACEPARENT || this.parent === undefined) return super.extract(carrier);
return super.extract(this.parent);
}
}
const TRACEPARENT = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01";
const items = contributing({
routes: {
"GET /items/:id": {
public: true,
handler: (_request, ctx) => ctx.trace("app.lookup", {}, async () => ({ kind: "json", value: 1 })),
},
"GET /broken": {
public: true,
handler: async () => {
throw new Error("bug");
},
},
},
relays: [
{
name: "radius",
verify: (request) =>
request.headers.get("x-relay") === "secret" ? { origin: "https://me.relay.example" } : undefined,
},
],
});
it("traces a routed request: its method, route pattern and status, never its path; its handler's ctx under it", async () => {
const telemetry = new W3cTelemetry();
const server = await served({ "@app/items": items }, { config: { telemetry } });
expect((await send(server.port, "GET", "/items/secret-id")).status).toBe(200);
expect((await send(server.port, "GET", "/broken")).status).toBe(500);
expect((await send(server.port, "GET", "/nowhere")).status).toBe(404);
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"],
]);
expect(JSON.stringify(telemetry.getSpans())).not.toContain("secret-id");
const lookup = telemetry.getSpans().find(({ name }) => name === "app.lookup")!;
expect(lookup.parentId).toBe(requests[0]!.id);
});
it("continues a W3C traceparent only from a request a contributed relay verified", async () => {
const telemetry = new W3cTelemetry();
const parent = await telemetry.startSpan({ name: "edge" }, (span) => telemetry.inject(span));
telemetry.parent = parent;
const server = await served({ "@app/items": items }, { config: { telemetry } });
const headers = { traceparent: TRACEPARENT, "x-forwarded-for": "203.0.113.9", "x-relay": "secret" };
expect((await send(server.port, "GET", "/items/1", { headers })).status).toBe(200);
expect((await send(server.port, "GET", "/items/2", { headers: { traceparent: TRACEPARENT } })).status).toBe(200);
await server.close();
const spans = telemetry.getSpans();
const edge = spans.find(({ name }) => name === "edge")!;
expect(spans.filter(({ name }) => name === "chord.http").map(({ parentId }) => parentId)).toEqual([
edge.id,
null,
]);
});
it("takes a relayed traceparent and tracestate only within their bounds and printable (review L2)", async () => {
const telemetry = new W3cTelemetry();
const server = await served({ "@app/items": items }, { config: { telemetry } });
const relay = { "x-forwarded-for": "203.0.113.9", "x-relay": "secret" };
const get = (headers: Record<string, string>) =>
send(server.port, "GET", "/items/1", { headers: { ...relay, ...headers } });
expect((await get({ traceparent: TRACEPARENT, tracestate: "a=1, b=2" })).status).toBe(200);
expect((await get({ traceparent: `00-${"a".repeat(300)}` })).status).toBe(200);
expect((await get({ traceparent: TRACEPARENT, tracestate: "s".repeat(513) })).status).toBe(200);
await server.close();
expect(telemetry.extracted).toEqual([
{ traceparent: TRACEPARENT, tracestate: "a=1, b=2" },
{ traceparent: TRACEPARENT },
]);
});
});

76
packages/chord/test/remote/provider.test.ts
View file

@ -1,3 +1,4 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it } from "vitest";
import { BACKGROUND_CONTEXT as context } from "../../src/context/index.ts";
import { type Contract, int, local, map, method, obj, remote } from "../../src/contracts/index.ts";
@ -1021,3 +1022,78 @@ function notesHold(id: number): Extract<Message, { kind: "hold" }> {
}
const UTF8 = new TextEncoder();
describe("telemetry at the provider (slice 9)", () => {
/** A server recording to `telemetry`, serving `Notes`, and a raw consumer holding S1 (bound). */
async function traced() {
const telemetry = new InMemoryTelemetryContext();
const { peer, server } = await rawLinked((h) => void serveNotes(h), { telemetry });
hold(peer, 0, Notes, { session: "S1" });
await peer.next("bound");
return { telemetry, peer, server };
}
it("runs a call's method under its carrier, extracted with the host's adapter; an absent or unknown one is a root", async () => {
const { telemetry, peer } = await traced();
const carrier = await telemetry.startSpan({ name: "caller" }, (span) => telemetry.inject(span));
const { add: addIndex } = EDITOR.methods as { add: number };
peer.send({ kind: "call", call: 0, hold: 0, method: addIndex, args: jsonPart({ text: "a" }), trace: carrier });
await peer.next("result");
call(peer, 1, 0, addIndex, { text: "b" });
await peer.next("result");
peer.send({ kind: "call", call: 2, hold: 0, method: addIndex, args: jsonPart({ text: "c" }), trace: { x: "y" } });
await peer.next("result");
const spans = telemetry.getSpans();
const caller = spans.find(({ name }) => name === "caller")!;
const methods = spans.filter(
({ name, attributes }) => name === "chord.method" && attributes.type === "app.notes",
);
expect(methods.map(({ parentId }) => parentId)).toEqual([caller.id, null, null]);
expect(methods[0]!.attributes).toEqual({
type: "app.notes",
member: "add",
object: "app.notes(S1)",
"principal.kind": "owner",
outcome: "ok",
});
});
it("counts holds placed here up and down, its own state messages, and the bytes of its link", async () => {
const { telemetry, peer, server } = await traced();
await addNote(server, "S1", "a");
await peer.next("state");
peer.send({ kind: "release", hold: 0 });
await transported();
const sums: Record<string, number> = {};
for (const { name, value } of telemetry.getMetrics()) sums[name] = (sums[name] ?? 0) + value;
expect(sums["chord.holds.active"]).toBe(0);
expect(
telemetry
.getMetrics()
.filter(({ name }) => name === "chord.holds.active")
.map(({ value }) => value),
).toEqual([1, -1]);
expect(sums["chord.link.state_messages"]).toBe(1);
expect(sums["chord.links.open"]).toBe(1);
const bytes = telemetry.getMetrics().filter(({ name }) => name === "chord.link.bytes");
expect(new Set(bytes.map(({ attributes }) => attributes.direction))).toEqual(new Set(["sent", "received"]));
});
it("records how long state waited for a slot of the window", async () => {
const telemetry = new InMemoryTelemetryContext();
const { server } = await rawLinked((h) => void serveNotes(h), { telemetry });
const [a, b] = memoryLinkPair();
server.accept(a, { principal: { kind: "owner" }, codec: testCodec() }, context);
const slow = new RawPeer(b, { ack: false });
hold(slow, 0, Notes, { session: "S1" });
await slow.next("bound");
await addNote(server, "S1", "a");
await slow.next("state");
// The window (two messages) is full: the next change waits for an ack.
await addNote(server, "S1", "b");
expect(telemetry.getMetrics().filter(({ name }) => name === "chord.backpressure.wait")).toHaveLength(0);
slow.ack();
await slow.next("state");
expect(telemetry.getMetrics().filter(({ name }) => name === "chord.backpressure.wait")).toHaveLength(1);
});
});

66
packages/chord/test/remote/remote-object.test.ts
View file

@ -1,5 +1,6 @@
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { describe, expect, it, vi } from "vitest";
import { BACKGROUND_CONTEXT as context, withCancel } from "../../src/context/index.ts";
import { BACKGROUND_CONTEXT as context, withCancel, withTelemetry } from "../../src/context/index.ts";
import { int, local, method, obj, remote, str } from "../../src/contracts/index.ts";
import { PluginError } from "../../src/data/index.ts";
import { defineState } from "../../src/documents/index.ts";
@ -848,3 +849,66 @@ forEachCodec(() => {
});
});
});
describe("consumer spans (slice 9)", () => {
it("holds in a `chord.hold` span until bound, its carrier on the hold; a call in a `chord.call` span, its carrier on the call", async () => {
const telemetry = new InMemoryTelemetryContext();
const { client, peer } = await rawProvider({ telemetry });
await telemetry.startSpan({ name: "view" }, async (span) => {
const traced = withTelemetry(span, context);
const getting = client.get(Notes, { session: "S1" }, traced);
const held = await peer.next("hold");
bindHold(peer, held.hold);
const notes = await getting;
const calling = (notes as RefIn<typeof Notes, "editor">).add({ text: "a" }, traced);
const call = await peer.next("call");
peer.send({ kind: "error", call: call.call, error: wireError(new PluginError("quota", "full")) });
await rejection(calling);
const spans = telemetry.getSpans();
const hold = spans.find(({ name }) => name === "chord.hold")!;
const chordCall = spans.find(({ name }) => name === "chord.call")!;
expect(held.trace).toEqual(hold.context);
expect(call.trace).toEqual(chordCall.context);
expect(hold.attributes).toEqual({
type: "app.notes",
object: "app.notes(S1)",
"address.kind": "server",
outcome: "bound",
});
expect(chordCall.attributes).toMatchObject({ member: "add", outcome: "error" });
expect(chordCall.status).toEqual({ status: "error", error: { name: "call_failed", message: "full" } });
});
});
it("keeps a call its caller cancelled ok, outcome `aborted` (a thrown cancel is no error)", async () => {
const telemetry = new InMemoryTelemetryContext();
const { client, peer } = await rawProvider({ telemetry });
const getting = client.get(Notes, { session: "S1" }, context);
bindHold(peer, (await peer.next("hold")).hold);
const notes = (await getting) as RefIn<typeof Notes, "editor">;
const { context: cancellable, cancel } = withCancel(context);
await telemetry.startSpan({ name: "view" }, async (span) => {
const calling = notes.add({ text: "a" }, withTelemetry(span, cancellable));
await peer.next("call");
cancel();
await rejection(calling);
});
const call = telemetry.getSpans().find(({ name }) => name === "chord.call")!;
expect([call.attributes.outcome, call.status]).toEqual(["aborted", { status: "ok" }]);
});
it("ends a hold's span failed when its first answer is a failure", async () => {
const telemetry = new InMemoryTelemetryContext();
const { client, peer } = await rawProvider({ telemetry });
await telemetry.startSpan({ name: "view" }, async (span) => {
client.hold(Notes, { session: "S1" }, withTelemetry(span, context));
const { hold } = await peer.next("hold");
const error = { kind: "chord", error: { code: "unavailable", message: "not served" } } as const;
peer.send({ kind: "failed", hold, cause: { kind: "waiting", error } });
await delivered();
});
const hold = telemetry.getSpans().find(({ name }) => name === "chord.hold")!;
expect(hold.attributes.outcome).toBe("failed");
expect(hold.status).toEqual({ status: "error", error: { name: "hold_failed", message: "not served" } });
});
});

28
packages/chord/test/support.ts
View file

@ -4,7 +4,7 @@
import { DatabaseSync } from "node:sqlite";
import { setFlagsFromString } from "node:v8";
import { runInNewContext } from "node:vm";
import { InMemoryTelemetryContext } from "@earendil-works/pi-telemetry";
import { InMemoryTelemetryContext, type TelemetryContext } from "@earendil-works/pi-telemetry";
import { afterEach, beforeAll, beforeEach, describe, expect, vi } from "vitest";
import { BACKGROUND_CONTEXT, type Context, withTelemetry } from "../src/context/index.ts";
import {
@ -555,6 +555,7 @@ export async function rawLinked(
readonly compression?: Compression;
/** What the raw peer is to the host: a child (`accept`, the default) or its parent (`connect`). */
readonly role?: "child" | "parent";
readonly telemetry?: TelemetryContext;
} = {},
): Promise<{ readonly server: Host<TestPrincipal>; readonly peer: RawPeer; readonly errors: HostError[] }> {
const errors: HostError[] = [];
@ -563,6 +564,7 @@ export async function rawLinked(
principal: { kind: "server" },
readyTimeout: options.readyTimeout,
compression: options.compression,
telemetry: options.telemetry,
onError: (error) => errors.push(error),
});
await server.load([{ name: "@test/app", facet: defineFacet<TestPrincipal>(setup) }], BACKGROUND_CONTEXT);
@ -693,12 +695,18 @@ export async function addNote(server: Host<TestPrincipal>, session: string, text
/** A client connected to a raw peer playing the provider (the link's limits `limits`), after the handshake. */
export async function rawProvider(
options: { readonly readyTimeout?: number; readonly limits?: PartLimits; readonly compression?: Compression } = {},
options: {
readonly readyTimeout?: number;
readonly limits?: PartLimits;
readonly compression?: Compression;
readonly telemetry?: TelemetryContext;
} = {},
) {
const errors: HostError[] = [];
const client = createHost<TestPrincipal>({
readyTimeout: options.readyTimeout,
compression: options.compression,
telemetry: options.telemetry,
onError: (error) => errors.push(error),
});
await client.load([], BACKGROUND_CONTEXT);
@ -824,6 +832,12 @@ export async function relayed(
};
/** The limits of the tab's link at the server. */
readonly limits?: PartLimits;
/** The telemetry adapter of each host: tab, server, workers. */
readonly telemetry?: {
readonly tab?: TelemetryContext;
readonly server?: TelemetryContext;
readonly worker?: TelemetryContext;
};
} = {},
): Promise<Relayed> {
const context = options.context ?? BACKGROUND_CONTEXT;
@ -831,12 +845,13 @@ export async function relayed(
const workers = new Map<string, Host<TestPrincipal>>();
const routeLinks: Link[] = [];
const resolves: string[] = [];
const { revokedBy, compression = {} } = options;
const { revokedBy, compression = {}, telemetry = {} } = options;
const server = createHost<TestPrincipal>({
address: Server(),
principal: { kind: "server" },
revokedBy: options.serverRevokedBy ?? revokedBy,
compression: compression.server,
telemetry: telemetry.server,
onError: (error) => errors.server.push(error),
});
const codec = options.codecs?.route ?? testCodec();
@ -849,6 +864,7 @@ export async function relayed(
principal,
revokedBy,
compression: compression.worker,
telemetry: telemetry.worker,
onError: (error) => errors.worker.push(error),
});
host.connect(b, { principal: { kind: "server" }, trusted: options.trusted, codec }, context);
@ -874,7 +890,11 @@ export async function relayed(
[{ name: "@test/server", facet: defineFacet<TestPrincipal>((h) => options.server?.(h)) }],
context,
);
const tab = createHost<TestPrincipal>({ compression: compression.tab, onError: (error) => errors.tab.push(error) });
const tab = createHost<TestPrincipal>({
compression: compression.tab,
telemetry: telemetry.tab,
onError: (error) => errors.tab.push(error),
});
await tab.load([], context);
const [a, b] = memoryLinkPair();
const tabCodec = options.codecs?.tab ?? testCodec();

14
packages/chord/test/telemetry-sqlite.test.ts
View file

@ -95,6 +95,20 @@ describe("SQLite telemetry span and propagation conformance", () => {
});
describe("SQLite telemetry buffering and aggregation", () => {
it("orders spans started in the same millisecond as they started: a trace's first span, siblings (slice 9)", async () => {
vi.spyOn(Date, "now").mockReturnValue(20_001);
await using f = await fixture();
await f.telemetry.startSpan({ name: "root" }, async (span) => {
for (let index = 0; index < 11; index++) await span.startSpan({ name: `child ${index}` }, () => {});
});
await f.telemetry.flush();
const { traces } = await f.telemetry.findTraces({ name: "root" });
expect(traces[0]!.spans.map(({ name }) => name)).toEqual([
"root",
...Array.from({ length: 11 }, (_, index) => `child ${index}`),
]);
});
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");

457
packages/chord/test/telemetry.test.ts Normal file
View file

@ -0,0 +1,457 @@
import {
InMemoryTelemetryContext,
NOOP_TELEMETRY_CONTEXT,
NOOP_TELEMETRY_METRICS,
type StoredSpan,
type TelemetryCarrier,
type TelemetryMetrics,
} from "@earendil-works/pi-telemetry";
import { renderTrace } from "@earendil-works/pi-telemetry/render";
import { describe, expect, it } from "vitest";
import { BACKGROUND_CONTEXT, type Context, withTelemetry } from "../src/context/index.ts";
import { ChordError } from "../src/data/index.ts";
import { memoryLinkPair } from "../src/link/index.ts";
import { jsonPart, type Message } from "../src/link/internal.ts";
import { openNodeSqliteDatabase } from "../src/sqlite/node.ts";
import {
CHORD_TELEMETRY_SCHEMA,
carrierOf,
chordMetrics,
OpenSpan,
parentOf,
spanFailed,
untraced,
} from "../src/telemetry.ts";
import { createSqliteTelemetry } from "../src/telemetry-sqlite/index.ts";
import {
expectCollected,
metered,
PlacedNotes,
RawPeer,
relayed,
testCodec,
transported,
wireNames,
} from "./support.ts";
/** A context whose span is a root of `telemetry`, while `fn` runs. */
function traced<T>(telemetry: InMemoryTelemetryContext, fn: (context: Context) => Promise<T>): Promise<T> {
return telemetry.startSpan({ name: "test" }, (span) => fn(withTelemetry(span, BACKGROUND_CONTEXT)));
}
/** `spans` as a tree of names (children indented), events with `·`, without durations or attributes. */
function tree(spans: readonly StoredSpan[]): string {
return renderTrace(spans.map((span) => ({ ...span, attributes: {}, links: [], startedMs: span.startedMs })))
.replaceAll(/ \(\+?[\d.]+ms\)/g, "")
.replaceAll(/ \w+=\S+/g, "");
}
describe("the schema", () => {
it("declares every span Chord starts and keeps ids off metrics", () => {
const spans = Object.keys(CHORD_TELEMETRY_SCHEMA.spans).sort();
expect(spans).toEqual([
"chord.activate",
"chord.call",
"chord.close",
"chord.hold",
"chord.http",
"chord.job",
"chord.load",
"chord.method",
"chord.open",
"chord.relay",
"chord.reload",
"chord.resolve",
"chord.revoke",
"chord.routine",
]);
const ids = ["object", "hold", "call", "address", "job.id"];
for (const [name, metric] of Object.entries(CHORD_TELEMETRY_SCHEMA.metrics)) {
expect([name, Object.keys(metric.attributes).filter((key) => ids.includes(key))]).toEqual([name, []]);
}
});
it("declares every metric a traced call over a relay records", async () => {
const telemetry = new InMemoryTelemetryContext();
const { tab } = await relayed({ telemetry: { tab: telemetry, server: telemetry, worker: telemetry } });
await traced(telemetry, async (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);
});
const recorded = new Set(telemetry.getMetrics().map(({ name }) => name));
const declared = Object.keys(CHORD_TELEMETRY_SCHEMA.metrics);
expect([...recorded].filter((name) => !declared.includes(name))).toEqual([]);
const spans = new Set(telemetry.getSpans().map(({ name }) => name));
spans.delete("test");
expect([...spans].filter((name) => !(name in CHORD_TELEMETRY_SCHEMA.spans))).toEqual([]);
});
});
describe("nothing recorded", () => {
it("treats the NOOP context as untraced: no carrier, its own root", () => {
expect(untraced(NOOP_TELEMETRY_CONTEXT)).toBe(true);
expect(untraced(new InMemoryTelemetryContext())).toBe(false);
expect(carrierOf(NOOP_TELEMETRY_CONTEXT)).toBeUndefined();
expect(parentOf({ any: "carrier" }, NOOP_TELEMETRY_CONTEXT)).toBe(NOOP_TELEMETRY_CONTEXT);
});
it("records nothing and sends no carrier when no host has an adapter", async () => {
const { tab, tabLink } = await relayed();
const sent: unknown[] = [];
const send = tabLink.send.bind(tabLink);
tabLink.send = (bytes) => {
sent.push(bytes);
send(bytes);
};
const notes = await tab.get(PlacedNotes, { session: "S1" }, BACKGROUND_CONTEXT);
if (notes.variant !== "editor") throw new Error("expected the editor");
expect(await notes.add({ text: "a" }, BACKGROUND_CONTEXT)).toBe(1);
expect(sent.length).toBeGreaterThan(0);
});
});
describe("carriers", () => {
it("extracts an unknown or absent carrier as the adapter's root, never throwing", async () => {
const telemetry = new InMemoryTelemetryContext();
expect(parentOf(undefined, telemetry)).toBe(telemetry);
expect(parentOf({ foo: "bar" }, telemetry)).toBe(telemetry);
const carrier = await telemetry.startSpan({ name: "parent" }, (span) => carrierOf(span));
await parentOf(carrier, telemetry).startSpan({ name: "child" }, () => {});
const [parent, child] = telemetry.getSpans();
expect(child!.parentId).toBe(parent!.id);
});
});
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 ok = new OpenSpan(telemetry, "chord.method", attributes);
ok.endWhen(Promise.resolve(1), "method_failed", undefined);
const aborted = new OpenSpan(telemetry, "chord.method", attributes);
aborted.endWhen(Promise.reject(new ChordError({ code: "aborted", message: "stop" })), "method_failed", undefined);
const failed = new OpenSpan(telemetry, "chord.method", attributes);
failed.endWhen(Promise.reject(new Error("x".repeat(600))), "method_failed", undefined);
await transported();
expect(ok.ended && aborted.ended && failed.ended).toBe(true);
ok.end();
const spans = telemetry.getSpans();
expect(spans.map(({ attributes, status }) => [attributes.outcome, status.status])).toEqual([
["ok", "ok"],
["aborted", "ok"],
["error", "error"],
]);
const status = spans[2]!.status;
expect(status.status === "error" && status.error).toEqual({ name: "method_failed", message: "x".repeat(500) });
});
it("marks a span failed with a fixed category and at most 500 characters", async () => {
const telemetry = new InMemoryTelemetryContext();
await telemetry.startSpan({ name: "s" }, (span) => spanFailed(span, "call_failed", "y".repeat(501)));
expect(telemetry.getSpans()[0]!.status).toEqual({
status: "error",
error: { name: "call_failed", message: "y".repeat(500) },
});
});
});
describe("metrics", () => {
it("makes each instrument once per adapter's metrics and none for NOOP", () => {
const telemetry = new InMemoryTelemetryContext();
const metrics = chordMetrics(telemetry.metrics);
expect(chordMetrics(telemetry.metrics)).toBe(metrics);
expect(metrics.counter("chord.link.encodes")).toBe(metrics.counter("chord.link.encodes"));
expect(chordMetrics(undefined)).toBe(chordMetrics(NOOP_TELEMETRY_METRICS));
metrics.counter("chord.link.bytes").add(3, { direction: "sent" });
expect(telemetry.getMetrics()).toMatchObject([
{ name: "chord.link.bytes", kind: "counter", unit: "By", value: 3, attributes: { direction: "sent" } },
]);
});
it("keeps no adapter alive (its instruments are cached by its metrics object, weakly)", async () => {
let metrics: TelemetryMetrics | undefined = new InMemoryTelemetryContext().metrics;
const ref = new WeakRef(metrics);
chordMetrics(metrics).counter("chord.query.runs").add(1);
metrics = undefined;
await expectCollected(ref);
});
});
describe("across hosts", () => {
/** The tab, server and workers of `relayed`, all recording to one SQLite telemetry store. */
async function store() {
const db = await openNodeSqliteDatabase(":memory:");
const telemetry = await createSqliteTelemetry(db);
const hosts = await relayed({ telemetry: { tab: telemetry, server: telemetry, worker: telemetry } });
return { telemetry, ...hosts };
}
it("follows a call from the tab through the server's relay into the worker's method and its commit", 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({ name: "test" });
expect(traces).toHaveLength(1);
const spans = traces[0]!.spans;
expect(new Set(spans.map(({ traceId }) => traceId)).size).toBe(1);
const call = spans.find(({ name }) => name === "chord.call")!;
expect(call.attributes).toMatchObject({ type: "app.placed-notes", member: "add", "address.kind": "session" });
const relay = spans.find(({ name, attributes }) => name === "chord.relay" && attributes.member !== "hold")!;
expect(relay.parentId).toBe(call.id);
const method = spans.find(({ name, attributes }) => name === "chord.method" && attributes.member === "add")!;
expect(method.parentId).toBe(relay.id);
expect(method.attributes).toMatchObject({ "principal.kind": "owner", outcome: "ok" });
const local = spans.find(({ name, parentId }) => name === "chord.method" && parentId === method.id)!;
expect(local.attributes).toMatchObject({ type: "app.note-store", member: "add" });
expect(local.events.map(({ name, attributes }) => [name, attributes.documents, attributes.ops])).toEqual([
["chord.commit", 1, 1],
]);
expect(tree(spans)).toContain(
[
" chord.call",
" chord.relay",
" chord.method",
" chord.method",
" · chord.commit",
].join("\n"),
);
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) => {
await tab.get(PlacedNotes, { session: "S1" }, withTelemetry(span, BACKGROUND_CONTEXT));
});
await transported();
await telemetry.flush();
const { traces } = await telemetry.findTraces({ limit: 100 });
// In the order the store's recorder started them (its span ids count up).
const all = traces
.flatMap((trace) => trace.spans)
.sort((a, b) => Number(a.id.split(":")[1]) - Number(b.id.split(":")[1]));
const hold = all.find(({ name }) => name === "chord.hold")!;
expect(hold.attributes).toMatchObject({ type: "app.placed-notes", outcome: "bound" });
const relay = all.find(({ name, parentId }) => name === "chord.relay" && parentId === hold.id)!;
expect(relay.attributes).toMatchObject({ member: "hold", "upstream.kind": "session", outcome: "ok" });
const resolve = all.find(({ name }) => name === "chord.resolve")!;
expect(resolve.parentId).toBeUndefined();
expect(resolve.attributes).toMatchObject({ kind: "session", address: "session|S1", outcome: "linked" });
expect(resolve.links.map(({ spanId }) => spanId)).toEqual([relay.id]);
const [activation, resumed] = all.filter(
({ name, attributes }) => name === "chord.activate" && attributes.type === "app.placed-notes",
);
expect(activation!.parentId).toBeUndefined();
// Linked to its trigger, and (waiting for it) to the activation of the store it declared: it parked on it, and
// its own steps ran in a span linked to the parked one.
const noteStore = all.find(
({ name, attributes }) => name === "chord.activate" && attributes.type === "app.note-store",
)!;
expect(noteStore.links.map(({ spanId }) => spanId)).toEqual([activation!.id]);
expect(activation!.links.map(({ spanId }) => spanId)).toEqual([relay.id, noteStore.id]);
expect(activation!.attributes.outcome).toBe("parked");
expect(activation!.events.map(({ name, attributes }) => [name, attributes.cause])).toEqual([
["chord.park", "loading"],
]);
expect(resumed!.links.map(({ spanId }) => spanId)).toEqual([activation!.id]);
expect(resumed!.attributes).toMatchObject({ attempt: 1, outcome: "live" });
await telemetry.close();
});
it("costs a call over a relay exactly its spans and no extra encode", async () => {
/** One call's spans and encodes, after the reference is live, with hosts recording to `telemetry` or not. */
async function oneCall(telemetry: InMemoryTelemetryContext | undefined) {
// The links count their encodes through their context (`metered`); the caller's own span is the hosts' adapter's.
const { context, counts } = await metered();
const hosts = telemetry === undefined ? {} : { tab: telemetry, server: telemetry, worker: telemetry };
const { tab } = await relayed({ context, telemetry: hosts });
// A commit inside a recorded method counts through the method's span: both adapters are summed.
const encoded = () =>
(counts()["chord.link.encodes"] ?? 0) +
(telemetry?.getMetrics().filter(({ name }) => name === "chord.link.encodes").length ?? 0);
const call = async (caller: Context) => {
const notes = await tab.get(PlacedNotes, { session: "S1" }, caller);
if (notes.variant !== "editor") throw new Error("expected the editor");
await notes.add({ text: "warm" }, caller);
await transported();
const spans = telemetry?.getSpans().length ?? 0;
const encodes = encoded();
await notes.add({ text: "a" }, caller);
await transported();
const recorded = telemetry?.getSpans().slice(spans) ?? [];
return {
spans: recorded.map(({ name, attributes }) => `${name} ${attributes.type}`),
encodes: encoded() - encodes,
};
};
if (telemetry === undefined) return call(BACKGROUND_CONTEXT);
return telemetry.startSpan({ name: "test" }, (span) => call(withTelemetry(span, BACKGROUND_CONTEXT)));
}
const plain = await oneCall(undefined);
const recorded = await oneCall(new InMemoryTelemetryContext());
expect(recorded.spans).toEqual([
"chord.call app.placed-notes",
"chord.relay app.placed-notes",
"chord.method app.placed-notes",
"chord.method app.note-store",
]);
expect(recorded.encodes).toBe(plain.encodes);
});
it("starts a new root for a well-formed carrier the server's adapter does not know", async () => {
/** A client adapter whose carriers no other adapter reads. */
class Foreign extends InMemoryTelemetryContext {
override inject(): TelemetryCarrier {
return { unknown: "carrier" };
}
}
const telemetry = new InMemoryTelemetryContext();
const { tab } = await relayed({ telemetry: { tab: new Foreign(), server: telemetry, worker: telemetry } });
const tabTelemetry = new Foreign();
await tabTelemetry.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();
const spans = telemetry.getSpans();
const relays = spans.filter(({ name }) => name === "chord.relay");
expect(relays.map(({ parentId, parentContext }) => [parentId, parentContext])).toEqual([
[null, null],
[null, null],
]);
// The worker's method continues the relay's new trace.
const call = relays.find(({ attributes }) => attributes.member !== "hold")!;
const method = spans.find(({ name, attributes }) => name === "chord.method" && attributes.member === "add")!;
expect(method.parentId).toBe(call.id);
});
});
describe("re-holds (slice 9 review L1)", () => {
it("carries the carrier only on a reference's first hold; a re-hold after a reconnect is a fresh root linked to it", async () => {
const telemetry = new InMemoryTelemetryContext();
const { tab, server, tabLink } = await relayed({
telemetry: { tab: telemetry, server: telemetry, worker: telemetry },
});
const notes = await telemetry.startSpan({ name: "page load" }, (span) =>
tab.get(PlacedNotes, { session: "S1" }, withTelemetry(span, BACKGROUND_CONTEXT)),
);
await transported();
let link: { close(): void } = tabLink;
for (let round = 0; round < 3; round++) {
link.close();
await transported();
const [a, b] = memoryLinkPair();
link = a;
server.accept(a, { principal: { kind: "owner" }, codec: testCodec() }, BACKGROUND_CONTEXT);
tab.connect(b, { principal: { kind: "server" }, codec: testCodec() }, BACKGROUND_CONTEXT);
for (let i = 0; i < 5; i++) await transported();
}
const spans = telemetry.getSpans();
const load = spans.find(({ name }) => name === "page load")!;
const holds = spans.filter(({ name }) => name === "chord.hold");
expect(holds.map(({ parentId }) => parentId)).toEqual([load.id, null, null, null]);
const [first, ...again] = holds;
for (const hold of again) {
expect(hold.links.map(({ context: carrier }) => carrier)).toEqual([first!.context]);
expect(hold.attributes.outcome).toBe("bound");
}
const relays = spans.filter(({ name, attributes }) => name === "chord.relay" && attributes.member === "hold");
expect(relays.map(({ parentId }) => parentId)).toEqual(holds.map(({ id }) => id));
notes.release();
});
});
describe("relayed re-holds (slice 9 review L1)", () => {
it("re-holds upstream after a drop in a fresh relay root linked to the first relay span", async () => {
const telemetry = new InMemoryTelemetryContext();
const { tab, routeLinks } = await relayed({
telemetry: { tab: telemetry, server: telemetry, worker: telemetry },
});
const notes = await telemetry.startSpan({ name: "page load" }, (span) =>
tab.get(PlacedNotes, { session: "S1" }, withTelemetry(span, BACKGROUND_CONTEXT)),
);
await transported();
routeLinks[0]!.close();
for (let i = 0; i < 8; i++) await transported();
expect(routeLinks).toHaveLength(2);
const hold = telemetry.getSpans().find(({ name }) => name === "chord.hold")!;
const relays = telemetry
.getSpans()
.filter(({ name, attributes }) => name === "chord.relay" && attributes.member === "hold");
expect(relays.map(({ parentId }) => parentId)).toEqual([hold.id, null]);
expect(relays[1]!.links.map(({ context: carrier }) => carrier)).toEqual([relays[0]!.context]);
notes.release();
});
});
describe("what a peer sends (slice 9 review M1, M2, L8)", () => {
/** A server routing `Session` (recording to `telemetry`) and a raw guest peer on an untrusted link to it. */
async function hostile() {
const telemetry = new InMemoryTelemetryContext();
const { server, errors } = await relayed({ telemetry: { server: telemetry, worker: telemetry } });
const [a, b] = memoryLinkPair();
server.accept(a, { principal: { kind: "owner" }, codec: testCodec() }, BACKGROUND_CONTEXT);
const peer = new RawPeer(b);
await peer.next("hello");
return { telemetry, peer, errors };
}
/** A hold of `PlacedNotes` for S1 with `override`. */
function holdOf(override: Partial<Extract<Message, { kind: "hold" }>>): Message {
return {
kind: "hold",
hold: 0,
type: PlacedNotes.name,
version: 1,
fingerprint: PlacedNotes.fingerprint,
params: jsonPart({ session: "S1" }),
address: { kind: "session", params: { id: "S1" } },
...override,
};
}
it.each([
["a 500,000-character type", { type: "x".repeat(500_000) }],
["a 257-character host kind", { address: { kind: "k".repeat(257), params: {} } }],
["a carrier with a control character", { trace: { "pi-memory-span": "\u001b]0;PWNED\u0007" } }],
["a carrier key with a space", { trace: { "a b": "c" } }],
["a carrier of 9 keys", { trace: Object.fromEntries(Array.from({ length: 9 }, (_, i) => [`k${i}`, "v"])) }],
["a carrier value of 257 characters", { trace: { k: "v".repeat(257) } }],
])("refuses %s as a malformed header: the link closes, nothing is recorded", async (_, override) => {
const { telemetry, peer, errors } = await hostile();
peer.send(holdOf(override as Partial<Extract<Message, { kind: "hold" }>>));
await transported();
expect(peer.closed).toBe(true);
expect(errors.server.map(({ kind }) => kind)).toContain("protocol_error");
expect(telemetry.getSpans().filter(({ name }) => name === "chord.relay")).toEqual([]);
});
it("caps an object's label (its client-chosen params key) at 256 characters in its spans", async () => {
const { telemetry, peer } = await hostile();
const session = "s".repeat(10_000);
peer.send(holdOf({ params: jsonPart({ session }), address: { kind: "session", params: { id: session } } }));
await peer.next("bound");
peer.send({
kind: "call",
call: 0,
hold: 0,
method: wireNames(PlacedNotes, "editor").methods.add!,
args: jsonPart({ text: "a" }),
});
await peer.next("result");
const labelled = telemetry.getSpans().filter(({ attributes }) => typeof attributes.object === "string");
expect(labelled.map(({ name }) => name)).toEqual(expect.arrayContaining(["chord.activate", "chord.method"]));
for (const { attributes } of labelled) expect(String(attributes.object).length).toBeLessThanOrEqual(256);
const resolve = telemetry.getSpans().find(({ name }) => name === "chord.resolve")!;
expect(String(resolve.attributes.address).length).toBe(256);
});
});