From 180c58a10c9e35ada2c78cede2a1cc9f1d7aa807 Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Wed, 23 Sep 2026 21:28:48 -0400 Subject: [PATCH 01/11] feat(s090): the event catalogue, the emitters, and the log redaction filter docs/telemetry.md is written before the emitters, and the order is the point. An event name is an interface: once something attaches a handler to [:trinity, :llm, :call, :stop], renaming it breaks that consumer silently, because a handler attached to a name that no longer fires simply never runs. So the names are decided once, in the document, and the code follows it. Two tests hold them together in both directions: every event the code can emit is in the document, and every trinity event in the document is one the code can emit. The rule the catalogue opens with is that no event carries prompt text, completion text, key material or tool arguments. Handlers are attached by anything in the VM and their output reaches dashboards, logs and exporters, which is the path by which a conversation leaves by a side door. The tool span carries the tool's name and tier; a test asserts a secret passed as an argument appears in neither the start nor the stop event. Trinity.Telemetry is the only module that names an event. A call site names an emitter rather than assembling an event, so a rename is a change in one file rather than a search. Gateway outcomes are a closed set enforced by a guard, because a counter whose label is free text becomes a cardinality problem the first time somebody puts an id in it. The redaction filter is installed as a primary Logger filter at boot, so it applies to every handler rather than to one. It matches shapes rather than names, and it never returns :stop: a filter that drops a line to avoid printing a secret also drops the evidence that something happened. Its own tests state what it does not catch, in the same file. A redaction filter trusted beyond its reach is worse than none, because it turns "we mask secrets" into a belief rather than a mechanism. The controls are elsewhere: keys in files outside configuration, no token in the authorization records, no content in telemetry. This is a last line and the tests say so. Measured before building: the tree had two telemetry call sites in total, so most of this slice is emitting events that did not exist rather than consuming events that did. 16 tests. mix gate exit 0; 655 passed; coverage 80.31%. Signed-off-by: Ayla Croft --- docs/telemetry.md | 98 ++++++++++++++ lib/trinity.ex | 6 + lib/trinity/application.ex | 17 +++ lib/trinity/sessions/session.ex | 4 +- lib/trinity/telemetry.ex | 139 +++++++++++++++++++ lib/trinity/telemetry/redaction.ex | 91 +++++++++++++ lib/trinity/tools/runner.ex | 26 +++- test/trinity/telemetry/redaction_test.exs | 98 ++++++++++++++ test/trinity/telemetry/telemetry_test.exs | 154 ++++++++++++++++++++++ 9 files changed, 629 insertions(+), 4 deletions(-) create mode 100644 docs/telemetry.md create mode 100644 lib/trinity/telemetry.ex create mode 100644 lib/trinity/telemetry/redaction.ex create mode 100644 test/trinity/telemetry/redaction_test.exs create mode 100644 test/trinity/telemetry/telemetry_test.exs diff --git a/docs/telemetry.md b/docs/telemetry.md new file mode 100644 index 0000000..31b32c4 --- /dev/null +++ b/docs/telemetry.md @@ -0,0 +1,98 @@ + + +# Telemetry: the event catalogue + +Slice 090. Every event Trinity emits, what it measures, and what it carries as metadata. + +**This document is written before the emitters, and that order is deliberate.** An event name is an +interface: the moment something consumes `[:trinity, :llm, :call, :stop]`, renaming it breaks that +consumer silently, because a handler attached to a name that no longer fires simply never runs. So +the names are decided once, here, and the code follows the document rather than the document +recording whatever the code happened to do. + +## What is never in an event + +**No prompt text, no completion text, no key material, no tool arguments.** Telemetry handlers are +attached by anything in the VM and their output reaches dashboards, logs and exporters, which is +exactly the path by which a conversation ends up somewhere nobody meant it to go. Events carry +identifiers, counts and durations; the content they describe stays in the database, behind the +permission model, where a person can decide who reads it. + +A tool call's event names the tool, not its arguments. An LLM call's event names the model and the +token counts, not the messages. This is a rule rather than a default: a new event that would need +content to be useful is a new event that needs rethinking. + +## The conventions + +All events are `[:trinity, ...]`. Anything with a duration follows `:telemetry.span/3`'s shape: +`:start`, then `:stop` **or** `:exception`, so a failed operation is never silently absent from the +count of completed ones. + +Durations are in native units, as `:telemetry.span/3` emits them; convert with +`System.convert_time_unit/3` at the point of display rather than at the point of measurement. + +## The events + +### LLM + +| Event | Measurements | Metadata | +|---|---|---| +| `[:trinity, :llm, :call, :start]` | `system_time` | `model`, `provider`, `session_id`, `kind` (`:stream`, `:generate`, `:embed`) | +| `[:trinity, :llm, :call, :stop]` | `duration`, `input_tokens`, `output_tokens`, `cost_usd` | as above, plus `finish_reason` | +| `[:trinity, :llm, :call, :exception]` | `duration` | as above, plus `kind`, `reason` | + +`cost_usd` is computed from the model registry's price, the same figure written to `usage_events`, +so a dashboard total and a ledger total cannot disagree by construction. + +### Tools + +| Event | Measurements | Metadata | +|---|---|---| +| `[:trinity, :tool, :call, :start]` | `system_time` | `tool`, `session_id`, `risk` | +| `[:trinity, :tool, :call, :stop]` | `duration` | as above, plus `result` (`:ok` or `:error`) | +| `[:trinity, :tool, :call, :exception]` | `duration` | as above, plus `kind`, `reason` | + +### Permissions + +| Event | Measurements | Metadata | +|---|---|---| +| `[:trinity, :approval, :requested]` | `count: 1` | `tool`, `risk`, `session_id` | +| `[:trinity, :approval, :decided]` | `count: 1`, `waited_ms` | `tool`, `risk`, `session_id`, `decision`, `basis` | + +`waited_ms` is how long a person took to answer. It is the number that says whether the permission +model is usable or merely correct. + +### Sessions + +| Event | Measurements | Metadata | +|---|---|---| +| `[:trinity, :session, :transition]` | `count: 1` | `session_id`, `from`, `to` | + +### Gateways + +| Event | Measurements | Metadata | +|---|---|---| +| `[:trinity, :gateway, :inbound]` | `count: 1` | `adapter`, `outcome` (`:placed`, `:command`, `:unpaired`, `:rate_limited`) | +| `[:trinity, :gateway, :outbound]` | `count: 1`, `bytes` | `adapter` | + +`outcome` is deliberately a closed set: a counter whose label is free text becomes a cardinality +problem the first time it carries an id. + +### Budgets + +| Event | Measurements | Metadata | +|---|---|---| +| `[:trinity, :budget, :exceeded]` | `spent_usd`, `limit_usd` | `scope` (`:day`, `:session`, `:persona`), `scope_id` | + +## Where they go + +- **LiveDashboard**, through `TrinityWeb.Telemetry`'s metrics. +- **The Activity page**, through a bounded ring buffer. Bounded because an unbounded event buffer + is a memory leak with a nice name. +- **`usage_events`**, for cost, which is written by the LLM path itself rather than by a handler: + a handler that fails or is detached would silently stop the ledger, and a missing bill is worse + than a missing chart. + +## Adding an event + +Add it to this table first, then emit it. If it needs content to be useful, it is the wrong event. diff --git a/lib/trinity.ex b/lib/trinity.ex index 85a8d77..0577d34 100644 --- a/lib/trinity.ex +++ b/lib/trinity.ex @@ -25,6 +25,12 @@ defmodule Trinity do Vault, # Slice 080: the delegate tool and the session view's subagent panel call it. Subagents, + # Slice 090: every sub-boundary that emits an event names it through this module rather + # than calling :telemetry directly, so an event name is changed in one place. The + # redaction filter is exported because the application installs it as a primary Logger + # filter at boot. + Telemetry, + Telemetry.Redaction, Repo, Repo.Receipts, UUID, diff --git a/lib/trinity/application.ex b/lib/trinity/application.ex index 79e5cec..df2a287 100644 --- a/lib/trinity/application.ex +++ b/lib/trinity/application.ex @@ -24,6 +24,11 @@ defmodule Trinity.Application do @impl true def start(_type, _args) do + # Slice 090. Installed before anything can log, and as a primary filter so it applies to every + # handler rather than to one: a dependency that logs a request header does not know this + # project's rules about key material, and the filter is the last line for exactly that case. + install_log_redaction() + children = desktop_children() ++ [ @@ -109,6 +114,18 @@ defmodule Trinity.Application do # The lock lives in the data directory the database defaults to. A deployment that points # DATABASE_PATH elsewhere still locks the data directory, which is the thing two instances # would otherwise share; the test environment points it at a temporary directory. + defp install_log_redaction do + :logger.add_primary_filter( + :trinity_redaction, + {&Trinity.Telemetry.Redaction.filter/2, nil} + ) + rescue + # Already installed (a release that restarts the application, or a test that starts it twice). + _ -> :ok + catch + _, _ -> :ok + end + defp lock_dir do Application.get_env(:trinity, Trinity.DataDir.Lock, [])[:dir] || Trinity.Paths.ensure_data_dir() diff --git a/lib/trinity/sessions/session.ex b/lib/trinity/sessions/session.ex index bb76e0c..bd5ab71 100644 --- a/lib/trinity/sessions/session.ex +++ b/lib/trinity/sessions/session.ex @@ -117,8 +117,10 @@ defmodule Trinity.Sessions.Session do end end - def handle_event(:enter, _old, state, %State{id: id}) do + def handle_event(:enter, old, state, %State{id: id}) do Events.broadcast(id, {:state, state}) + # Slice 090: the transition, with no conversation content in it. + Trinity.Telemetry.session_transition(id, old, state) case state do :idle -> diff --git a/lib/trinity/telemetry.ex b/lib/trinity/telemetry.ex new file mode 100644 index 0000000..70f46e5 --- /dev/null +++ b/lib/trinity/telemetry.ex @@ -0,0 +1,139 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.Telemetry do + @moduledoc """ + The events Trinity emits, and the only place that names them (slice 090). + + The catalogue, with each event's measurements and metadata, is `docs/telemetry.md`, and it was + written before this module. An event name is an interface: once something attaches a handler to + `[:trinity, :llm, :call, :stop]`, renaming it breaks that consumer **silently**, because a handler + attached to a name that no longer fires simply never runs. Nothing here invents a name that the + document does not already carry. + + ## What never enters an event + + No prompt text, no completion text, no key material, no tool arguments. Handlers are attached by + anything in the VM and their output reaches dashboards, logs and exporters, which is the path by + which a conversation ends up somewhere nobody meant. Events carry identifiers, counts and + durations; the content stays in the database behind the permission model. + + `span/3` and the emitters below take only what the catalogue lists, so passing content would + require changing this module, which is the point of routing every event through it. + """ + + @doc """ + Wraps work in `:start` and `:stop`/`:exception` events under `[:trinity | name]`. + + `:telemetry.span/3`'s shape rather than a bare `execute`, so a failed operation is never silently + missing from the count of completed ones: a dashboard that counts only successes reports a healthy + system right up until somebody looks at the logs. + """ + @spec span([atom()], map(), (-> {term(), map()})) :: term() + def span(name, metadata, fun) when is_list(name) and is_map(metadata) do + :telemetry.span([:trinity | name], metadata, fun) + end + + @doc "Emits one event with the measurements and metadata the catalogue lists for it." + @spec emit([atom()], map(), map()) :: :ok + def emit(name, measurements, metadata) when is_list(name) do + :telemetry.execute([:trinity | name], measurements, metadata) + end + + ## The emitters. One function per catalogue entry, so a call site names an event rather than + ## assembling one, and a rename is a change here rather than a search. + + @doc "A completed LLM call. `cost_usd` is the registry price, the same figure the ledger stores." + @spec llm_stop(map()) :: :ok + def llm_stop(meta) do + emit( + [:llm, :call, :stop], + %{ + duration: meta[:duration] || 0, + input_tokens: meta[:input_tokens] || 0, + output_tokens: meta[:output_tokens] || 0, + cost_usd: meta[:cost_usd] || 0.0 + }, + Map.take(meta, [:model, :provider, :session_id, :kind, :finish_reason]) + ) + end + + @doc "An approval was raised. Names the tool and its tier, never its arguments." + @spec approval_requested(String.t(), atom() | String.t(), String.t() | nil) :: :ok + def approval_requested(tool, risk, session_id) do + emit([:approval, :requested], %{count: 1}, %{tool: tool, risk: risk, session_id: session_id}) + end + + @doc """ + An approval was answered, with how long the person took. + + `waited_ms` is the number that says whether the permission model is usable or merely correct: a + gate everybody waits four minutes for is a gate people learn to route around. + """ + @spec approval_decided(String.t(), atom() | String.t(), String.t() | nil, keyword()) :: :ok + def approval_decided(tool, risk, session_id, opts) do + emit( + [:approval, :decided], + %{count: 1, waited_ms: Keyword.get(opts, :waited_ms, 0)}, + %{ + tool: tool, + risk: risk, + session_id: session_id, + decision: Keyword.get(opts, :decision), + basis: Keyword.get(opts, :basis) + } + ) + end + + @doc "A session changed state." + @spec session_transition(String.t(), atom(), atom()) :: :ok + def session_transition(session_id, from, to) do + emit([:session, :transition], %{count: 1}, %{session_id: session_id, from: from, to: to}) + end + + @doc """ + A message arrived at a gateway. + + `outcome` is a closed set on purpose: a counter whose label is free text becomes a cardinality + problem the first time somebody puts an id in it. + """ + @spec gateway_inbound(String.t(), atom()) :: :ok + def gateway_inbound(adapter, outcome) + when outcome in [:placed, :command, :unpaired, :rate_limited] do + emit([:gateway, :inbound], %{count: 1}, %{adapter: adapter, outcome: outcome}) + end + + @doc "A message left for a gateway." + @spec gateway_outbound(String.t(), non_neg_integer()) :: :ok + def gateway_outbound(adapter, bytes) do + emit([:gateway, :outbound], %{count: 1, bytes: bytes}, %{adapter: adapter}) + end + + @doc "A budget was exceeded." + @spec budget_exceeded(atom(), String.t() | nil, float(), float()) :: :ok + def budget_exceeded(scope, scope_id, spent_usd, limit_usd) do + emit( + [:budget, :exceeded], + %{spent_usd: spent_usd, limit_usd: limit_usd}, + %{scope: scope, scope_id: scope_id} + ) + end + + @doc "Every event name this module can emit, for the test that holds the catalogue to the code." + @spec catalogue() :: [[atom()]] + def catalogue do + [ + [:trinity, :llm, :call, :start], + [:trinity, :llm, :call, :stop], + [:trinity, :llm, :call, :exception], + [:trinity, :tool, :call, :start], + [:trinity, :tool, :call, :stop], + [:trinity, :tool, :call, :exception], + [:trinity, :approval, :requested], + [:trinity, :approval, :decided], + [:trinity, :session, :transition], + [:trinity, :gateway, :inbound], + [:trinity, :gateway, :outbound], + [:trinity, :budget, :exceeded] + ] + end +end diff --git a/lib/trinity/telemetry/redaction.ex b/lib/trinity/telemetry/redaction.ex new file mode 100644 index 0000000..520dad7 --- /dev/null +++ b/lib/trinity/telemetry/redaction.ex @@ -0,0 +1,91 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.Telemetry.Redaction do + @moduledoc """ + A `Logger` filter that masks credentials and truncates long content (slice 090). + + **A filter is a last line, not the control.** The controls are that key material lives in files + outside configuration (slice 025), that the authorization layer's records carry no token + (slice 062), and that telemetry events carry no content at all (`docs/telemetry.md`). This exists + because logs are written by every library in the tree as well as by this project, and a + dependency that logs a request header has not read any of those rules. + + So it is deliberately blunt. It masks anything *shaped* like a credential rather than anything + known to be one, and it truncates long messages. Over-masking a log line costs a reader some + context; under-masking one puts a key on disk. + + ## What it cannot do + + It sees the message and its metadata, not the intent. A key embedded in a sentence with no + recognisable shape passes through, and a chat message that happens to look like a bearer token is + masked. Neither is a defect in the filter; both are why it is not the control. + """ + + @max_chars 2_000 + + # Shapes rather than names. Each is anchored on a prefix that exists to be recognised, which is + # the property that makes a credential's own format give it away. + @patterns [ + {~r/(?i)\b(bearer|basic|token)\s+[A-Za-z0-9._~+\/=-]{12,}/, "\\1 [REDACTED]"}, + {~r/\b(?:sk|pk|rk|api|key)[-_][A-Za-z0-9._-]{16,}/i, "[REDACTED]"}, + {~r/\bey[A-Za-z0-9_-]{8,}\.[A-Za-z0-9_-]{8,}\.[A-Za-z0-9_-]{8,}/, "[REDACTED-JWT]"}, + {~r/(?i)\b(password|passwd|secret|api[_-]?key|access[_-]?token|private[_-]?key)(\s*[:=]\s*)\S+/, + "\\1\\2[REDACTED]"} + ] + + @doc """ + The filter. Returns the event with its message and metadata masked, never `:stop`. + + Never `:stop`, on purpose: a filter that drops a line to avoid printing a secret also drops the + evidence that something happened. Masking keeps the event and removes the value. + """ + @spec filter(map(), term()) :: map() + def filter(%{msg: msg, meta: meta} = event, _opts) do + %{event | msg: redact_msg(msg), meta: redact_meta(meta)} + end + + def filter(event, _opts), do: event + + @doc "Masks credential-shaped substrings in a binary." + @spec redact(term()) :: term() + def redact(text) when is_binary(text) do + Enum.reduce(@patterns, text, fn {re, replacement}, acc -> + Regex.replace(re, acc, replacement) + end) + end + + def redact(other), do: other + + @doc "Truncates to the logging limit, saying how much was dropped rather than trailing off." + @spec truncate(binary(), pos_integer()) :: binary() + def truncate(text, max \\ @max_chars) when is_binary(text) do + if String.length(text) > max do + String.slice(text, 0, max) <> "… [#{String.length(text) - max} more characters]" + else + text + end + end + + @doc "The character limit applied to a logged message." + @spec max_chars() :: pos_integer() + def max_chars, do: @max_chars + + defp redact_msg({:string, text}) when is_binary(text), + do: {:string, text |> redact() |> truncate()} + + defp redact_msg({format, args}) when is_list(args), do: {format, Enum.map(args, &redact_term/1)} + defp redact_msg({:report, report}), do: {:report, redact_term(report)} + defp redact_msg(other), do: other + + defp redact_meta(meta) when is_map(meta), + do: Map.new(meta, fn {k, v} -> {k, redact_term(v)} end) + + defp redact_meta(meta), do: meta + + defp redact_term(v) when is_binary(v), do: v |> redact() |> truncate() + defp redact_term(v) when is_list(v), do: Enum.map(v, &redact_term/1) + defp redact_term(%{__struct__: _} = v), do: v + defp redact_term(v) when is_map(v), do: Map.new(v, fn {k, val} -> {k, redact_term(val)} end) + defp redact_term({a, b}), do: {redact_term(a), redact_term(b)} + defp redact_term(v), do: v +end diff --git a/lib/trinity/tools/runner.ex b/lib/trinity/tools/runner.ex index a0f1298..448120e 100644 --- a/lib/trinity/tools/runner.ex +++ b/lib/trinity/tools/runner.ex @@ -172,14 +172,34 @@ defmodule Trinity.Tools.Runner do what keeps it a caller for reads only. """ @spec call_tool(Registry.entry(), map(), Context.t()) :: {:ok, Result.t()} | {:error, term()} - def call_tool(%{effect: :none, module: module}, args, ctx) do + def call_tool(%{effect: :none, module: module, name: name} = entry, args, ctx) do + # Slice 090. The span carries the tool's name and tier and never its arguments: a telemetry + # handler is attached by anything in the VM and its output reaches dashboards and exporters, + # which is exactly how a filesystem path or a shell command ends up somewhere nobody meant + # (docs/telemetry.md). + Trinity.Telemetry.span( + [:tool, :call], + %{tool: name, risk: entry[:risk], session_id: ctx.session_id}, + fn -> + result = invoke(module, args, ctx) + + {result, + %{tool: name, risk: entry[:risk], session_id: ctx.session_id, result: outcome(result)}} + end + ) + end + + def call_tool(%{name: name}, _args, _ctx), + do: {:error, {:effectful_tool_outside_membrane, name}} + + defp invoke(module, args, ctx) do module.execute(args, ctx) rescue e -> {:error, {:crash, {e, __STACKTRACE__}}} end - def call_tool(%{name: name}, _args, _ctx), - do: {:error, {:effectful_tool_outside_membrane, name}} + defp outcome({:ok, _}), do: :ok + defp outcome(_), do: :error defp timeout_of(%{name: name}) do with {:ok, entry} <- Registry.lookup(name), diff --git a/test/trinity/telemetry/redaction_test.exs b/test/trinity/telemetry/redaction_test.exs new file mode 100644 index 0000000..20a7b08 --- /dev/null +++ b/test/trinity/telemetry/redaction_test.exs @@ -0,0 +1,98 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.Telemetry.RedactionTest do + @moduledoc """ + Slice 090, AC4: a credential in a log message is masked. + + The tests here also state what the filter does **not** catch, in the same file, because a + redaction filter that is trusted beyond its reach is worse than none: it turns "we mask secrets" + into a belief rather than a mechanism. The controls are elsewhere (keys in files, no token in + records, no content in telemetry); this is a last line and the tests say so. + """ + use ExUnit.Case, async: true + + alias Trinity.Telemetry.Redaction + + describe "what it masks" do + test "an authorization header, however it is spelled" do + for prefix <- ~w(Bearer bearer Token basic) do + line = "GET /v1/models #{prefix} abcdefghijklmnopqrstuvwxyz123456" + out = Redaction.redact(line) + assert out =~ "[REDACTED]" + refute out =~ "abcdefghijklmnopqrstuvwxyz123456" + end + end + + test "a provider key, by its shape rather than by its name" do + line = "calling openai with sk-proj-AbCdEfGhIjKlMnOpQrStUvWxYz012345" + out = Redaction.redact(line) + refute out =~ "AbCdEfGhIjKlMnOpQrStUvWxYz012345" + assert out =~ "[REDACTED]" + end + + test "a JSON web token" do + jwt = "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIxMjM0NTY3ODkwIn0.dBjftJeZ4CVPmB92K27uhbUJU1p1r_wW1g" + assert Redaction.redact("token=#{jwt}") =~ "[REDACTED" + refute Redaction.redact("token=#{jwt}") =~ "dBjftJeZ4CVPmB92K27uhbUJU1p1r_wW1g" + end + + test "a named secret in a key/value position" do + for line <- [ + "password: hunter2-and-then-some", + "api_key=sk_live_something_long_here", + "access-token = zzzzzzzzzzzzzzzzzzzz", + "PRIVATE_KEY:abcdefghijklmnop" + ] do + out = Redaction.redact(line) + assert out =~ "[REDACTED]", "not masked: #{line} -> #{out}" + end + end + + test "it masks inside a Logger event's message and metadata, and never drops the event" do + event = %{ + msg: {:string, "connecting with Bearer abcdefghijklmnopqrstuvwxyz"}, + meta: %{header: "Authorization: Bearer abcdefghijklmnopqrstuvwxyz", session_id: "s-1"} + } + + out = Redaction.filter(event, nil) + + assert {:string, masked} = out.msg + assert masked =~ "[REDACTED]" + refute masked =~ "abcdefghijklmnopqrstuvwxyz" + refute out.meta.header =~ "abcdefghijklmnopqrstuvwxyz" + + # The event survives: a filter that drops a line to avoid printing a secret also drops the + # evidence that something happened. + assert out.meta.session_id == "s-1" + end + end + + describe "truncation" do + test "a long message is cut and says how much was dropped" do + long = String.duplicate("x", Redaction.max_chars() + 500) + out = Redaction.truncate(long) + + assert String.length(out) < String.length(long) + assert out =~ "500 more characters" + end + + test "a short message is untouched" do + assert Redaction.truncate("short") == "short" + end + end + + describe "what it does not catch, stated rather than left to be discovered" do + test "a credential with no recognisable shape passes through" do + # This is the filter's honest limit. It matches shapes, and a secret that looks like an + # ordinary word is an ordinary word to it. + line = "the passphrase is correct horse battery staple" + assert Redaction.redact(line) == line + end + + test "content that merely looks like a credential is masked, and that is the right trade" do + # Over-masking costs a reader context; under-masking puts a key on disk. + line = "the user wrote: my password: is a secret I keep" + assert Redaction.redact(line) =~ "[REDACTED]" + end + end +end diff --git a/test/trinity/telemetry/telemetry_test.exs b/test/trinity/telemetry/telemetry_test.exs new file mode 100644 index 0000000..936e54e --- /dev/null +++ b/test/trinity/telemetry/telemetry_test.exs @@ -0,0 +1,154 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.TelemetryTest do + @moduledoc """ + Slice 090, AC1 and AC4: the documented events are emitted with the documented metadata, the + catalogue and the code agree, and no event carries content. + + The last of those is the one worth writing carefully. A telemetry handler can be attached by + anything in the VM, and its output reaches dashboards, logs and exporters; an event that carried + a prompt or a tool's arguments would be a conversation leaving by a side door. So the tests here + do not only assert that events fire, they assert what is **absent** from them. + """ + use Trinity.SessionCase + + alias Trinity.Telemetry + + setup do + ref = make_ref() + handler = "test-#{System.unique_integer([:positive])}" + me = self() + + :telemetry.attach_many( + handler, + Telemetry.catalogue(), + fn name, measurements, metadata, _ -> + send(me, {ref, name, measurements, metadata}) + end, + nil + ) + + on_exit(fn -> :telemetry.detach(handler) end) + {:ok, ref: ref} + end + + describe "AC1: the documented events fire with the documented metadata" do + test "a tool call emits a start and a stop naming the tool and its result", %{ref: ref} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + ctx = %Trinity.Tools.Context{session_id: session.id} + {:ok, entry} = Trinity.Tools.Registry.lookup("echo") + + Trinity.Tools.Runner.call_tool(entry, %{"text" => "hello"}, ctx) + + assert_receive {^ref, [:trinity, :tool, :call, :start], %{system_time: _}, start_meta} + assert start_meta.tool == "echo" + assert start_meta.session_id == session.id + + assert_receive {^ref, [:trinity, :tool, :call, :stop], %{duration: d}, stop_meta} + assert is_integer(d) + assert stop_meta.tool == "echo" + assert stop_meta.result == :ok + end + + test "a tool call's events carry the tool's name and never its arguments", %{ref: ref} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + ctx = %Trinity.Tools.Context{session_id: session.id} + {:ok, entry} = Trinity.Tools.Registry.lookup("echo") + secret = "a-value-that-must-not-appear-in-telemetry" + + Trinity.Tools.Runner.call_tool(entry, %{"text" => secret}, ctx) + + assert_receive {^ref, [:trinity, :tool, :call, :start], _, start_meta} + assert_receive {^ref, [:trinity, :tool, :call, :stop], _, stop_meta} + + refute inspect(start_meta) =~ secret + refute inspect(stop_meta) =~ secret + end + + test "a session transition names where it went", %{ref: ref} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + {:ok, _pid} = Sessions.ensure_started(session.id) + + assert_receive {^ref, [:trinity, :session, :transition], %{count: 1}, meta} + assert meta.session_id == session.id + assert meta.to == :idle + end + + test "the approval and budget emitters carry what the catalogue says" do + ref = make_ref() + me = self() + handler = "t2-#{System.unique_integer([:positive])}" + + :telemetry.attach_many( + handler, + Telemetry.catalogue(), + fn n, m, md, _ -> send(me, {ref, n, m, md}) end, + nil + ) + + on_exit(fn -> :telemetry.detach(handler) end) + + Telemetry.approval_requested("write_note", :write, "sess-1") + + assert_receive {^ref, [:trinity, :approval, :requested], %{count: 1}, + %{tool: "write_note", risk: :write}} + + Telemetry.approval_decided("write_note", :write, "sess-1", + decision: :once, + basis: :user, + waited_ms: 42 + ) + + assert_receive {^ref, [:trinity, :approval, :decided], %{waited_ms: 42}, + %{decision: :once, basis: :user}} + + Telemetry.budget_exceeded(:day, "2026-09-24", 12.5, 10.0) + + assert_receive {^ref, [:trinity, :budget, :exceeded], %{spent_usd: 12.5, limit_usd: 10.0}, + %{scope: :day}} + end + + test "a gateway outcome outside the closed set is a function clause, not a new label" do + # The atom is built at runtime so the type checker cannot prove the call fails and warn + # about it: the point of the test is the guard's behaviour, not the compiler's opinion. + outcome = String.to_atom("not" <> "_an_outcome") + assert_raise FunctionClauseError, fn -> Telemetry.gateway_inbound("console", outcome) end + end + end + + describe "the catalogue and the code agree" do + test "every event the catalogue lists appears in docs/telemetry.md" do + doc = File.read!("docs/telemetry.md") + + for name <- Telemetry.catalogue() do + rendered = "[" <> Enum.map_join(name, ", ", &":#{&1}") <> "]" + + assert String.contains?(doc, rendered), + "#{rendered} is emitted but not documented in docs/telemetry.md" + end + end + + test "every trinity event in the document is one the code can emit" do + documented = + "docs/telemetry.md" + |> File.read!() + |> then(&Regex.scan(~r/\[:trinity(?:, :[a-z_]+)+\]/, &1)) + |> Enum.map(&hd/1) + |> Enum.uniq() + + known = + Enum.map(Telemetry.catalogue(), fn n -> + "[" <> Enum.map_join(n, ", ", &":#{&1}") <> "]" + end) + + assert documented -- known == [], + "documented but not emittable: #{inspect(documented -- known)}" + end + end +end From 19b2ac44543aad7faafb0207271b6a2f348cc5b3 Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 07:30:31 -0400 Subject: [PATCH 02/11] feat(s090): the cost ledger, and AC2's totals moved from manual to automatic Trinity.Telemetry.Costs answers what the model calls have cost, by day, session, persona and model, and whether a configured budget has been passed. It is a read, not a pipeline, and not a telemetry handler. Slice 011 already writes a usage_events row per completed call with the price applied. A handler that failed or was detached would silently stop the ledger, and a missing bill is worse than a missing chart. The compiler refused the obvious implementation and was right. Trinity.LLM is a sub-boundary that depends on Trinity, so a module in Trinity naming Trinity.LLM.Usage is a cycle. The queries are schemaless against the usage_events table instead, which is the more honest description anyway: this reads a ledger rather than using the LLM's API, and every query is an aggregate that needs no struct. The cost is that column names become an unchecked contract, so a test reads the table's columns and fails if one disappears. Two behaviours are deliberate and tested rather than incidental. An empty ledger returns 0.0 and not nil, because a nil reaching a template renders as nothing and reads as "no data" when it means "no spend". And an unconfigured budget is not a budget of zero: the alternative silently blocks every call on a fresh install. Blocking is separate from warning and off by default. A budget that silently stops an agent mid-task is a failure a person cannot diagnose from the outside; the warning is what makes the number visible before it becomes a wall. AC2 was manual in whole. Its totals half is now automatic, asserted against seeded rows, because a total is arithmetic and arithmetic is the last thing that should be checked by eye. The manual queue keeps the half that needs a person: the blocking behaviour and its message on screen. The retag is recorded in NOTES rather than done quietly, and it is toward more proof rather than less. 10 tests. mix gate exit 0; 665 passed; coverage 80.31%. Signed-off-by: Ayla Croft --- lib/trinity/telemetry/costs.ex | 187 ++++++++++++++++++++++++++ test/trinity/telemetry/costs_test.exs | 182 +++++++++++++++++++++++++ 2 files changed, 369 insertions(+) create mode 100644 lib/trinity/telemetry/costs.ex create mode 100644 test/trinity/telemetry/costs_test.exs diff --git a/lib/trinity/telemetry/costs.ex b/lib/trinity/telemetry/costs.ex new file mode 100644 index 0000000..c02d84e --- /dev/null +++ b/lib/trinity/telemetry/costs.ex @@ -0,0 +1,187 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.Telemetry.Costs do + @moduledoc """ + What the model calls have cost, and whether a budget has been passed (slice 090). + + **This is a read, not a pipeline.** Slice 011 already writes a `usage_events` row per completed + call with the cost computed from the model registry's price. Nothing here recomputes that, and + nothing here is a telemetry handler: a handler that failed or was detached would silently stop + the ledger, and a missing bill is worse than a missing chart. The events in + `docs/telemetry.md` describe the same calls, and the dashboards read them, but the money is read + from the rows. + + ## Budgets + + Configured rather than stored, because there is no settings table and inventing one for three + numbers would be the larger change: + + config :trinity, :budgets, day: 5.0, session: 1.0, persona: 20.0 + + A budget that is not configured is not enforced. `check/2` answers `:ok` or + `{:over, spent, limit}` and emits `[:trinity, :budget, :exceeded]` when it is over, so the + warning reaches a dashboard whether or not anything is blocking on it. + + **Blocking is separate from warning, and off by default.** `config :trinity, :budgets, + block_when_over: true` makes the session refuse a new turn. It is off because a budget that + silently stops an agent mid-task is a failure a person cannot diagnose from the outside, and the + warning is what makes the number visible before it becomes a wall. + """ + + import Ecto.Query + + alias Trinity.Repo + + # The table, not the schema. `Trinity.LLM` is a sub-boundary that depends on `Trinity`, so a + # module in `Trinity` naming `Trinity.LLM.Usage` would be a cycle and the compiler refuses it. + # That refusal is right rather than inconvenient: this module reads a ledger, it does not use the + # LLM's API, and every query here is an aggregate that needs no struct. The column names are the + # contract, and the test asserts they still exist. + @table "usage_events" + + @scopes [:day, :session, :persona] + + @doc "The scopes a budget can be set for." + @spec scopes() :: [atom()] + def scopes, do: @scopes + + @doc "Total cost in US dollars across every recorded call, optionally since a time." + @spec total(keyword()) :: float() + def total(opts \\ []) do + @table + |> since(opts[:since]) + |> select([u], sum(u.cost_usd)) + |> Repo.one() + |> zero_if_nil() + end + + @doc "Total cost for one session." + @spec for_session(String.t()) :: float() + def for_session(session_id) do + @table + |> where([u], u.session_id == ^session_id) + |> select([u], sum(u.cost_usd)) + |> Repo.one() + |> zero_if_nil() + end + + @doc """ + Total cost for one persona, summed across its sessions. + + `usage_events` carries the session, not the persona, so this joins. Storing the persona on the + usage row would make this a simpler query and a wrong one: a session's persona can change, and + the cost belongs to the session that incurred it. + """ + @spec for_persona(String.t()) :: float() + def for_persona(persona_id) do + from(u in @table, + join: s in "sessions", + on: s.id == u.session_id, + where: s.persona_id == ^persona_id, + select: sum(u.cost_usd) + ) + |> Repo.one() + |> zero_if_nil() + end + + @doc "Total cost today, in UTC." + @spec for_today() :: float() + def for_today, do: total(since: DateTime.utc_now() |> DateTime.to_date() |> start_of_day()) + + @doc "Totals by day, newest first, as `{date, cost}`." + @spec by_day(pos_integer()) :: [{Date.t(), float()}] + def by_day(days \\ 30) do + since = Date.utc_today() |> Date.add(-days) |> start_of_day() + + @table + |> where([u], u.inserted_at >= ^since) + |> group_by([u], fragment("date(?)", u.inserted_at)) + |> select([u], {fragment("date(?)", u.inserted_at), sum(u.cost_usd)}) + |> Repo.all() + |> Enum.map(fn {d, c} -> {to_date(d), zero_if_nil(c)} end) + |> Enum.sort({:desc, Date}) + end + + @doc "Totals by model, largest first, as `{model_id, cost, calls}`." + @spec by_model(keyword()) :: [{String.t(), float(), non_neg_integer()}] + def by_model(opts \\ []) do + @table + |> since(opts[:since]) + |> group_by([u], u.model_id) + |> select([u], {u.model_id, sum(u.cost_usd), count(u.id)}) + |> Repo.all() + |> Enum.map(fn {m, c, n} -> {m, zero_if_nil(c), n} end) + |> Enum.sort_by(&elem(&1, 1), :desc) + end + + @doc "The configured budget for a scope, or `nil` when none is set." + @spec budget(atom()) :: float() | nil + def budget(scope) when scope in @scopes do + case Application.get_env(:trinity, :budgets, [])[scope] do + n when is_number(n) -> n / 1 + _ -> nil + end + end + + @doc "Whether a new turn should be refused when a budget is passed. Off unless configured." + @spec blocking?() :: boolean() + def blocking?, do: Application.get_env(:trinity, :budgets, [])[:block_when_over] == true + + @doc """ + Whether a scope is over its budget, emitting the warning event when it is. + + `:ok` when no budget is set for the scope, because an unconfigured budget is not a budget of + zero. That distinction matters: the alternative silently blocks every call on a fresh install. + """ + @spec check(atom(), String.t() | nil) :: :ok | {:over, float(), float()} + def check(scope, scope_id \\ nil) + + def check(scope, scope_id) when scope in @scopes do + case budget(scope) do + nil -> + :ok + + limit -> + spent = spent(scope, scope_id) + + if spent > limit do + Trinity.Telemetry.budget_exceeded(scope, scope_id, spent, limit) + {:over, spent, limit} + else + :ok + end + end + end + + def check(_scope, _scope_id), do: :ok + + @doc "Every configured scope that is over, for a caller that wants the whole picture at once." + @spec over(String.t() | nil, String.t() | nil) :: [{atom(), float(), float()}] + def over(session_id \\ nil, persona_id \\ nil) do + [{:day, nil}, {:session, session_id}, {:persona, persona_id}] + |> Enum.filter(fn {scope, id} -> scope == :day or id != nil end) + |> Enum.flat_map(fn {scope, id} -> + case check(scope, id) do + {:over, spent, limit} -> [{scope, spent, limit}] + :ok -> [] + end + end) + end + + defp spent(:day, _), do: for_today() + defp spent(:session, id) when is_binary(id), do: for_session(id) + defp spent(:persona, id) when is_binary(id), do: for_persona(id) + defp spent(_, _), do: 0.0 + + defp since(query, nil), do: query + defp since(query, %DateTime{} = at), do: where(query, [u], u.inserted_at >= ^at) + + defp start_of_day(%Date{} = d), do: DateTime.new!(d, ~T[00:00:00], "Etc/UTC") + + defp to_date(%Date{} = d), do: d + defp to_date(s) when is_binary(s), do: Date.from_iso8601!(s) + + defp zero_if_nil(nil), do: 0.0 + defp zero_if_nil(%Decimal{} = d), do: Decimal.to_float(d) + defp zero_if_nil(n) when is_number(n), do: n / 1 +end diff --git a/test/trinity/telemetry/costs_test.exs b/test/trinity/telemetry/costs_test.exs new file mode 100644 index 0000000..5e3e807 --- /dev/null +++ b/test/trinity/telemetry/costs_test.exs @@ -0,0 +1,182 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.Telemetry.CostsTest do + @moduledoc """ + Slice 090, AC2 (the totals half, retagged `[auto]`): the ledger's totals equal the sum of the + rows, and a budget that is passed emits its warning. + + The SLICE made this criterion manual, to be checked by eye against a seeded dataset. A total is + arithmetic, and arithmetic is the last thing that should be checked by looking at it, so the + totals are asserted here and the manual queue keeps only the part that needs a person: the + blocking behaviour and its message on screen. + """ + use Trinity.DataCase, async: false + + alias Trinity.Repo + alias Trinity.Sessions + alias Trinity.Telemetry.Costs + + defp seed!(session_id, cost, opts \\ []) do + Repo.insert_all("usage_events", [ + %{ + id: Trinity.UUID.generate(), + model_id: Keyword.get(opts, :model, "fake:chat"), + provider: "fake", + kind: "stream", + input_tokens: 10, + output_tokens: 20, + cached_tokens: 0, + reasoning_tokens: 0, + cost_usd: cost, + session_id: session_id, + # Encoded here rather than passed as a map: a schemaless insert has no schema to tell the + # adapter this column is JSON, and SQLite refuses a bare map. + provider_meta: JSON.encode!(%{}), + inserted_at: Keyword.get(opts, :at, DateTime.utc_now() |> DateTime.truncate(:second)) + } + ]) + end + + defp session!(opts \\ []) do + {:ok, s} = + Sessions.create_session( + Enum.into(opts, %{persona_id: Sessions.default_persona().id, title: "t"}) + ) + + s + end + + setup do + prior = Application.get_env(:trinity, :budgets) + + on_exit(fn -> + if prior, + do: Application.put_env(:trinity, :budgets, prior), + else: Application.delete_env(:trinity, :budgets) + end) + + :ok + end + + describe "totals equal the sum of the rows" do + test "across everything, and per session" do + a = session!() + b = session!() + + seed!(a.id, 1.50) + seed!(a.id, 0.25) + seed!(b.id, 2.00) + + assert_in_delta Costs.total(), 3.75, 0.0001 + assert_in_delta Costs.for_session(a.id), 1.75, 0.0001 + assert_in_delta Costs.for_session(b.id), 2.00, 0.0001 + end + + test "per persona, summed across that persona's sessions" do + {:ok, persona} = Trinity.Personas.create(%{name: "auditor", soul: "careful"}) + mine = session!(persona_id: persona.id) + theirs = session!() + + seed!(mine.id, 3.00) + seed!(theirs.id, 9.99) + + assert_in_delta Costs.for_persona(persona.id), 3.00, 0.0001 + end + + test "by model, largest first, with the call count" do + s = session!() + seed!(s.id, 0.10, model: "cheap") + seed!(s.id, 0.10, model: "cheap") + seed!(s.id, 5.00, model: "dear") + + assert [{"dear", dear, 1}, {"cheap", cheap, 2}] = Costs.by_model() + assert_in_delta dear, 5.00, 0.0001 + assert_in_delta cheap, 0.20, 0.0001 + end + + test "an empty ledger is zero, not nil" do + # sum() over no rows is NULL, and a nil reaching a template renders as nothing rather than + # as a number, which reads as "no data" when it means "no spend". + assert Costs.total() == 0.0 + assert Costs.for_session(session!().id) == 0.0 + assert Costs.by_day() == [] + end + end + + describe "budgets" do + test "an unconfigured budget is not a budget of zero" do + Application.delete_env(:trinity, :budgets) + s = session!() + seed!(s.id, 1_000.0) + + # The alternative silently blocks every call on a fresh install. + assert Costs.budget(:day) == nil + assert Costs.check(:day) == :ok + assert Costs.check(:session, s.id) == :ok + end + + test "passing a budget answers with what was spent and what the limit was" do + Application.put_env(:trinity, :budgets, session: 1.0) + s = session!() + seed!(s.id, 2.50) + + assert {:over, spent, limit} = Costs.check(:session, s.id) + assert_in_delta spent, 2.50, 0.0001 + assert limit == 1.0 + end + + test "passing a budget emits the warning event, whether or not anything blocks on it" do + Application.put_env(:trinity, :budgets, day: 0.5) + s = session!() + seed!(s.id, 0.75) + + ref = make_ref() + me = self() + handler = "budget-#{System.unique_integer([:positive])}" + + :telemetry.attach( + handler, + [:trinity, :budget, :exceeded], + fn _, m, md, _ -> + send(me, {ref, m, md}) + end, + nil + ) + + on_exit(fn -> :telemetry.detach(handler) end) + + assert {:over, _, _} = Costs.check(:day) + assert_receive {^ref, %{spent_usd: _, limit_usd: 0.5}, %{scope: :day}} + end + + test "blocking is off unless configured, and separate from warning" do + Application.put_env(:trinity, :budgets, day: 0.01) + refute Costs.blocking?() + + Application.put_env(:trinity, :budgets, day: 0.01, block_when_over: true) + assert Costs.blocking?() + end + + test "over/2 reports every configured scope that is past its limit" do + {:ok, persona} = Trinity.Personas.create(%{name: "spender", soul: "eager"}) + s = session!(persona_id: persona.id) + seed!(s.id, 4.00) + + Application.put_env(:trinity, :budgets, day: 1.0, session: 10.0, persona: 2.0) + + scopes = Costs.over(s.id, persona.id) |> Enum.map(&elem(&1, 0)) |> Enum.sort() + assert scopes == [:day, :persona] + end + end + + test "the columns this module reads still exist" do + # The queries are schemaless, so the column names are the contract with slice 011's schema and + # nothing else checks them. A rename there should fail here rather than in a dashboard. + {:ok, %{columns: columns}} = + Repo.query("SELECT * FROM usage_events LIMIT 0") + + for column <- ~w(cost_usd session_id model_id inserted_at id) do + assert column in columns, "usage_events lost the #{column} column this ledger reads" + end + end +end From b425e08c8d7e09f6e00ab159fef8beb7bcad4d2c Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 08:04:23 -0400 Subject: [PATCH 03/11] feat(s090): the Activity page, its bounded buffer, and a LiveDashboard sessions page Trinity.Telemetry.Activity keeps the last 200 events and drops the oldest. Bounded because an unbounded event buffer is a memory leak with a nice name, and in memory only because what must survive a restart is a receipt or a usage row, both written to disk by the code that caused them rather than by a listener. Its handler does one send and nothing else. A telemetry handler runs in the process that emitted the event, so work done there is charged to whatever turn happened to emit it. The handler is attached in init and detached in terminate so its lifetime is the buffer's: a handler that outlives its target sends to a dead pid on every event for the rest of the run. The Activity page shows those events beside the cost totals, because what happened and what it cost are the same question asked twice and splitting them across two pages makes a person do the joining. It reads and never writes. The test that matters there is a negative one. Events carry no prompt text, no completion text and no tool arguments, so a test asserting rows appear would pass equally well on a page that had quietly started showing conversations. A secret is passed as a tool argument and the page is asserted not to contain it. The LiveDashboard page answers what LiveDashboard cannot: which processes are Trinity sessions and what state each machine is in, which is the question someone asks when a turn looks stuck. It asks the process rather than reading the row, because a row reads active long after its process has gone: slice 080 found that in a panel that promised which are running and delivered which are not archived. 6 more tests. mix gate exit 0; 671 passed; coverage 80.31%. Signed-off-by: Ayla Croft --- lib/trinity.ex | 2 + lib/trinity/application.ex | 3 + lib/trinity/telemetry/activity.ex | 112 ++++++++++++ lib/trinity_web/dashboard/sessions_page.ex | 92 ++++++++++ lib/trinity_web/live/activity_live.ex | 176 +++++++++++++++++++ lib/trinity_web/router.ex | 8 +- test/trinity_web/live/activity_live_test.exs | 98 +++++++++++ 7 files changed, 490 insertions(+), 1 deletion(-) create mode 100644 lib/trinity/telemetry/activity.ex create mode 100644 lib/trinity_web/dashboard/sessions_page.ex create mode 100644 lib/trinity_web/live/activity_live.ex create mode 100644 test/trinity_web/live/activity_live_test.exs diff --git a/lib/trinity.ex b/lib/trinity.ex index 0577d34..ed06877 100644 --- a/lib/trinity.ex +++ b/lib/trinity.ex @@ -30,6 +30,8 @@ defmodule Trinity do # redaction filter is exported because the application installs it as a primary Logger # filter at boot. Telemetry, + Telemetry.Activity, + Telemetry.Costs, Telemetry.Redaction, Repo, Repo.Receipts, diff --git a/lib/trinity/application.ex b/lib/trinity/application.ex index df2a287..0ea1617 100644 --- a/lib/trinity/application.ex +++ b/lib/trinity/application.ex @@ -33,6 +33,9 @@ defmodule Trinity.Application do desktop_children() ++ [ TrinityWeb.Telemetry, + # Slice 090: the Activity page's bounded buffer. Early, so it is listening before + # anything it would want to have recorded has happened. + Trinity.Telemetry.Activity, # Slice 010: one node per data directory. Before the Repo, so a refused boot has # opened no database file; the reason names the holder's OS pid and mode. {Trinity.DataDir.Lock, dir: lock_dir(), mode: mode()}, diff --git a/lib/trinity/telemetry/activity.ex b/lib/trinity/telemetry/activity.ex new file mode 100644 index 0000000..a1c7069 --- /dev/null +++ b/lib/trinity/telemetry/activity.ex @@ -0,0 +1,112 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule Trinity.Telemetry.Activity do + @moduledoc """ + A bounded, in-memory record of recent events, for the Activity page (slice 090). + + **Bounded, because an unbounded event buffer is a memory leak with a nice name.** It keeps the + last `limit/0` events and drops the oldest; nothing here is durable and nothing here is meant to + be. What must survive a restart is a receipt (slice 024) or a usage row (slice 011), and both are + written to disk by the code that caused them rather than by a listener. + + **It holds what the catalogue allows and nothing else.** The events themselves carry no prompt + text, no completion text and no tool arguments (`docs/telemetry.md`), so neither does this. That + is worth stating because an activity feed is exactly the feature that tempts someone to enrich a + record with "just the first line of the message", and the place to refuse that is here, where the + refusal is visible, rather than in review. + + It is a `GenServer` rather than an ETS table so that the handler's work is bounded by a mailbox + it cannot outrun: a telemetry handler runs **in the process that emitted the event**, and doing + real work there would put this module's cost on the turn's latency. + """ + + use GenServer + + alias Trinity.Telemetry + + @handler "trinity-activity" + @limit 200 + + @type entry :: %{ + at: DateTime.t(), + event: [atom()], + measurements: map(), + metadata: map() + } + + @doc "How many events are kept." + @spec limit() :: pos_integer() + def limit, do: @limit + + def start_link(opts), do: GenServer.start_link(__MODULE__, opts, name: __MODULE__) + + @doc """ + The recent events, newest first. + + Options: `:session_id` and `:event` (a prefix, so `[:trinity, :tool]` matches both the start and + the stop). + """ + @spec recent(keyword()) :: [entry()] + def recent(opts \\ []) do + GenServer.call(__MODULE__, :recent) + |> filter_session(opts[:session_id]) + |> filter_event(opts[:event]) + catch + :exit, _ -> [] + end + + @doc "Empties the buffer. For tests, and for a person who wants the page to start again." + @spec clear() :: :ok + def clear do + GenServer.call(__MODULE__, :clear) + catch + :exit, _ -> :ok + end + + @impl true + def init(_opts) do + # Attached here rather than in the application so the handler's lifetime is this process's: a + # handler that outlives its target sends to a dead pid on every event for the rest of the run. + :telemetry.attach_many(@handler, Telemetry.catalogue(), &__MODULE__.handle/4, nil) + {:ok, %{entries: []}} + end + + @impl true + def terminate(_reason, _state) do + :telemetry.detach(@handler) + :ok + end + + @doc false + # Runs in the emitting process. It does one `send` and nothing else, on purpose: a handler that + # did real work here would charge it to whatever turn happened to emit the event. + def handle(event, measurements, metadata, _config) do + send(__MODULE__, {:event, event, measurements, metadata, DateTime.utc_now()}) + :ok + rescue + # A send to a name that is not registered raises; an unstarted buffer must not break a turn. + _ -> :ok + end + + @impl true + def handle_info({:event, event, measurements, metadata, at}, state) do + entry = %{at: at, event: event, measurements: measurements, metadata: metadata} + {:noreply, %{state | entries: Enum.take([entry | state.entries], @limit)}} + end + + def handle_info(_other, state), do: {:noreply, state} + + @impl true + def handle_call(:recent, _from, state), do: {:reply, state.entries, state} + def handle_call(:clear, _from, state), do: {:reply, :ok, %{state | entries: []}} + + defp filter_session(entries, nil), do: entries + + defp filter_session(entries, session_id), + do: Enum.filter(entries, &(&1.metadata[:session_id] == session_id)) + + defp filter_event(entries, nil), do: entries + + defp filter_event(entries, prefix) when is_list(prefix), + do: Enum.filter(entries, &List.starts_with?(&1.event, prefix)) +end diff --git a/lib/trinity_web/dashboard/sessions_page.ex b/lib/trinity_web/dashboard/sessions_page.ex new file mode 100644 index 0000000..7ab7d5d --- /dev/null +++ b/lib/trinity_web/dashboard/sessions_page.ex @@ -0,0 +1,92 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule TrinityWeb.Dashboard.SessionsPage do + @moduledoc """ + A LiveDashboard page listing the session processes that are alive, with their `gen_statem` state + (slice 090, AC3). + + LiveDashboard already lists every process in the VM. What it cannot say is which of them is a + Trinity session and what state that session's machine is in, which is the question someone asks + when a turn appears stuck: waiting on a model, waiting on an approval, or idle and the page did + not notice. + + It reads the registry and asks each process, so it shows the running system rather than the + database's opinion of it. A session row reads `active` long after its process has gone; slice 080 + found that the hard way, in a panel that promised "which are running" and delivered "which are + not archived". + """ + + use Phoenix.LiveDashboard.PageBuilder + + alias Trinity.Sessions + + @impl true + def menu_link(_, _), do: {:ok, "Trinity sessions"} + + @impl true + def render(assigns) do + ~H""" + <.live_table + id="trinity-sessions" + dom_id="trinity-sessions" + page={@page} + title="Trinity sessions" + row_fetcher={&fetch_rows/2} + rows_name="sessions" + > + <:col field={:id} header="Session" /> + <:col field={:state} header="State" /> + <:col field={:title} header="Title" /> + <:col field={:origin} header="Origin" /> + <:col field={:pid} header="Process" /> + <:col field={:memory} header="Memory (KB)" sortable={:desc} /> + + """ + end + + @doc false + def fetch_rows(params, _node) do + rows = rows() + {sort_rows(rows, params), length(rows)} + end + + defp rows do + for session <- Sessions.list_sessions(limit: 200), + pid = Sessions.whereis(session.id), + is_pid(pid) do + %{ + id: short(session.id), + state: state_of(session.id), + title: session.title || "(untitled)", + origin: session.origin, + pid: inspect(pid), + memory: memory_kb(pid) + } + end + end + + # Asked of the process, never read from the row: a row's status is the session's lifecycle and + # says nothing about whether its machine is doing anything. + defp state_of(session_id) do + case Sessions.state(session_id) do + %{state: state} -> to_string(state) + _ -> "-" + end + catch + :exit, _ -> "-" + end + + defp memory_kb(pid) do + case Process.info(pid, :memory) do + {:memory, bytes} -> div(bytes, 1024) + _ -> 0 + end + end + + defp short(id), do: String.slice(id, -8, 8) + + defp sort_rows(rows, %{sort_by: by, sort_dir: dir}) when is_atom(by), + do: Enum.sort_by(rows, &Map.get(&1, by), dir) + + defp sort_rows(rows, _params), do: rows +end diff --git a/lib/trinity_web/live/activity_live.ex b/lib/trinity_web/live/activity_live.ex new file mode 100644 index 0000000..76b914c --- /dev/null +++ b/lib/trinity_web/live/activity_live.ex @@ -0,0 +1,176 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule TrinityWeb.ActivityLive do + @moduledoc """ + `/activity` (slice 090): what Trinity has been doing, as events, with what it has cost. + + The page reads and never writes, like every page in this tree. It shows the bounded buffer + (`Trinity.Telemetry.Activity`), filterable by session and by kind of event, and the cost totals + beside it, because "what happened" and "what it cost" are the same question asked twice and + splitting them across two pages makes a person do the joining. + + **It shows what the events carry, which is deliberately not much.** No prompt text, no completion + text, no tool arguments (`docs/telemetry.md`). An activity feed is exactly the feature that + tempts someone to enrich a row with "just the first line of the message"; the refusal lives in + the catalogue and this page inherits it. + """ + use TrinityWeb, :live_view + + alias Trinity.Telemetry.{Activity, Costs} + + @refresh_ms 2_000 + + @impl true + def mount(_params, _session, socket) do + if connected?(socket), do: :timer.send_interval(@refresh_ms, :refresh) + + {:ok, + socket + |> assign(page_title: gettext("Activity"), filter: nil, session_filter: "") + |> load()} + end + + @impl true + def handle_info(:refresh, socket), do: {:noreply, load(socket)} + + @impl true + def handle_event("filter", %{"kind" => kind}, socket) do + {:noreply, socket |> assign(filter: prefix(kind)) |> load()} + end + + def handle_event("session", %{"session_id" => id}, socket) do + {:noreply, socket |> assign(session_filter: String.trim(id)) |> load()} + end + + def handle_event("clear", _params, socket) do + Activity.clear() + {:noreply, load(socket)} + end + + defp prefix(""), do: nil + defp prefix("all"), do: nil + defp prefix(kind), do: [:trinity, String.to_existing_atom(kind)] + + defp load(socket) do + session_id = + if socket.assigns.session_filter == "", do: nil, else: socket.assigns.session_filter + + assign(socket, + entries: Activity.recent(event: socket.assigns.filter, session_id: session_id), + today: Costs.for_today(), + total: Costs.total(), + by_model: Costs.by_model() |> Enum.take(5), + over: Costs.over(session_id, nil) + ) + end + + @impl true + def render(assigns) do + ~H""" + + <:bar> + {gettext("Activity")} + + {gettext("today")} ${:erlang.float_to_binary(@today, decimals: 4)} + + + {gettext("all time")} ${:erlang.float_to_binary(@total, decimals: 4)} + + + +
+
+ {gettext("Over the")} {scope} {gettext("budget")}: + + ${:erlang.float_to_binary(spent, decimals: 4)} / ${:erlang.float_to_binary(limit, + decimals: 2 + )} + +
+ +
+

+ {gettext("Cost by model")} +

+
    +
  • + {model} + {calls} {gettext("calls")} + ${:erlang.float_to_binary(cost, decimals: 4)} +
    • +
+
+ +
+
+ +
+
+ +
+ + +
+ +
+

+ {gettext("Nothing yet. Events appear here as Trinity works.")} +

+
    +
  • + + {Calendar.strftime(e.at, "%H:%M:%S")} + + {name(e.event)} + {summarise(e)} + {duration(e.measurements)} +
    • +
+
+ +

+ {gettext("The last")} {Activity.limit()} {gettext( + "events, in memory only. Receipts and usage are on disk; this is not." + )} +

+
+ + """ + end + + defp name([:trinity | rest]), do: Enum.join(rest, ".") + defp name(other), do: inspect(other) + + # What a row says. Identifiers and outcomes, never content: the events do not carry content and + # this page does not invent any. + defp summarise(%{metadata: m}) do + [m[:tool], m[:model], m[:adapter], m[:decision], m[:outcome], m[:result], m[:to], m[:scope]] + |> Enum.reject(&is_nil/1) + |> Enum.map_join(" · ", &to_string/1) + end + + defp duration(%{duration: d}) when is_integer(d) do + ms = System.convert_time_unit(d, :native, :millisecond) + "#{ms} ms" + end + + defp duration(%{cost_usd: c}) when is_number(c) and c > 0, + do: "$" <> :erlang.float_to_binary(c / 1, decimals: 4) + + defp duration(_), do: "" +end diff --git a/lib/trinity_web/router.ex b/lib/trinity_web/router.ex index e55bc1f..534a4c5 100644 --- a/lib/trinity_web/router.ex +++ b/lib/trinity_web/router.ex @@ -46,6 +46,8 @@ defmodule TrinityWeb.Router do live "/permissions", PermissionsLive, :index # Slice 031: full-text search over every message. live "/search", SearchLive, :index + # Slice 090: what Trinity has been doing, and what it has cost. + live "/activity", ActivityLive, :index # Slice 034: settings, with the export as a download. live "/settings", SettingsLive, :index get "/settings/export.tar.gz", ExportController, :download @@ -102,7 +104,11 @@ defmodule TrinityWeb.Router do scope "/dev" do pipe_through :browser - live_dashboard "/dashboard", metrics: TrinityWeb.Telemetry, csp_nonce_assign_key: :csp_nonce + live_dashboard "/dashboard", + metrics: TrinityWeb.Telemetry, + csp_nonce_assign_key: :csp_nonce, + # Slice 090: which session processes are alive and what state each machine is in. + additional_pages: [trinity_sessions: TrinityWeb.Dashboard.SessionsPage] end end end diff --git a/test/trinity_web/live/activity_live_test.exs b/test/trinity_web/live/activity_live_test.exs new file mode 100644 index 0000000..39bd2a9 --- /dev/null +++ b/test/trinity_web/live/activity_live_test.exs @@ -0,0 +1,98 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule TrinityWeb.ActivityLiveTest do + @moduledoc """ + Slice 090, AC6: the Activity page. + + The assertion that matters most here is a negative one. The page shows events, and events carry + no content by rule (`docs/telemetry.md`); a test that only checked rows appeared would pass + equally well on a page that had quietly started showing prompts. + """ + use TrinityWeb.ConnCase, async: false + + import Phoenix.LiveViewTest + + alias Trinity.Sessions + alias Trinity.Telemetry + alias Trinity.Telemetry.Activity + + setup do + Activity.clear() + on_exit(&Activity.clear/0) + :ok + end + + defp settle, do: Activity.recent() + + test "an empty buffer says so rather than showing an empty box", %{conn: conn} do + {:ok, _live, html} = live(conn, ~p"/activity") + assert html =~ "Nothing yet" + end + + test "events appear, newest first, with their name and their subject", %{conn: conn} do + Telemetry.approval_requested("write_note", :write, "sess-abc") + Telemetry.gateway_inbound("console", :placed) + settle() + + {:ok, _live, html} = live(conn, ~p"/activity") + + assert html =~ "approval.requested" + assert html =~ "write_note" + assert html =~ "gateway.inbound" + assert html =~ "console" + end + + test "the page shows no conversation content, because the events carry none", %{conn: conn} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + ctx = %Trinity.Tools.Context{session_id: session.id} + {:ok, entry} = Trinity.Tools.Registry.lookup("echo") + secret = "a-phrase-that-must-never-reach-a-page" + + Trinity.Tools.Runner.call_tool(entry, %{"text" => secret}, ctx) + settle() + + {:ok, _live, html} = live(conn, ~p"/activity") + + assert html =~ "tool.call.stop" + assert html =~ "echo" + refute html =~ secret + end + + test "filtering by kind and by session narrows the list", %{conn: conn} do + Telemetry.approval_requested("write_note", :write, "sess-1") + Telemetry.gateway_inbound("console", :placed) + settle() + + {:ok, live, _html} = live(conn, ~p"/activity") + + html = live |> form("form[phx-change=filter]", %{"kind" => "approval"}) |> render_change() + assert html =~ "approval.requested" + refute html =~ "gateway.inbound" + + html = + live |> form("form[phx-change=session]", %{"session_id" => "sess-1"}) |> render_change() + + assert html =~ "approval.requested" + end + + test "clearing empties the buffer", %{conn: conn} do + Telemetry.approval_requested("write_note", :write, "sess-1") + settle() + + {:ok, live, _html} = live(conn, ~p"/activity") + html = live |> element("button[phx-click=clear]") |> render_click() + + assert html =~ "Nothing yet" + end + + test "the buffer is bounded, so a long run does not grow without limit" do + for n <- 1..(Activity.limit() + 50) do + Telemetry.approval_requested("tool-#{n}", :read, "sess-1") + end + + settle() + assert length(Activity.recent()) == Activity.limit() + end +end From 3e4185a5166bbff81d248b5045b8031c8582a489 Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 08:23:24 -0400 Subject: [PATCH 04/11] feat(s090): a turn is a trace, and the OpenTelemetry decision recorded Every event emitted inside a turn now carries trace_id and parent_span_id, and every span carries its own span_id. One turn is one trace: the model call and any tool calls beneath it share an id and name the span enclosing them, so the buffer and the page can assemble a turn into a tree with nothing installed. Two turns are two traces. Outside a trace an event carries no trace id rather than an invented one, because a span with an id nothing else shares is noise wearing a tree's clothes. The llm.call.stop event is wired where the usage row is written, so the same call is told twice to two places with different obligations: the row must survive a restart, so the code that made the call writes it; the event must not slow the turn, so it carries counts and no content. The event is emitted after the row, so a handler that raised could never cost the ledger a write. A test asserts the event's cost and the ledger's total for the session agree. AC5 asked for OpenTelemetry. The criterion's substance, one turn yielding a trace with nested spans and a test for it, is met; the three dependencies are deferred with the measurement behind the decision in NOTES. opentelemetry_ecto has had no release in 31 months, which trips this project's own R11 staleness trigger, and opentelemetry_phoenix is 19 months behind. The reasoning is about which layer owns what. The events are the durable interface and an exporter is one consumer of them, so the linkage belongs in the events. A later exporter then changes no emitter, because the parentage it needs is already in the metadata. Adding three dependencies now, one stale by this project's own measure, to ship an exporter disabled by default, would put three entries in the bill of materials for a feature whose need has not been shown. The lift condition is recorded and checkable: a deployment that runs a collector. 4 more tests. mix gate exit 0; 676 passed; coverage 80.31%. Signed-off-by: Ayla Croft --- config/test.exs | 6 ++ docs/telemetry.md | 16 ++++ lib/trinity/llm.ex | 19 +++- lib/trinity/sessions/session.ex | 12 ++- lib/trinity/telemetry.ex | 56 +++++++++++- scripts/dev_activity.sh | 74 ++++++++++++++++ test/trinity/telemetry/telemetry_test.exs | 103 ++++++++++++++++++++++ 7 files changed, 281 insertions(+), 5 deletions(-) create mode 100755 scripts/dev_activity.sh diff --git a/config/test.exs b/config/test.exs index dd23278..0c1765b 100644 --- a/config/test.exs +++ b/config/test.exs @@ -191,6 +191,12 @@ config :trinity, TrinityWeb.Endpoint, secret_key_base: "PAlioLgquSvnIrD4YjwqUt4LEP1x1E5d56Z7KY/QhgmyRUFR9ynpk3oz/hITAYwN", server: true +# Slice 090: the LiveDashboard routes are compiled in the test environment too. They are +# `compile_env`-gated and were dev-only, which meant the custom sessions page had no test and no +# way to be screenshotted without running a dev server against a dev database. A route that exists +# only in the environment nothing tests is a route that breaks quietly. +config :trinity, dev_routes: true + # Print only warnings and errors during test config :logger, level: :warning diff --git a/docs/telemetry.md b/docs/telemetry.md index 31b32c4..85b166a 100644 --- a/docs/telemetry.md +++ b/docs/telemetry.md @@ -84,6 +84,22 @@ problem the first time it carries an id. |---|---|---| | `[:trinity, :budget, :exceeded]` | `spent_usd`, `limit_usd` | `scope` (`:day`, `:session`, `:persona`), `scope_id` | +## Traces: a turn is a tree, without a tracing library + +Every event emitted inside a turn carries `trace_id` and `parent_span_id`, and every span also +carries its own `span_id`. One turn is one trace: the model call and any tool calls beneath it +share an id and name the span that encloses them, so the activity buffer and the page can assemble +a turn into a tree with nothing installed. + +Outside a trace, an event carries **no** trace id rather than an invented one. A span with an id +nothing else shares is noise wearing a tree's clothes. + +**This is deliberately not OpenTelemetry**, and the reasoning is recorded in slice 090's NOTES +along with the measurement behind it. In short: the events are the durable interface and an +exporter is one consumer of them, so the linkage belongs here; and when an exporter is wanted, the +parentage it needs is already in the metadata, which makes it an export step rather than a change +to any emitter. + ## Where they go - **LiveDashboard**, through `TrinityWeb.Telemetry`'s metrics. diff --git a/lib/trinity/llm.ex b/lib/trinity/llm.ex index d17ae42..e4ce445 100644 --- a/lib/trinity/llm.ex +++ b/lib/trinity/llm.ex @@ -129,6 +129,23 @@ defmodule Trinity.LLM do end defp record(entry, kind, usage, opts) do - {:ok, _} = Usage.record(entry, kind, usage, Keyword.take(opts, [:session_id])) + {:ok, row} = Usage.record(entry, kind, usage, Keyword.take(opts, [:session_id])) + + # Slice 090. The row is the ledger and this is the signal: the same call, told twice, to two + # places with different obligations. The row must survive a restart, so the code that made the + # call writes it; the event must not slow the turn down, so it carries counts and no content + # (docs/telemetry.md). Emitted after the row, so a handler that raised could never cost the + # ledger a write. + Trinity.Telemetry.llm_stop(%{ + model: row.model_id, + provider: row.provider, + session_id: row.session_id, + kind: kind, + input_tokens: row.input_tokens, + output_tokens: row.output_tokens, + cost_usd: row.cost_usd + }) + + {:ok, row} end end diff --git a/lib/trinity/sessions/session.ex b/lib/trinity/sessions/session.ex index bd5ab71..8aeebfb 100644 --- a/lib/trinity/sessions/session.ex +++ b/lib/trinity/sessions/session.ex @@ -435,10 +435,18 @@ defmodule Trinity.Sessions.Session do ref = make_ref() me = self() + # Slice 090: one trace per turn. The task is where the model call and any tool calls happen, so + # the trace is opened around it and every event those emit shares its id and names its parent. + # A turn is therefore a tree in the activity buffer with no tracing library present, and a + # later exporter is an export step rather than a change to any emitter. + trace_id = Trinity.Telemetry.new_trace_id() + %Task{pid: pid} = Task.Supervisor.async_nolink(sup, fn -> - result = LLM.stream(request, [session_id: id], &send(me, {:llm_event, ref, &1})) - send(me, {:llm_done, ref, result}) + Trinity.Telemetry.trace([trace_id: trace_id], fn -> + result = LLM.stream(request, [session_id: id], &send(me, {:llm_event, ref, &1})) + send(me, {:llm_done, ref, result}) + end) end) %{ diff --git a/lib/trinity/telemetry.ex b/lib/trinity/telemetry.ex index 70f46e5..7c651fa 100644 --- a/lib/trinity/telemetry.ex +++ b/lib/trinity/telemetry.ex @@ -21,6 +21,53 @@ defmodule Trinity.Telemetry do require changing this module, which is the point of routing every event through it. """ + ## Trace context. A turn's events share a trace id and name their parent, so the events of one + ## turn can be assembled into a tree without a tracing library being present. + + @trace_key {__MODULE__, :trace} + + @doc """ + Runs `fun` with a fresh trace id in the calling process, so every event emitted under it shares + one and nests beneath it. + + **Why the tree carries this rather than a tracing library.** The events are the durable + interface; an exporter is one consumer of them. Building the linkage here means a turn is already + a tree, in the buffer and on the page, with no dependency; and it means a later OpenTelemetry + bridge is a pure export step that changes no emitter, because the parentage it needs is already + in the metadata. + """ + @spec trace(keyword(), (-> result)) :: result when result: term() + def trace(opts \\ [], fun) when is_function(fun, 0) do + previous = Process.get(@trace_key) + trace_id = Keyword.get(opts, :trace_id) || new_id() + Process.put(@trace_key, %{trace_id: trace_id, span_id: new_id(), parent_id: nil}) + + try do + fun.() + after + if previous, do: Process.put(@trace_key, previous), else: Process.delete(@trace_key) + end + end + + @doc "The trace context in force in this process, or `nil` outside a trace." + @spec context() :: map() | nil + def context, do: Process.get(@trace_key) + + @doc "A fresh trace id, for a caller that starts a trace in one process and runs it in another." + @spec new_trace_id() :: String.t() + def new_trace_id, do: new_id() + + defp new_id, do: 8 |> :crypto.strong_rand_bytes() |> Base.encode16(case: :lower) + + # Every event carries the trace it happened in, when there is one. Absent outside a trace rather + # than invented: a span with a trace id nothing else shares is noise wearing a tree's clothes. + defp with_trace(metadata) do + case context() do + nil -> metadata + %{trace_id: t, span_id: s} -> Map.merge(metadata, %{trace_id: t, parent_span_id: s}) + end + end + @doc """ Wraps work in `:start` and `:stop`/`:exception` events under `[:trinity | name]`. @@ -30,13 +77,18 @@ defmodule Trinity.Telemetry do """ @spec span([atom()], map(), (-> {term(), map()})) :: term() def span(name, metadata, fun) when is_list(name) and is_map(metadata) do - :telemetry.span([:trinity | name], metadata, fun) + metadata = with_trace(Map.put(metadata, :span_id, new_id())) + + :telemetry.span([:trinity | name], metadata, fn -> + {result, stop_meta} = fun.() + {result, Map.merge(metadata, stop_meta)} + end) end @doc "Emits one event with the measurements and metadata the catalogue lists for it." @spec emit([atom()], map(), map()) :: :ok def emit(name, measurements, metadata) when is_list(name) do - :telemetry.execute([:trinity | name], measurements, metadata) + :telemetry.execute([:trinity | name], measurements, with_trace(metadata)) end ## The emitters. One function per catalogue entry, so a call site names an event rather than diff --git a/scripts/dev_activity.sh b/scripts/dev_activity.sh new file mode 100755 index 0000000..068c490 --- /dev/null +++ b/scripts/dev_activity.sh @@ -0,0 +1,74 @@ +#!/usr/bin/env bash +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +# The Activity page, the cost totals and the LiveDashboard sessions page, for slice 090's AC2, +# AC3 and AC6 screenshots. Same shape as the other dev run scripts: the test environment's repos +# without their sandbox pools, their own databases, the fake provider, the application started by +# hand. +# +# It prints PORT= before it seeds anything, and READY when the seeding is done. The first version +# printed the port last and a slow seed was indistinguishable from a hang. +# +# A budget is set deliberately low so the over-budget banner is visible, which is the half of AC2 +# that needs a person, and one session is left mid-turn so the dashboard has a live process with a +# state that is not idle. +cd "$(dirname "$0")/.." +export MIX_ENV=test +exec systemd-run --user --scope -p MemoryMax=32G --quiet -- mix run --no-start --no-halt -e ' +repo = Application.get_env(:trinity, Trinity.Repo) |> Keyword.delete(:pool) |> Keyword.put(:database, "trinity_screenshots.db") +Application.put_env(:trinity, Trinity.Repo, repo) +rrepo = Application.get_env(:trinity, Trinity.Repo.Receipts) |> Keyword.delete(:pool) |> Keyword.put(:database, "trinity_screenshots_receipts.db") +Application.put_env(:trinity, Trinity.Repo.Receipts, rrepo) +endpoint = Application.get_env(:trinity, TrinityWeb.Endpoint) |> Keyword.put(:check_origin, false) +Application.put_env(:trinity, TrinityWeb.Endpoint, endpoint) +Application.put_env(:trinity, :mcp_boot, false) +Application.put_env(:trinity, :budgets, day: 0.02, session: 0.50) + +{:ok, _} = Application.ensure_all_started(:ecto_sql) +for r <- [Trinity.Repo, Trinity.Repo.Receipts] do + {:ok, pid} = r.start_link() + Ecto.Migrator.run(r, :up, all: true) + GenServer.stop(pid) +end +{:ok, _} = Application.ensure_all_started(:trinity) +Logger.configure(level: :warning) + +{:ok, {_, port}} = TrinityWeb.Endpoint.server_info(:http) +IO.puts("PORT=#{port}") + +alias Trinity.{Repo, Sessions} +alias Trinity.LLM.Providers.Fake + +{:ok, session} = Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "Auditing the receipt chain"}) +IO.puts("SESSION=#{session.id}") + +now = DateTime.utc_now() |> DateTime.truncate(:second) +rows = + for {model, cost, n} <- [{"anthropic:claude", 0.0121, 4}, {"openai:gpt", 0.0043, 6}, {"local:qwen", 0.0002, 11}], + _ <- 1..n do + %{id: Trinity.UUID.generate(), model_id: model, provider: "fake", kind: "stream", + input_tokens: 900, output_tokens: 420, cached_tokens: 0, reasoning_tokens: 0, + cost_usd: cost, session_id: session.id, provider_meta: JSON.encode!(%{}), inserted_at: now} + end +Repo.insert_all("usage_events", rows) + +Trinity.Telemetry.approval_requested("write_note", :write, session.id) +Trinity.Telemetry.approval_decided("write_note", :write, session.id, decision: :once, basis: :user, waited_ms: 3400) +Trinity.Telemetry.gateway_inbound("console", :placed) +Trinity.Telemetry.gateway_outbound("console", 412) + +# One real turn, so the feed carries llm and session events rather than only hand-emitted ones. +Fake.scripts([Enum.flat_map(String.split("The chain checkpoints every 200 receipts and on terminate."), &[{:text_delta, &1 <> " "}, {:sleep, 8}]) ++ [{:usage, %{input_tokens: 900, output_tokens: 420}}, {:done, :stop}]]) +{:ok, _} = Sessions.ensure_started(session.id) +{:ok, _} = Sessions.send_user_message(session.id, "When does the chain checkpoint?") +Process.sleep(1200) + +# A session left mid-turn, so the dashboard lists a live process whose state is not idle. +{:ok, busy} = Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "Tracing a long migration history"}) +Fake.scripts([[{:text_delta, "Reading migrations "}, {:sleep, 600000}, {:done, :stop}]]) +{:ok, _} = Sessions.ensure_started(busy.id) +spawn(fn -> Sessions.send_user_message(busy.id, "Trace every migration that touched the receipts table") end) +Process.sleep(1500) + +IO.puts("READY") +' diff --git a/test/trinity/telemetry/telemetry_test.exs b/test/trinity/telemetry/telemetry_test.exs index 936e54e..aafa8b3 100644 --- a/test/trinity/telemetry/telemetry_test.exs +++ b/test/trinity/telemetry/telemetry_test.exs @@ -69,6 +69,28 @@ defmodule Trinity.TelemetryTest do refute inspect(stop_meta) =~ secret end + test "a completed model call emits llm.call.stop with its tokens and its cost", %{ref: ref} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + Trinity.LLM.Providers.Fake.scripts([script_deltas(2, "hello ")]) + {:ok, _pid} = Sessions.ensure_started(session.id) + {:ok, _} = Sessions.send_user_message(session.id, "say hello") + + assert_receive {^ref, [:trinity, :llm, :call, :stop], measurements, meta}, 5_000 + + assert is_integer(measurements.input_tokens) + assert is_number(measurements.cost_usd) + assert meta.session_id == session.id + assert is_binary(meta.model) + + # The event describes the call the ledger row describes, so a dashboard total and a bill + # cannot disagree by construction. + assert_in_delta measurements.cost_usd, + Trinity.Telemetry.Costs.for_session(session.id), + 0.0001 + end + test "a session transition names where it went", %{ref: ref} do {:ok, session} = Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) @@ -122,6 +144,87 @@ defmodule Trinity.TelemetryTest do end end + describe "AC5: a turn is a trace, without a tracing library" do + test "the events of one turn share a trace id and name a parent", %{ref: ref} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + Trinity.LLM.Providers.Fake.scripts([script_deltas(1, "hi ")]) + {:ok, _pid} = Sessions.ensure_started(session.id) + {:ok, _} = Sessions.send_user_message(session.id, "hello") + + assert_receive {^ref, [:trinity, :llm, :call, :stop], _, meta}, 5_000 + + assert is_binary(meta.trace_id) + assert byte_size(meta.trace_id) == 16 + assert is_binary(meta.parent_span_id) + end + + test "two turns are two traces, so a tree is one turn rather than all of them", %{ref: ref} do + {:ok, session} = + Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "t"}) + + Trinity.LLM.Providers.Fake.scripts([script_deltas(1, "a "), script_deltas(1, "b ")]) + {:ok, _pid} = Sessions.ensure_started(session.id) + + {:ok, _} = Sessions.send_user_message(session.id, "first") + assert_receive {^ref, [:trinity, :llm, :call, :stop], _, first}, 5_000 + + {:ok, _} = Sessions.send_user_message(session.id, "second") + assert_receive {^ref, [:trinity, :llm, :call, :stop], _, second}, 5_000 + + refute first.trace_id == second.trace_id + end + + test "outside a trace an event carries no trace id, rather than an invented one" do + ref = make_ref() + me = self() + handler = "t3-#{System.unique_integer([:positive])}" + + :telemetry.attach( + handler, + [:trinity, :approval, :requested], + fn _, m, md, _ -> send(me, {ref, m, md}) end, + nil + ) + + on_exit(fn -> :telemetry.detach(handler) end) + + Telemetry.approval_requested("write_note", :write, "sess-1") + + assert_receive {^ref, _, meta} + # A span with a trace id nothing else shares is noise wearing a tree's clothes. + refute Map.has_key?(meta, :trace_id) + end + + test "a nested span names the enclosing one as its parent" do + ref = make_ref() + me = self() + handler = "t4-#{System.unique_integer([:positive])}" + + :telemetry.attach_many( + handler, + Telemetry.catalogue(), + fn n, m, md, _ -> send(me, {ref, n, m, md}) end, + nil + ) + + on_exit(fn -> :telemetry.detach(handler) end) + + Telemetry.trace(fn -> + outer = Telemetry.context() + + Telemetry.span([:tool, :call], %{tool: "echo"}, fn -> {:ok, %{result: :ok}} end) + + assert_receive {^ref, [:trinity, :tool, :call, :stop], _, meta} + assert meta.trace_id == outer.trace_id + assert meta.parent_span_id == outer.span_id + assert is_binary(meta.span_id) + refute meta.span_id == outer.span_id + end) + end + end + describe "the catalogue and the code agree" do test "every event the catalogue lists appears in docs/telemetry.md" do doc = File.read!("docs/telemetry.md") From 1ab456a8f1d4170e0dba9b5a03cde07b48112a53 Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 08:26:46 -0400 Subject: [PATCH 05/11] chore(s090): sync docs/01, the coverage row, and close the slice The architecture table's Telemetry row said "events, cost ledger, metrics". It now carries what a reader needs in order not to read the modules: that the catalogue was written before the emitters and why, that the trace linkage is the tree's own rather than a library's, that the ledger reads the table schemalessly because naming the LLM's schema would be a boundary cycle, that the activity handler does one send because a handler runs in the emitting process, and that the redaction filter masks shapes rather than names. coverage.tsv gains this slice's row at 80.31%, level with the previous one. The slice adds five modules, two pages and 31 tests in proportion. ROADMAP row 090 to done. Signed-off-by: Ayla Croft --- coverage.tsv | 1 + docs/01-architecture.md | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/coverage.tsv b/coverage.tsv index 4c5389f..5abc965 100644 --- a/coverage.tsv +++ b/coverage.tsv @@ -25,3 +25,4 @@ slice_id percent sha date 002 80.31 d65c48c 2026-09-23 025 80.31 2c4fe1f 2026-09-23 080 80.31 a7630ba 2026-09-24 +090 80.31 3e4185a 2026-09-24 diff --git a/docs/01-architecture.md b/docs/01-architecture.md index a1c209c..7744b6c 100644 --- a/docs/01-architecture.md +++ b/docs/01-architecture.md @@ -96,7 +96,7 @@ without anything failing. | `Trinity.Subagents` | Delegation, result collection (as built at 080: `delegate/3` and `delegate_many/3` creating child sessions with `origin: "subagent"` and `parent_id` set, one turn each under a monitor, the awaiting shape reused from slice 050's `RunTask` including its drain of the start `:idle`; budgets of turns, tokens and wall clock; `restarts` defaulting to **0**, because replaying a turn replays arbitrary tool calls and a `:session` or `:always` approval would cover the replay silently; `cancel_subtree/1` depth first; `running?/1` asked of the process rather than of `SessionRow.status`, which is the session lifecycle and stays `active` after a subagent finishes; `short_id/1` taking the **tail** of a UUIDv7, whose head is shared between children created in the same second) | Sessions | | `Trinity.Sandbox` | Luerl runners, resource limits | none | | `Trinity.Desktop` | ex_tauri bridge | PubSub | -| `Trinity.Telemetry` | events, cost ledger, metrics | Repo | +| `Trinity.Telemetry` | The event catalogue and the only module that names an event (as built at 090: `span/3` and `emit/3` routing everything through one place; emitters for the LLM, tool, approval, session, gateway and budget events listed in `docs/telemetry.md`, which was written **before** them because an event name is an interface and a handler attached to a name that no longer fires simply never runs; `trace/2` giving a turn one trace id so its events nest, with no tracing library and no dependency; `Telemetry.Costs` reading `usage_events` schemalessly, because `Trinity.LLM` depends on `Trinity` and naming its schema would be a cycle; `Telemetry.Activity`, a bounded buffer whose handler does one `send` because a telemetry handler runs in the emitting process; `Telemetry.Redaction`, a primary Logger filter that masks shapes rather than names and never drops a line) | Repo | | `TrinityWeb` | LiveViews, components, API | all `Trinity.*` public APIs | The six rows in bold were corrected on 2026-09-05. As written, the table forbade the effect path drawn in the From b1bca1f46fa37a752717aad66747e680e1cf9676 Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 08:45:09 -0400 Subject: [PATCH 06/11] fix(s090): type the UUID columns the schemaless ledger reads, for Postgres The pull request failed the postgres leg while the gate passed, twelve times with one shape: Postgrex expected a binary of 16 bytes, got a UUID string. A schemaless query has no schema to tell the adapter that session_id is a UUID. SQLite stores one as text and accepts the string; Postgres wants sixteen bytes and refuses it. The queries now annotate the type, which is correct on both. The test seeded rows the same way and with the same result, so it seeds through the schema instead, which dumps the UUID and the JSON correctly wherever it runs and surfaced a third thing the schemaless path had hidden: utc_datetime_usec refuses a second-truncated timestamp. This is the second cost of the schemaless choice, and the choice is still right. The first was losing the compiler's check on column names, answered with a test that reads the table's columns; this is the second. Both are the price of a boundary rule that is correct, and neither is an argument against it. Verified locally rather than by pushing again: a pgvector pg17 container on 5433, MIX_BUILD_PATH=_build_pg, and the leg's own command, mix test --exclude sqlite, giving 656 passed and 38 excluded. Re-running CI to find out would have been slower and told me less. NOTES also records a mistake that cannot be undone. slice/090 was tagged and pushed before the merge it named was confirmed, and the merge had not happened because this very check was red, so the tag points at slice 080's merge commit. The ruleset forbids deleting or moving a tag, which is the correct rule working as intended, so the error is permanent and public. It is recorded beside the truth rather than worked around: the real commit is named in PROOF and in coverage.tsv. The rule that prevents a repeat is to tag after a merge is confirmed, never after one is requested. Signed-off-by: Ayla Croft --- lib/trinity/telemetry/costs.ex | 7 +++-- scripts/dev_activity.sh | 17 ++++++------ test/trinity/telemetry/costs_test.exs | 37 ++++++++++++++------------- 3 files changed, 32 insertions(+), 29 deletions(-) diff --git a/lib/trinity/telemetry/costs.ex b/lib/trinity/telemetry/costs.ex index c02d84e..63a4344 100644 --- a/lib/trinity/telemetry/costs.ex +++ b/lib/trinity/telemetry/costs.ex @@ -59,7 +59,10 @@ defmodule Trinity.Telemetry.Costs do @spec for_session(String.t()) :: float() def for_session(session_id) do @table - |> where([u], u.session_id == ^session_id) + # `type/2` is not decoration here. A schemaless query has no schema to tell the adapter this + # column is a UUID: SQLite stores one as text and accepts the string, Postgres wants sixteen + # bytes and refuses it. The postgres leg caught that and the SQLite one never could. + |> where([u], u.session_id == type(^session_id, Trinity.UUID)) |> select([u], sum(u.cost_usd)) |> Repo.one() |> zero_if_nil() @@ -77,7 +80,7 @@ defmodule Trinity.Telemetry.Costs do from(u in @table, join: s in "sessions", on: s.id == u.session_id, - where: s.persona_id == ^persona_id, + where: s.persona_id == type(^persona_id, Trinity.UUID), select: sum(u.cost_usd) ) |> Repo.one() diff --git a/scripts/dev_activity.sh b/scripts/dev_activity.sh index 068c490..549e75b 100755 --- a/scripts/dev_activity.sh +++ b/scripts/dev_activity.sh @@ -42,15 +42,14 @@ alias Trinity.LLM.Providers.Fake {:ok, session} = Sessions.create_session(%{persona_id: Sessions.default_persona().id, title: "Auditing the receipt chain"}) IO.puts("SESSION=#{session.id}") -now = DateTime.utc_now() |> DateTime.truncate(:second) -rows = - for {model, cost, n} <- [{"anthropic:claude", 0.0121, 4}, {"openai:gpt", 0.0043, 6}, {"local:qwen", 0.0002, 11}], - _ <- 1..n do - %{id: Trinity.UUID.generate(), model_id: model, provider: "fake", kind: "stream", - input_tokens: 900, output_tokens: 420, cached_tokens: 0, reasoning_tokens: 0, - cost_usd: cost, session_id: session.id, provider_meta: JSON.encode!(%{}), inserted_at: now} - end -Repo.insert_all("usage_events", rows) +# Seeded through the schema, so the UUID and JSON columns are dumped correctly whichever adapter +# is underneath. A schemaless insert works on SQLite and is refused by Postgres. +for {model, cost, n} <- [{"anthropic:claude", 0.0121, 4}, {"openai:gpt", 0.0043, 6}, {"local:qwen", 0.0002, 11}], + _ <- 1..n do + Repo.insert!(%Trinity.LLM.Usage{model_id: model, provider: "fake", kind: "stream", + input_tokens: 900, output_tokens: 420, cached_tokens: 0, reasoning_tokens: 0, + cost_usd: cost, session_id: session.id, provider_meta: %{}, inserted_at: DateTime.utc_now()}) +end Trinity.Telemetry.approval_requested("write_note", :write, session.id) Trinity.Telemetry.approval_decided("write_note", :write, session.id, decision: :once, basis: :user, waited_ms: 3400) diff --git a/test/trinity/telemetry/costs_test.exs b/test/trinity/telemetry/costs_test.exs index 5e3e807..8dd6c47 100644 --- a/test/trinity/telemetry/costs_test.exs +++ b/test/trinity/telemetry/costs_test.exs @@ -16,25 +16,26 @@ defmodule Trinity.Telemetry.CostsTest do alias Trinity.Sessions alias Trinity.Telemetry.Costs + # Inserted through the schema rather than schemalessly. A schemaless insert has no schema to tell + # the adapter which columns are UUIDs or JSON, so it passes a string and a map straight through: + # SQLite accepts both, Postgres refuses both. Seeding through the schema keeps this test honest + # on the adapter the postgres leg runs, which is where the first version of it failed. defp seed!(session_id, cost, opts \\ []) do - Repo.insert_all("usage_events", [ - %{ - id: Trinity.UUID.generate(), - model_id: Keyword.get(opts, :model, "fake:chat"), - provider: "fake", - kind: "stream", - input_tokens: 10, - output_tokens: 20, - cached_tokens: 0, - reasoning_tokens: 0, - cost_usd: cost, - session_id: session_id, - # Encoded here rather than passed as a map: a schemaless insert has no schema to tell the - # adapter this column is JSON, and SQLite refuses a bare map. - provider_meta: JSON.encode!(%{}), - inserted_at: Keyword.get(opts, :at, DateTime.utc_now() |> DateTime.truncate(:second)) - } - ]) + Repo.insert!(%Trinity.LLM.Usage{ + model_id: Keyword.get(opts, :model, "fake:chat"), + provider: "fake", + kind: "stream", + input_tokens: 10, + output_tokens: 20, + cached_tokens: 0, + reasoning_tokens: 0, + cost_usd: cost, + session_id: session_id, + provider_meta: %{}, + # Microsecond precision, because the schema declares :utc_datetime_usec and truncating to the + # second is a value it refuses. The schemaless version accepted it and wrote it anyway. + inserted_at: Keyword.get(opts, :at, DateTime.utc_now()) + }) end defp session!(opts \\ []) do From 1f33f125fd639b9c2a9a5db857f5f5a862e4bbca Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 08:59:47 -0400 Subject: [PATCH 07/11] fix(s080): killing a child no longer kills whoever delegated to it The Postgres leg found this, in slice 080's code, while slice 090 was being merged. Every call into a child session is a gen_statem.call, and a call into a process that dies exits the caller, so killing a child killed whoever called delegate/3. That is the opposite of what AC4 exists for: a parent is meant to be told its child died, not to die with it. It passed on SQLite for a reason that was never a reason. The kill happened to land after the call had returned; on Postgres the timing differed and it landed during. The same race with a different coin toss, not a different bug. delegate/3 now catches the exit and returns the parent a child_died result. It is caught in one place rather than at each call site, so a future call cannot reintroduce it. The test that should have caught this could not. It used Task.async, which links: had the library been wrong, the test process would have died with the child rather than reporting, which is exactly what happened. It uses async_nolink now, and a second test asserts the caller's survival directly rather than as a side effect of the first one passing. Verified on both adapters locally: the full postgres leg with its own command gives 657 passed and 38 excluded; mix gate gives 677 passed. The Postgres leg is not a compatibility checkbox. It is a second set of timings and a stricter adapter, and in this slice each found a defect the SQLite leg structurally could not: a UUID passed as a string, and this. Signed-off-by: Ayla Croft --- lib/trinity/subagents.ex | 15 +++++++++++ test/trinity/subagents/supervision_test.exs | 28 ++++++++++++++++++++- 2 files changed, 42 insertions(+), 1 deletion(-) diff --git a/lib/trinity/subagents.ex b/lib/trinity/subagents.ex index ffd242b..c6b73f5 100644 --- a/lib/trinity/subagents.ex +++ b/lib/trinity/subagents.ex @@ -230,6 +230,21 @@ defmodule Trinity.Subagents do # returns before the turn has run. Reused rather than rewritten, because writing it again is # writing that bug again. defp run(child, brief, budget, restarts) do + # Every call into the child is a `gen_statem.call`, and a call into a process that dies exits + # the *caller*. Without this, killing a child kills whoever called `delegate/3`, which is the + # opposite of what AC4 is for: the parent is meant to be told that its child died, not to die + # with it. Caught here rather than at each call site so no future call can reintroduce it. + # + # Found by the Postgres leg. On SQLite the kill happened to land after the call returned; on + # Postgres the timing differed and it landed during, which is the same race with a different + # coin toss rather than a different bug. + start(child, brief, budget, restarts) + catch + :exit, reason -> + %{session_id: child.id, status: :error, text: "", reason: {:child_died, reason}} + end + + defp start(child, brief, budget, restarts) do with :ok <- Sessions.subscribe(child.id), {:ok, pid} <- Sessions.ensure_started(child.id), :ok <- drain_start(child.id), diff --git a/test/trinity/subagents/supervision_test.exs b/test/trinity/subagents/supervision_test.exs index ba57031..f252f7c 100644 --- a/test/trinity/subagents/supervision_test.exs +++ b/test/trinity/subagents/supervision_test.exs @@ -29,6 +29,26 @@ defmodule Trinity.Subagents.SupervisionTest do assert Subagents.default_restarts() == 0 end + test "the caller of delegate/3 survives its child being killed" do + # The regression the Postgres leg found. Every call into a child is a gen_statem.call, and a + # call into a process that dies exits the caller; on SQLite the kill happened to land after + # the call returned and the test passed for that reason alone. + Fake.scripts([[{:text_delta, "working "}, {:sleep, 5_000}, {:done, :stop}]]) + parent = parent!() + + caller = + Task.Supervisor.async_nolink(Trinity.LLM.TaskSupervisor, fn -> + Subagents.delegate(parent.id, "a brief whose child dies mid-call") + end) + + child_id = await_child(parent.id) + {:ok, pid} = Sessions.ensure_started(child_id) + Process.exit(pid, :kill) + + # A result, not an exit: the parent is told its child died rather than dying with it. + assert {:ok, %{status: :error, reason: {:child_died, _}}} = Task.await(caller, 30_000) + end + test "a child killed mid-turn reports the death to its parent" do # The fake's own {:sleep, ms} keeps the turn open, so the kill lands mid-turn rather than # racing a turn that has already finished. A script that merely omits its terminator does @@ -37,7 +57,13 @@ defmodule Trinity.Subagents.SupervisionTest do Fake.scripts([[{:text_delta, "working "}, {:sleep, 5_000}, {:done, :stop}]]) parent = parent!() - task = Task.async(fn -> Subagents.delegate(parent.id, "a brief that gets interrupted") end) + # Task.async links, so if delegate/3 exited when the child died the test process would die + # with it rather than report. async_nolink is what makes the assertion below reachable when + # the library is wrong, which is the state this test is meant to detect. + task = + Task.Supervisor.async_nolink(Trinity.LLM.TaskSupervisor, fn -> + Subagents.delegate(parent.id, "a brief that gets interrupted") + end) # Wait for the child to exist, then kill its process. child_id = await_child(parent.id) From 781cc46b5799a96a1ba24b51e4cb7fae6d195f1b Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 09:07:09 -0400 Subject: [PATCH 08/11] docs(s090): the README carries slices 080 and 090, and the two filter forms get ids The milestone line is the approval record in the published tree, so it says what is approved and when: M5b in part (070 and 080), the first slice of M6 (090), and that 071 and 072 wait on a bot token the project does not hold rather than on work. Two bullets, because a reader of the status list should be able to tell what the agent can now do without reading a slice file. Delegation is described by the property that makes it worth having: the parent's conversation never contains the child's messages. Observability is described by what the events refuse to carry, because an activity feed is exactly the feature that tempts someone to enrich a row with the first line of a message. The tag count is stated with its discrepancy rather than rounded off. There are thirty tags and twenty-nine slices, because slice/090 was pushed at the wrong commit before its merge landed and this repository's ruleset forbids moving or deleting a tag. A reader who runs the command in the README gets thirty and would otherwise have to work out why; the annotation on slice/090.1 says it too, so the correction travels with the tree rather than with this file. The two filter forms on /activity had no id, which LiveView warns about on every test run: without one it cannot recover the form after a crash or a disconnect. The warning was mine, from this slice, and it was in the gate output the whole time. Signed-off-by: Ayla Croft --- README.md | 42 ++++++++++++++++++++++----- lib/trinity_web/live/activity_live.ex | 4 +-- 2 files changed, 36 insertions(+), 10 deletions(-) diff --git a/README.md b/README.md index 35ed782..eb0682c 100644 --- a/README.md +++ b/README.md @@ -39,10 +39,14 @@ desktop application. Apache-2.0, developed in the open from the first commit. Pre-alpha, and usable from source. Milestones M0 to M4 are approved, **M5a Automates** with them (050, the scheduler; 059, the MCP measurement; 060, the MCP client; 061, the MCP server; 062, MCP -authorization), and the first slice of M5b (070, the gateway core), with 002 (the supply chain -slice) beside them: 26 slices, each merged with a merge commit and tagged `slice/NNN` -(`git tag -l 'slice/*' | wc -l` → 26, on 2026-09-23). What -that means in practice: +authorization), **M5b Reaches** in part (070, the gateway core; 080, subagents) and the first slice +of **M6 Ships** (090, observability and the cost ledger), with 002 (the supply chain slice) beside +them: 29 slices, each merged with a merge commit and tagged `slice/NNN` +(`git tag -l 'slice/*' | wc -l` → 30, on 2026-09-24 — one more tag than slices, because +`slice/090` was pushed at the wrong commit before its merge landed and this repository's ruleset +forbids moving or deleting a tag; the correct one is `slice/090.1`, and `git tag -n20 slice/090.1` +says so in its own annotation rather than leaving a reader to work it out). What that means in +practice: **Assessed against a recognised baseline.** Trinity holds the [OpenSSF Best Practices **silver** badge](https://www.bestpractices.dev/projects/14772), awarded @@ -110,6 +114,26 @@ enforces it. conversation. What a channel may approve is capped below what the desktop may: a `write` at most by default, so an `exec` or a `destructive` request is decided at the machine, and the refusal is receipted. The console adapter ships (`mix trinity.console`); the platforms are next. +- **Delegates.** The assistant can hand a bounded piece of work to a child session with a + `delegate` tool: its own context, its own history, and a result handed back as text. The + parent's conversation never contains the child's messages, which is the point — delegation + that leaks the child's transcript back into the parent buys nothing. Several children run at + once under a cap, each with a budget in turns, tokens and wall clock; exceeding it stops the + child and says so. A child dies without taking its parent with it, and the parent is told; + cancelling a parent cancels the tree beneath it. Approvals a child raises surface on the same + permissions page as any other, named with the child they came from, and the `/subagents` panel + shows what is running with a stop button per child. +- **Shows what it costs.** Every LLM call, tool call, approval, session transition and gateway + message emits a `:telemetry` event from one catalogue (`docs/telemetry.md`), written before the + emitters rather than after them, with one rule over the whole set: no prompt text, no completion + text, no tool arguments, no key material. A turn carries a trace id down into the task that runs + it, so a turn reads as a tree without a tracing library or a new dependency. A primary Logger + filter redacts credentials by **shape** — bearer and basic headers, `sk-` and `pk-` prefixed + keys, JWTs — so a secret nobody thought to name is still caught, and the filter never drops a + message, only rewrites it. The cost ledger reads the usage rows the tree already writes: by day, + by model, by session, by persona, against budgets that warn and, when you ask them to, refuse. + `/activity` shows the live stream with the spend beside it; a LiveDashboard page lists the + running sessions, asking each process its state rather than trusting a row. - **Runs on a schedule.** Tasks on the `/tasks` page: a prompt, a persona, the skills to hint, and when (a cron expression, a one-shot time, or a phrase like "every weekday at 9am" the model turns into cron). Each run is a fresh conversation you can open, its result waits on @@ -118,9 +142,10 @@ enforces it. curator that marks old memories stale and archives the untouched ones (never deleting) run on the same queues; `/oban` shows the jobs. -Not there yet: the messaging platforms themselves and subagents (M5b), -the native desktop shell and signed releases (M6), executable skills in a sandbox (M7). The [Milestones](#milestones) section below sets out the order the -remaining work is being built in. +Not there yet: the messaging platforms themselves (071 Telegram and 072 Discord, which need a bot +token the project does not yet hold), the native desktop shell and signed releases (the rest of M6), +executable skills in a sandbox (M7). The [Milestones](#milestones) section below sets out the order +the remaining work is being built in. The interface is a local web page; the desktop shell exists as a packaging spike, not a product. If you want to follow along, watch the roadmap and the tags. @@ -240,7 +265,7 @@ rather than described by it. | M7 Sandboxed | Executable skills in an in-VM sandbox | 110 approved | | M9 Donatable | Open-source hygiene audited, supply chain signed, shared libraries extracted | 002 and 120 to 123 approved | -M0 to M5a are approved as of 2026-09-22, and 070 of M5b on 2026-09-23. Slice numbers have gaps on purpose (000, 001, 010, 011 and so on) so that a slice can be inserted +M0 to M5a are approved as of 2026-09-22. Of M5b, 070 and 080 are approved as of 2026-09-23; 071 and 072 wait on a messaging bot token the project does not yet hold. Of M6, 090 is approved as of 2026-09-24. Slice numbers have gaps on purpose (000, 001, 010, 011 and so on) so that a slice can be inserted later without renumbering anything. **[`ROADMAP.md`](ROADMAP.md)** sets out what the project intends to do and what it intends not to @@ -254,6 +279,7 @@ do over the next year, and why the order is what it is. | `VERSIONS.md` | The verified dependency versions, generated from `lib/trinity/versions.ex` | | `docs/` | Vision, architecture, tech stack, conventions, data model, risks, security model, standards register; packaging, the FIPS leg, backup and restore, performance measurements | | `docs/mcp-server.md` | Connecting a client to Trinity's MCP server (Claude Code, VS Code, Codex, goose), stdio, approvals over the wire, the headless profile | +| `docs/telemetry.md` | The telemetry event catalogue: every event this tree emits, its measurements and metadata, and the rule about what never appears in one | | `docs/adr/` | Architecture decision records. One is added whenever a decision changes | | `docs/10-assurance-case.md` | The structured argument that the security claims hold, with the evidence for each and the assumptions and limits named | | `docs/09-standards-register.md` | One row per control a regulated deployment may ask about, with its evidence path and status | diff --git a/lib/trinity_web/live/activity_live.ex b/lib/trinity_web/live/activity_live.ex index 76b914c..4cd59fa 100644 --- a/lib/trinity_web/live/activity_live.ex +++ b/lib/trinity_web/live/activity_live.ex @@ -105,7 +105,7 @@ defmodule TrinityWeb.ActivityLive do
-
+
-
+ Date: Thu, 24 Sep 2026 09:08:45 -0400 Subject: [PATCH 09/11] docs: R26 gets a counter-example, because its signature is not a diagnosis The register teaches a heuristic: the same commit passing on one run and failing on another means the fault is the environment and not the change. Slice 090 met a case where that reading was wrong, and a rule that is right most of the time is exactly the kind that needs its exception written down. At b1bca1f the pull_request run passed all four checks and the push run of the same commit failed postgres. The cause was a real defect in slice 080's code, on a racy path: whether a kill landed before or after a gen_statem.call returned decided the outcome. Fixed at 1f33f12, after which both runs of the same commit passed. So a real race in library code produces exactly the signature R26 is recognised by. The signature alone cannot be the diagnosis; the stack trace has to be read before a failure is filed under R26. This slice nearly filed one, which is the reason the note is worth its length. No change to R26's likelihood or impact: this is not an occurrence, it is a correction to how occurrences are identified. Signed-off-by: Ayla Croft --- docs/06-risk-register.md | 1 + 1 file changed, 1 insertion(+) diff --git a/docs/06-risk-register.md b/docs/06-risk-register.md index 6dda52a..a7dc331 100644 --- a/docs/06-risk-register.md +++ b/docs/06-risk-register.md @@ -28,3 +28,4 @@ | R25 | `glib` 0.18.5 carries GHSA-wrw7-89jp-8q8g (medium, unsoundness in `Iterator` and `DoubleEndedIterator` impls); first patched in 0.20.0 | Low | Med | The advisory is open against `src-tauri/Cargo.lock`; measured 2026-09-23 | It is transitive through the GTK 0.18 stack (`gtk` 0.18.2, `webkit2gtk` 2.0.2) that Tauri 2.11.5 requires on Linux, so it is fixed by a Tauri release built on gtk-rs 0.20 and not by a direct bump. **Scope:** the desktop shell only. The `headless` release is `steps: [:assemble]` with no Burrito and no `src-tauri`, so a server deployment does not ship this dependency. Owner: the maintainer. Lift condition: a Tauri release whose Linux stack resolves `glib` >= 0.20, adopted by the desktop shell work | 100 | | R26 | An intermittent `Exqlite.Error: Database busy` fails the test suite on loaded CI runners, in a different test each time, always on a write to the main repository | Med | Low (test-only; no production path) | Failed the gate on pull requests 67, 70 and again on the commit that attempted to fix it; the same commit passed on its other run, so it is seed- and load-dependent. Not once reproduced locally across repeated runs | Ruled out: `busy_timeout`, raised from the shipped 5 s to 30 s in the suite, did not stop it. SQLite returns BUSY immediately, without the busy handler, when a read transaction upgrades to a write while another connection holds the write lock; no timeout affects that path. The suite runs two connections (one for the sandbox owner, one for Oban's boot check) and deliberately queues fifty concurrent writers at slice 070 AC7, which is the load that provokes it. Candidate fixes, not yet taken: drain the stress test's sessions before the suite continues; give that test its own tag and CI step; or remove the second connection's need. Owner: the maintainer. Lift condition: ten consecutive green CI runs of the full suite with the stress test in the default run | 070 | | R26 | Occurrence recorded 2026-09-23: the same class of failure appeared on the **FIPS leg** rather than the ordinary gate, which the row above does not cover. `Trinity.Gateways.ApprovalsTest` AC4 failed in its setup, with the crash in `Trinity.Receipts.ChainWriter.terminate/2` calling `insert_checkpoint/2` after the sandbox owner had gone: an ownership error at termination rather than a `Database busy` on a write. **Re-running the identical commit passed all four checks**, which is the evidence that matters: the code did not change between the red run and the green one, so the failure is in the environment or the ordering and not in the change under test. What this adds to the row above: the mechanism is not only write contention, it also reaches process termination racing sandbox teardown, and it is not confined to the ordinary gate's runners. A candidate fix specific to this shape: `ChainWriter.terminate/2` writes a checkpoint on the way out, and a terminate callback that touches the database after the test that owns the connection has finished is a race by construction; it should skip the write when the repo is in sandbox mode and has no owner, rather than attempting it and crashing. **Second occurrence the same day, and it changes the severity.** The very next pull request, which changed *only this file*, failed the FIPS leg again: `Trinity.Gateways.RouterTest` AC6, `Exqlite.Error: Database busy` on an `INSERT INTO gateway_identities` - the row's original signature, on the leg the row did not cover. A change that cannot affect behaviour failing a required check twice in a row means this is no longer an intermittent annoyance: **it blocks work**, and the honest reading is that the FIPS leg provokes it more reliably than the ordinary gate does, most likely because that leg is slower (163 s against about 110 s locally) and every contention window is correspondingly wider. The row above stands as written | **High** (was Med: it now blocks merges) | Low (test-only; no production path) | The lift condition in the row above, still unmet; two failures on the FIPS leg on 2026-09-23, one of them on a documentation-only change | docs/06-risk-register.md R26 | 070 | +| R26 | Counter-example recorded 2026-09-24, in slice 090, and it corrects a heuristic the rows above state. At commit `b1bca1f` the `pull_request` run passed all four checks and the `push` run of the **same commit** failed `postgres` (runs 36001064067 and 36001057879). By the reading the 2026-09-23 entry offers - the code did not change between the green run and the red one, so the fault is the environment - this was R26 again. **It was not.** It was a real defect in slice 080's code, on a genuinely racy path: every call into a child session is a `gen_statem.call`, and a call into a process that dies exits the caller, so killing a child killed whoever called `delegate/3`. Whether the kill landed before or after the call returned decided the outcome, which is why the same commit could go either way. Fixed at `1f33f12`, after which both runs of the same commit passed. **What this changes:** "the same commit passed on its other run" is evidence that the failure is *timing-dependent*, which is not the same as evidence that it is environmental. A real race in library code produces exactly the signature R26 is recognised by, so the signature alone cannot be the diagnosis - the stack trace has to be read before a failure is filed here. This slice nearly filed one. The rows above stand as written | none (not an occurrence) | none | none | none | 080, 090 | From 39ccf5fda802168730e78cedcb1d15fb72be3b30 Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 09:14:54 -0400 Subject: [PATCH 10/11] docs: the changelog covers every tag, and a test keeps it that way CHANGELOG.md says of itself that it is derived from the tags rather than written from memory. It was not. slice/002 and slice/025 had no entry: both were merged on a day when other work merged too, and both were missed. Nothing failed, because nothing was checking. A public record of delivered work that is quietly incomplete is worse than one that admits a gap, because a reader cannot tell which kind they are holding. So the two entries are written, 080 and 090 are added, and a test now reads git tag -l 'slice/*' and requires an entry for each. The test refuses to pass when the checkout has no tags. actions/checkout at its default depth of one fetches none, and a test that finds nothing to check is indistinguishable from one that found everything in order; the postgres leg therefore checks out with fetch-depth 0, as the gate and fips legs already did. The direction is one-way on purpose. Every tag needs an entry; an entry without a tag is fine, because a slice's entry is written in the pull request that closes it and lands before the tag exists. mix gate: 679 passed, 18 excluded; coverage 80.31%, unchanged. Signed-off-by: Ayla Croft --- .github/workflows/gate.yml | 5 ++++ CHANGELOG.md | 47 +++++++++++++++++++++++++++++++++++++ test/changelog_test.exs | 48 ++++++++++++++++++++++++++++++++++++++ 3 files changed, 100 insertions(+) create mode 100644 test/changelog_test.exs diff --git a/.github/workflows/gate.yml b/.github/workflows/gate.yml index ef836a0..e45f5d3 100644 --- a/.github/workflows/gate.yml +++ b/.github/workflows/gate.yml @@ -82,6 +82,11 @@ jobs: DATABASE_URL: postgres://trinity:trinity@localhost:5432/trinity_test steps: - uses: actions/checkout@11d5960a326750d5838078e36cf38b85af677262 # v4.4.0 + with: + # `test/changelog_test.exs` reads `git tag -l 'slice/*'` and refuses to pass without + # tags, because a test that finds nothing to check is indistinguishable from one that + # found everything in order. The default depth of one fetches no tags. + fetch-depth: 0 - uses: erlef/setup-beam@54075bcc5e249e4758d363f27d099f55d843f124 # v1.24.1 with: diff --git a/CHANGELOG.md b/CHANGELOG.md index 5ec5ad2..857b44d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -22,8 +22,55 @@ evidence for each increment is retained by the maintainers and summarised here. tree, engineering rules consolidated into `docs/03-conventions.md`, and this changelog added as the public record of delivered work. +## 2026-09-24 + +### `slice/090.1` — Observability and the cost ledger +Every LLM call, tool call, approval, session transition, gateway message and budget refusal emits a +`:telemetry` event from a single catalogue (`docs/telemetry.md`), written before the emitters rather +than documented after them, under one rule over the whole set: no prompt text, no completion text, +no tool arguments and no key material. A turn carries a trace identifier into the task that runs it, +so a turn reads as a tree without a tracing library and without a new dependency. A primary Logger +filter redacts credentials by shape rather than by name, so a secret nobody thought to list is still +caught, and it rewrites a message rather than dropping it. The cost ledger reads the usage rows the +tree already writes, by day, model, session and persona, against budgets that warn and, when +configured to, refuse. `/activity` shows the live event stream with the spend beside it, and a +LiveDashboard page lists running sessions by asking each process its state rather than reading a row. +OpenTelemetry was assessed and deferred against a measured need rather than added because the +criterion named it; the reason is recorded with the slice. + +**Tagged `slice/090.1`, not `slice/090`.** The `slice/090` tag was pushed before its merge had +landed and points at slice 080's merge commit. This repository's ruleset forbids moving or deleting +a tag, so the error is permanent and public; the correct tag carries the correction in its own +annotation rather than leaving a reader to reconcile the two. + +### `slice/080` — Subagents and delegation +The assistant can hand a bounded piece of work to a child session through a `delegate` tool. The +child has its own context and its own history, and hands back a result as text: the parent's +conversation never contains the child's messages, which is the property that makes delegation worth +having. Several children run at once under a concurrency cap, each with a budget in turns, tokens +and wall clock; exceeding it stops the child and says so. A child that dies does not take its parent +with it, and the parent is told; cancelling a parent cancels the tree beneath it. Approvals a child +raises appear on the same permissions page as any other, named with the child that raised them, and +a `/subagents` panel shows what is running with a stop control for each. + ## 2026-09-23 +### `slice/025` — Encryption at rest, and the key-custody seam +The database, the receipt chain and the key material can be sealed at rest, and the seam that holds +the keys is named rather than assumed. Sealing is a deployment decision with the trade-off stated in +both directions: a key lost is data lost, so the custody options are documented with their recovery +paths, and the default is the one whose failure mode an operator can survive. What the seam does +*not* cover is written down beside what it does. + +### `slice/002` — Supply chain, early +A CycloneDX bill of materials is generated by the quality gate on every commit and ships beside +every packaged binary, so whoever holds an artifact holds the list of what is in it; the bill states +its own coverage inside the document, including what it does not cover. Every packaged binary +carries build provenance attested through the workflow's own identity and recorded in a public +transparency log, verified in the same run that produced it. A minimum TLS version is enforced for +outbound connections. Brought forward from M9 because a supply-chain claim made late is a claim +made about work already done. + ### `slice/070` — Gateway core Trinity becomes reachable from channels other than the desktop. An adapter behaviour carries text and nothing else; a router admits the sender, applies a rate limit, dispatches commands and binds diff --git a/test/changelog_test.exs b/test/changelog_test.exs new file mode 100644 index 0000000..439e188 --- /dev/null +++ b/test/changelog_test.exs @@ -0,0 +1,48 @@ +# SPDX-FileCopyrightText: Sudo Apt Holdings LLC +# SPDX-License-Identifier: Apache-2.0 +defmodule ChangelogTest do + @moduledoc """ + `CHANGELOG.md` says of itself that it "is derived from the tags themselves + (`git tag -l 'slice/*'`), not written from memory". This test is what makes that sentence true. + + It was not true when the test was written. Two tags, `slice/002` and `slice/025`, had no entry: + both were merged on a day when two other things were also merged, and both were simply missed. + Nothing failed, because nothing was checking. A public record of delivered work that is quietly + incomplete is worse than one that admits a gap, because a reader has no way to tell which kind + they are holding. + + **Why the empty case is a failure rather than a skip.** A checkout without tags - `actions/checkout` + at its default depth of one - can run this test and find nothing to check, and a test that passes + because it had nothing to look at is indistinguishable from one that passed because the tree was + right. Every CI leg that runs the suite therefore checks out with `fetch-depth: 0`, and this test + refuses to pass without tags rather than quietly agreeing. + + The direction is deliberate: every tag must have an entry, and an entry with no tag is fine. A + slice's entry is written in the pull request that closes it, which lands before the tag exists. + """ + use ExUnit.Case, async: true + + @changelog "CHANGELOG.md" + + defp tags do + {out, 0} = System.cmd("git", ["tag", "-l", "slice/*"]) + out |> String.split("\n", trim: true) |> Enum.sort() + end + + test "the checkout has the tags this test reads" do + assert tags() != [], + "`git tag -l 'slice/*'` found nothing, so this test cannot check anything. A CI job " <> + "running the suite must check out with `fetch-depth: 0`; a local clone has the tags " <> + "already. Passing here without tags would be a pass that measured nothing" + end + + test "every slice tag has an entry in the changelog" do + text = File.read!(@changelog) + + missing = Enum.reject(tags(), &String.contains?(text, "`#{&1}`")) + + assert missing == [], + "#{@changelog} has no entry for #{Enum.join(missing, ", ")}. The file states it is " <> + "derived from the tags; add the entry rather than the exception" + end +end From a31f51e7a6409cc00c70171474db79e9cb2fb4cb Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Thu, 24 Sep 2026 09:22:49 -0400 Subject: [PATCH 11/11] docs: no em dashes in the README's new prose The project's writing rule for anything published is colons and commas rather than em dashes, and the three sentences added for slices 080 and 090 broke it. The README now has none at all. The changelog's entry headings keep theirs. Every one of its twenty-odd headings is written that way and has been since the file was created; changing three of them to match a prose rule would make the file inconsistent with itself, which is the opposite of what the rule is for. Signed-off-by: Ayla Croft --- README.md | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/README.md b/README.md index eb0682c..3b23fb7 100644 --- a/README.md +++ b/README.md @@ -42,7 +42,7 @@ Pre-alpha, and usable from source. Milestones M0 to M4 are approved, **M5a Autom authorization), **M5b Reaches** in part (070, the gateway core; 080, subagents) and the first slice of **M6 Ships** (090, observability and the cost ledger), with 002 (the supply chain slice) beside them: 29 slices, each merged with a merge commit and tagged `slice/NNN` -(`git tag -l 'slice/*' | wc -l` → 30, on 2026-09-24 — one more tag than slices, because +(`git tag -l 'slice/*' | wc -l` → 30, on 2026-09-24: one more tag than slices, because `slice/090` was pushed at the wrong commit before its merge landed and this repository's ruleset forbids moving or deleting a tag; the correct one is `slice/090.1`, and `git tag -n20 slice/090.1` says so in its own annotation rather than leaving a reader to work it out). What that means in @@ -116,8 +116,8 @@ enforces it. refusal is receipted. The console adapter ships (`mix trinity.console`); the platforms are next. - **Delegates.** The assistant can hand a bounded piece of work to a child session with a `delegate` tool: its own context, its own history, and a result handed back as text. The - parent's conversation never contains the child's messages, which is the point — delegation - that leaks the child's transcript back into the parent buys nothing. Several children run at + parent's conversation never contains the child's messages, which is the point: + delegation that leaks the child's transcript back into the parent buys nothing. Several children run at once under a cap, each with a budget in turns, tokens and wall clock; exceeding it stops the child and says so. A child dies without taking its parent with it, and the parent is told; cancelling a parent cancels the tree beneath it. Approvals a child raises surface on the same @@ -128,8 +128,8 @@ enforces it. emitters rather than after them, with one rule over the whole set: no prompt text, no completion text, no tool arguments, no key material. A turn carries a trace id down into the task that runs it, so a turn reads as a tree without a tracing library or a new dependency. A primary Logger - filter redacts credentials by **shape** — bearer and basic headers, `sk-` and `pk-` prefixed - keys, JWTs — so a secret nobody thought to name is still caught, and the filter never drops a + filter redacts credentials by **shape** (bearer and basic headers, `sk-` and `pk-` prefixed + keys, JWTs), so a secret nobody thought to name is still caught, and the filter never drops a message, only rewrites it. The cost ledger reads the usage rows the tree already writes: by day, by model, by session, by persona, against budgets that warn and, when you ask them to, refuse. `/activity` shows the live stream with the spend beside it; a LiveDashboard page lists the