Skip to content

feat(logging): structured logging via tracing across all binaries - #11

Open
jakob1379 wants to merge 1 commit into
jamesaphoenix:mainfrom
jakob1379:t3code/add-structured-logging
Open

feat(logging): structured logging via tracing across all binaries#11
jakob1379 wants to merge 1 commit into
jamesaphoenix:mainfrom
jakob1379:t3code/add-structured-logging

Conversation

@jakob1379

@jakob1379 jakob1379 commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

Replaces env_logger with tracing + tracing-subscriber behind a shared logging::init(), so the warnings the desktop UI already displays also reach the terminal.

The bug

emit_activity() only invoked the UI callback, and the CLI's bare env_logger::init() defaulted to error, hiding every existing log:: call site.

Activity now routes through emit_activity_with(), where the callback is a parameter rather than ambient state. Task-locals don't cross tokio::spawn, so the stream collectors captured the callback up front and had diverged from the logging path — in the desktop app, only the two pre-spawn "Launching…" events ever logged.

Configuration

  • RUST_LOG sets the filter (default info). Empty or unparseable falls back to info rather than silencing the process.
  • DIFFCORE_LOG_FORMAT=json switches to line-delimited JSON.
  • Output prefers stderr whenever it is a terminal. The desktop app falls back to ~/.diffcore/desktop.log only when it is not — GUI bundles discard stderr (windows_subsystem = "windows" in release; Finder/.desktop launches drop it). DIFFCORE_LOG_FILE overrides either way.
  • ANSI only on a real terminal, honouring NO_COLOR.
  • Targets: activity (backend events), ir_cache (replacing the bespoke DIFFCORE_CACHE_DEBUG gate), refinement, command.
RUST_LOG=info,activity=warn diffcore analyze --base main   # mute per-event chatter
DIFFCORE_LOG_FORMAT=json diffcore analyze --base main 2> analyze.log.jsonl

Channels that showed the user something but logged nothing

JobHandle::fail, CommandError's IPC serialization (the funnel ~30 tauri commands report failure through), and codex error items — which logged at info as "Completed error" with no detail, and now carry the nested error message at error.

Two pre-existing redact_api_keys bugs

Both became reachable by routing activity messages through redaction:

  • It byte-sliced at 500 bytes while activity messages cap at 180 chars. 183 CJK chars is 549 bytes, so it panicked mid-codepoint. The panic lands inside a tokio::spawned collector, surfacing as a misleading "Failed to join claude stdout task" and discarding the entire buffered LLM response.

  • sk- matched inside ordinary words, and break then skipped real keys later in the same line:

    "Codex is running task-manager build"  -> "Codex is running ta[REDACTED_API_KEY] build"
    "disk-usage high; using sk-abcdef..."  -> unchanged   (real key NOT redacted)
    

Both fixed at the root with regression tests. Note update.payload remains unredacted — it does not reach the logs, only the UI and SSE stream.

Notes

  • tracing-subscriber sits behind a default-off logging feature, so library consumers of diffcore-core don't link the subscriber stack (cargo tree -p diffcore-core -e normal shows zero matches).
  • Existing log:: call sites and dependency logs bridge in via tracing-log. No call site was rewritten.
  • Logs go to stderr, so diffcore analyze | jq still works.

Testing

1706 lib tests plus all integration suites and the tauri web suite pass; nix build is green. The regression test drives the real collect_claude_stream with a callback installed and was verified to fail (empty log output) against the pre-fix code.

Known follow-ups, deliberately out of scope

  • codex_cli.rs drops non-JSON lines, so codex raw stderr produces no activity where claude's produces a WARN. Pre-existing.
  • ~/.diffcore/desktop.log has no rotation once it is used.

Clippy

Measured against the merge-base with a matching toolchain:

errors warnings
baseline 10 107
this branch 7 107

No new findings. The three removed errors are the eprintln! calls in pipeline.rs that violated the crate's own #![deny(clippy::print_stderr)]. CI runs only cargo test --workspace --locked, so those deny attributes were never enforced — adding a clippy job would need the 7 remaining pre-existing errors addressed first, so I have left that out of this PR.

The desktop UI surfaced backend warnings that never reached the terminal:
emit_activity() only invoked the UI callback, and the CLI's bare
env_logger::init() defaulted to `error`, hiding every existing log:: site.

Replace env_logger with tracing + tracing-subscriber behind a shared
logging::init(). RUST_LOG sets the filter (default info; an empty or
unparseable value falls back to info rather than silencing the process),
DIFFCORE_LOG_FORMAT=json switches renderer, and DIFFCORE_LOG_FILE redirects
to a file. Output prefers stderr whenever it is a terminal; the desktop app
falls back to ~/.diffcore/desktop.log only when it is not, since Finder and
.desktop launches discard stderr. ANSI is emitted only to a real terminal and
honours NO_COLOR. Existing log:: call sites and dependency logs bridge in via
tracing-log, so no call site had to be rewritten.

Route activity through emit_activity_with() so the UI callback and the
logging path can no longer diverge; task-locals do not cross tokio::spawn,
so stream collectors pass the callback explicitly.

Close the channels that showed a user something while logging nothing:
JobHandle::fail, CommandError's IPC serialization, codex error items and
unrecognised failure events (which logged at info as "Completed error" with
no detail, and now carry the nested error message).

Redact api keys from activity messages before they reach persistent logs.
Doing so exposed two bugs in redact_api_keys, now fixed: it byte-sliced at
500 bytes while activity messages cap at 180 *chars*, panicking mid-codepoint
on non-ASCII output and killing the whole run via a JoinError; and `sk-`
matched inside ordinary words (task-, risk-, disk-), corrupting them while
`break` skipped real keys later in the same line. Note update.payload is
still unredacted -- it does not reach the logs, only the UI and SSE stream.

Filterable targets: `activity` for backend events, `ir_cache` for the IR
cache (replacing the bespoke DIFFCORE_CACHE_DEBUG env gate), `refinement`
for repair warnings, `command` for IPC errors.

tracing-subscriber sits behind a default-off `logging` feature so library
consumers do not link the subscriber stack.
@jakob1379
jakob1379 force-pushed the t3code/add-structured-logging branch from d16144b to aa551e2 Compare August 28, 2026 11:44
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant