diff --git a/CLAUDE.md b/CLAUDE.md index 9d5d20be5..d183dcc01 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -265,7 +265,16 @@ template the FireWire side. **Instrumentation.** Features and fixes should be traceable, but do not add IO or noisy logging to hot paths. Design instrumentation alongside the feature, suggest the relevant `log stream` command or predicate, and ask the user for runtime state when needed (for example: driver running, audio playing, device connected). Otherwise the trace may prove nothing. Gate hot-path telemetry **anomaly-only once the happy path is confirmed**: keep draining any telemetry ring so it never overflows, but emit a log line only on a real fault (e.g. `[PayloadWriter]` logs only on deficit/withoutPkt/raced/`written != visited`; `[TxPrepRange]` only on `stoppedShort`/`frameShort`), leaving one coarse liveness/margin heartbeat (`[TxPrep]`). A clean run then prints only the heartbeat, and any other line means a regression. -**The agent's Bash sandbox cannot read the unified log.** `log show` / `log stream` return **zero lines silently** under the sandbox (not an error — every predicate looks "empty"), so the agent cannot capture dext logs itself. Confirm the dext is alive with `systemextensionsctl list` (that works), but for the actual trace **hand the user a ready `log stream … | grep -m N … > file` command to run via the `!` prefix**, then read the file. DriverKit dexts have no real os_log categories (`os_log_create` is unavailable — everything is `OS_LOG_DEFAULT` from `kernel`), so the category lives only in the message-text prefix: filter on `eventMessage CONTAINS "[Tag]"`, and pass `--info --debug` or the lines (logged below default level) won't appear. +**Reading the unified log from the agent's Bash sandbox works — call `/usr/bin/log` by absolute path.** The long-standing claim that the sandbox returns "zero lines silently" was a misdiagnosis: **zsh has a `log` builtin that shadows `/usr/bin/log`**, so a bare `log show ...` is swallowed and every predicate looks empty. Spell the path and it behaves normally: +```bash +/usr/bin/log show --last 20m --info --debug --style compact \ + --predicate 'eventMessage CONTAINS "[Audio]"' +``` +Do not ask the user to run traces the agent can capture itself. Two real gotchas remain: +- DriverKit dexts have no os_log categories (`os_log_create` is unavailable — everything is `OS_LOG_DEFAULT`), and they surface as **`process == "kernel"`**, *not* as the dext's process name. Filtering on `process == "net.mrmidi.ASFW.ASFWDriver"` returns nothing even while the driver is logging. The category lives only in the message-text prefix, so filter on `eventMessage CONTAINS "[Tag]"`. +- Pass `--info --debug` or anything below Default level is invisible. `ASFW_LOG`/`ASFW_LOG_DEBUG` mirror at Default (always persisted); `ASFW_LOG_INFO` needs `--info`. + +**A silent dext is evidence, not a tooling failure.** `ASFW_LOG` mirrors to os_log whenever `LogConfig::IsOsLogMirrorEnabled()` (default true), and `LogConfig::Load()` emits a guaranteed `"LogConfig initialized: …"` line on every successful start. Grep for that line per dext instance: if a live, `matched`/`active` service in `ioreg` has no `LogConfig initialized` for its process lifetime, the instance never really came up — do not debug its behaviour, restart it. **Check `/Library/Logs/DiagnosticReports/net.mrmidi.ASFW.ASFWDriver-*.ips` early**; a crashed dext restarts into a degraded instance while `ioreg` still shows its services registered, which makes every downstream symptom (CoreAudio `'what'`, dead volume keys) look like a driver bug in the layer you were working on. **Commit and git history.** Keep history traceable. If changes are getting large, warn the user that it is better to commit the current work first; otherwise unrelated logic shifts can become hard to repair or reason about.