Repository navigation
Slice 090: observability, the cost ledger, and a turn as a trace - #85
Merged
Merged
Conversation
…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 <aylacroft@proton.me>
…tomatic 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 <aylacroft@proton.me>
…d 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 <aylacroft@proton.me>
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 <aylacroft@proton.me>
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 <aylacroft@proton.me>
…tgres 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 <aylacroft@proton.me>
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 <aylacroft@proton.me>
… 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 <aylacroft@proton.me>
…nosis 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 <aylacroft@proton.me>
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 <aylacroft@proton.me>
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 <aylacroft@proton.me>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Trinity now says what it is doing and what it costs.
Measured before building, and it reshaped the slice. The scope assumes telemetry exists across the tree to build dashboards on. There were exactly two
:telemetry.executecall sites in the entire codebase. So most of this is emitting events that did not exist, not consuming events that did. The cost ledger, by contrast, is largely a read: slice 011 already writes ausage_eventsrow per call with the price applied.The catalogue came before the emitters
docs/telemetry.mdwas written first, deliberately. 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. Two tests hold the document and the code together in both directions.Its first rule is that no event carries prompt text, completion text, key material or tool arguments. Handlers are attached by anything in the VM and reach dashboards, logs and exporters — that is the path by which a conversation leaves by a side door. A test passes a secret as a tool argument and asserts it appears in neither the start nor the stop event; another asserts it never reaches the Activity page.
Two decisions for you to accept or veto
AC2's totals moved from
[manual]to[auto]. The criterion asked for totals 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. The totals, the per-persona join, the empty-ledger case and the budget warning are now asserted; the manual queue keeps only the part needing a person, the over-budget banner on screen. A retag toward more proof.AC5's OpenTelemetry dependencies are deferred. The criterion's substance is met: one turn yields a trace with nested spans, and there is a test. It is built on
:telemetry, which the tree already had.Measured on hex.pm today:
opentelemetry_ecto1.2.0 was released 2024-02-06 — 31 months ago, which trips this project's own R11 staleness trigger;opentelemetry_phoenixis 19 months behind. The core is current.The reasoning is about which layer owns what. The events are the durable interface; an exporter is one consumer of them. Building the linkage into the events means a turn is already a tree on every install, including the ones that will never run a collector — and it means adding an exporter later changes no emitter, because the parentage it needs is already in the metadata. That is what makes it the choice that scales rather than the cheap one. The lift condition is recorded: a deployment that runs a collector.
The rest
The ledger is not a telemetry handler. A handler that failed or was detached would silently stop it, and a missing bill is worse than a missing chart. The row is written by the code that made the call; the event is emitted after it, so a raising handler could never cost a write. A test asserts the event's cost and the ledger's total agree.
The compiler refused the obvious ledger implementation and was right:
Trinity.LLMdepends onTrinity, so namingTrinity.LLM.Usageis a cycle. The queries are schemaless against the table, which is the more honest description anyway — and a test reads the table's columns so a rename fails here rather than in a dashboard.An empty ledger returns
0.0, notnil(nil 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.The redaction filter's own tests state what it does not catch. A filter trusted beyond its reach is worse than none: it turns "we mask secrets" into a belief rather than a mechanism.
The LiveDashboard routes are now compiled in test too. They were dev-only by
compile_env, which meant the custom page had no test and no way to be screenshotted. A route that exists only in the environment nothing tests is a route that breaks quietly.Evidence
mix gateexit 0; 676 passed, 18 excluded; coverage 80.31%. 31 tests in the slice. Both screenshots in the slice'sproof/; the manual queue is complete.