feat(telemetry): record the effects the harness caused itself #891

Merged
coilysiren merged 2 commits from aos/claude/hs68-effect-telemetry into main 2026-08-17 05:21:27 +00:00
Member

Part 1 of #890. The telemetry, not the mirror.

What was missing

$ grep -c "telemetry\.\|StartSpan\|Record" internal/community/workspace.go
0
$ grep -c "telemetry\.\|StartSpan\|Record" internal/community/attachmentingest.go
0

No span, no metric, no log line. So a read-only eco__get_market left a full trace and this service running a process left nothing, which is the wrong way round for an audit record.

Command execution

job.command span, sirens_echo.commands counter.

The verb is the label, the arguments are not. git and exec are this repository's own closed set. An argument is a clone URL or whatever a job kind declared, so it stays out.

Three outcomes rather than a boolean, because an operator reading them wants to know which:

outcome meaning
ok ran, exited zero
exited ran, exited non-zero
did_not_run never started

The exit code goes on the span, not the metric - 0 to 255 is cardinality a closed outcome label does not want. The span also carries duration, the truncation flag, and the job id. Command output reaches none of them, for the same reason it never reaches a member.

Attachment ingest

attachment.fetch span, sirens_echo.attachments counter, and every arm records - including the three that used to continue silently:

refused_host, fetch_failed, refused_binary, write_failed, stored.

Before this, discord.attachment.stored counted the successes at the caller and nothing counted the rest, so a refused upload and no upload at all were the same observation.

The URL never appears. The span carries the byte count and the status code instead, because a CDN path has the member's filename in it. Content does not appear either.

Two exception codes

sirens_echo.command.failed and sirens_echo.attachment.fetch_failed, both faultService, so neither failure is silently unclassified.

While updating the bounds I found docs/sirens-echo-exceptions.md claiming 34 unique types when main already had 36 - stale before this branch, by two, independent of it. Corrected to 38.

The part I deliberately did not do

None of this reaches the Temporal mirror.

The mirror keys off RecordToolCall alone, so a new Record* does not widen what leaves the process. Whether a command verb should be exported to a third-party SaaS is the disclosure decision #887's design says a person makes on purpose, and a command verb is closer to content than mcp.tool.name is.

TestNeitherEffectReachesTheTemporalMirror holds that line, and it asserts a tool call does mirror in the same run - so it cannot pass by simply never delivering anything, which is the way that test would otherwise rot.

That leaves #890's question 2 open and unanswered on purpose. It is a consult question and I have not touched it.

Other tests

  • a succeeding command, a non-zero exit, and a missing binary as three distinct outcomes
  • the runner still works with nil telemetry, which is what every existing caller passes
  • the command timeout still fires, since the new span sits on the context the timeout derives from
  • a refused host is not stored, and a 500 from the CDN is an error rather than a silent skip

just gate passes.

closes #890

Part 1 of #890. The telemetry, not the mirror. ## What was missing ``` $ grep -c "telemetry\.\|StartSpan\|Record" internal/community/workspace.go 0 $ grep -c "telemetry\.\|StartSpan\|Record" internal/community/attachmentingest.go 0 ``` No span, no metric, no log line. So a read-only `eco__get_market` left a full trace and **this service running a process left nothing**, which is the wrong way round for an audit record. ## Command execution `job.command` span, `sirens_echo.commands` counter. **The verb is the label, the arguments are not.** `git` and `exec` are this repository's own closed set. An argument is a clone URL or whatever a job kind declared, so it stays out. Three outcomes rather than a boolean, because an operator reading them wants to know which: | outcome | meaning | | --- | --- | | `ok` | ran, exited zero | | `exited` | ran, exited non-zero | | `did_not_run` | never started | The **exit code goes on the span, not the metric** - 0 to 255 is cardinality a closed outcome label does not want. The span also carries duration, the truncation flag, and the job id. Command output reaches none of them, for the same reason it never reaches a member. ## Attachment ingest `attachment.fetch` span, `sirens_echo.attachments` counter, and **every arm records** - including the three that used to `continue` silently: `refused_host`, `fetch_failed`, `refused_binary`, `write_failed`, `stored`. Before this, `discord.attachment.stored` counted the successes at the caller and nothing counted the rest, so **a refused upload and no upload at all were the same observation.** **The URL never appears.** The span carries the byte count and the status code instead, because a CDN path has the member's filename in it. Content does not appear either. ## Two exception codes `sirens_echo.command.failed` and `sirens_echo.attachment.fetch_failed`, both `faultService`, so neither failure is silently unclassified. While updating the bounds I found `docs/sirens-echo-exceptions.md` claiming **34** unique types when `main` already had 36 - stale before this branch, by two, independent of it. Corrected to 38. ## The part I deliberately did not do **None of this reaches the Temporal mirror.** The mirror keys off `RecordToolCall` alone, so a new `Record*` does not widen what leaves the process. Whether a command verb should be exported to a third-party SaaS is the disclosure decision #887's design says a person makes on purpose, and a command verb is closer to content than `mcp.tool.name` is. `TestNeitherEffectReachesTheTemporalMirror` holds that line, and it asserts a tool call **does** mirror in the same run - so it cannot pass by simply never delivering anything, which is the way that test would otherwise rot. **That leaves #890's question 2 open and unanswered on purpose.** It is a `consult` question and I have not touched it. ## Other tests - a succeeding command, a non-zero exit, and a missing binary as three distinct outcomes - the runner still works with nil telemetry, which is what every existing caller passes - the command timeout still fires, since the new span sits on the context the timeout derives from - a refused host is not stored, and a 500 from the CDN is an error rather than a silent skip `just gate` passes. closes #890
feat(telemetry): record the effects the harness caused itself
Some checks failed
ci / test (pull_request) Failing after 44s
ci / publish-echo-image (pull_request) Has been skipped
ci / publish-observed (pull_request) Has been skipped
ci / image-build (pull_request) Successful in 27s
588f19cee8
A tool call the model made was fully recorded and a command this service ran was
not. workspace.go and attachmentingest.go had no span, no metric, and no log
line between them, so for an audit record the wrong things were visible: a
read-only eco__get_market left a trace and running a process left nothing.

Command execution gets a job.command span and sirens_echo.commands. The verb is
the label, because git and exec are this repository's own closed set. Arguments
are not, because a clone argument is a repository URL. Three outcomes rather
than two: ok, exited, and did_not_run, since a command that failed and one that
never started are different things to look at. The exit code goes on the span
rather than the metric, because 0 to 255 is cardinality a closed label does not
want, and the output reaches neither.

Attachment ingest gets an attachment.fetch span and sirens_echo.attachments,
with every arm recording including the three that used to continue silently. A
refused upload and no upload at all were the same observation before this. The
span carries the byte count and the status code and never the URL, because a CDN
path has the member's filename in it.

Two exception codes, so neither failure is unclassified, and the taxonomy doc's
count was already two stale before this and is now correct.

None of it reaches the Temporal mirror. That keys off RecordToolCall alone, so a
new Record* does not widen what leaves the process, and whether a command verb
should go to a third-party SaaS is the disclosure decision sirens-echo#887 says
a person makes on purpose. A test holds that line and asserts a tool call does
mirror in the same run, so it cannot pass by delivering nothing.

closes #890

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Co-authored-by: Kai Siren <coilysiren@gmail.com>
Co-authored-by: Claude <noreply@anthropic.com>
fix(execution): make the command timeout bound wall clock
All checks were successful
ci / test (pull_request) Successful in 57s
ci / publish-echo-image (pull_request) Has been skipped
ci / publish-observed (pull_request) Has been skipped
ci / image-build (pull_request) Successful in 34s
21a1e108d7
The test written to check the timeout still fired after the telemetry change
caught that it never fired properly. exec.CommandContext kills the direct child
and does not close the pipe, and CombinedOutput waits for every writer to it
including a grandchild that inherited it. A shell that forks rather than execs
outlived its own deadline for as long as the grandchild ran: 30 seconds measured
against a 50 millisecond timeout.

That is why it was invisible. Where sh execs the command the kill works, where
it forks it does not, so CI and a laptop disagreed about the same test.

command.WaitDelay = commandKillGrace bounds the wait after the kill and closes
the pipes. SIRENS_ECHO_COMMAND_KILL_GRACE defaults to 5s and the same test now
finishes in 5.05s rather than 30s.

The orphan is not reaped. This unblocks the harness rather than killing the
process tree, which wants a process group and its own decision, and an orphan on
a workspace that gets removed is a smaller problem than a job that never ends.
Both stated on sirens-echo#892 rather than implied closed.

closes #892

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Co-authored-by: Kai Siren <coilysiren@gmail.com>
Co-authored-by: Claude <noreply@anthropic.com>
Author
Member

Second commit on this branch: the timeout test found a real bug, and it is fixed here rather than left asserting a false property.

CI failed the first push on TestTheCommandTimeoutStillApplies, and it was right to.

exec.CommandContext kills the direct child on expiry. It does not close the pipe, and CombinedOutput waits for every writer to it - including a grandchild that inherited it. So a command whose shell forks outlived its own deadline for as long as the grandchild ran.

Measured with the timeout set to 50 milliseconds:

--- FAIL: TestTheCommandTimeoutStillApplies (30.01s)
    the timeout took 30.012232209s to fire, so it does not bound wall clock

That is why it was invisible. Where sh execs the command the kill works, where it forks it does not, so CI and my laptop disagreed about the same test. ward exec <verb> runs builds and test suites, which spawn children as their whole purpose, so defaultCommandTimeout's 10 minutes was the number a reader would quote and not the number that applied.

command.WaitDelay = commandKillGrace bounds the wait after the kill and closes the pipes. SIRENS_ECHO_COMMAND_KILL_GRACE defaults to 5s, and the same test now finishes in 5.05s rather than 30s.

Not fixed, and said out loud: the orphan is not reaped. This unblocks the harness rather than killing the process tree, which wants a process group and its own decision. Filed with both halves on #892.

I could have relaxed the assertion to get CI green. Leaving a test asserting a bound the code did not have seemed the worse trade.

**Second commit on this branch: the timeout test found a real bug, and it is fixed here rather than left asserting a false property.** CI failed the first push on `TestTheCommandTimeoutStillApplies`, and it was right to. `exec.CommandContext` kills the direct child on expiry. It does not close the pipe, and `CombinedOutput` waits for every writer to it - **including a grandchild that inherited it**. So a command whose shell forks outlived its own deadline for as long as the grandchild ran. Measured with the timeout set to 50 milliseconds: ``` --- FAIL: TestTheCommandTimeoutStillApplies (30.01s) the timeout took 30.012232209s to fire, so it does not bound wall clock ``` **That is why it was invisible.** Where `sh` execs the command the kill works, where it forks it does not, so CI and my laptop disagreed about the same test. `ward exec <verb>` runs builds and test suites, which spawn children as their whole purpose, so `defaultCommandTimeout`'s 10 minutes was the number a reader would quote and not the number that applied. `command.WaitDelay = commandKillGrace` bounds the wait after the kill and closes the pipes. `SIRENS_ECHO_COMMAND_KILL_GRACE` defaults to 5s, and the same test now finishes in **5.05s rather than 30s**. **Not fixed, and said out loud:** the orphan is not reaped. This unblocks the harness rather than killing the process tree, which wants a process group and its own decision. Filed with both halves on #892. I could have relaxed the assertion to get CI green. Leaving a test asserting a bound the code did not have seemed the worse trade.
Sign in to join this conversation.
No reviewers
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
coilyco-gaming/sirens-echo!891
No description provided.