feat: surface backend tracing logs to the frontend via stderr by wolfv · Pull Request #6312 · prefix-dev/pixi

wolfv · 2026-06-09T10:57:33Z

Description

This PR implements structured logging that allows the backend to emit tracing events as JSON-formatted log records that the frontend can parse and re-emit through its own tracing subscriber. This enables backend logs to be interleaved with frontend logs while maintaining full structured information.

Key changes:

New pixi_build_types::log module - Defines the wire format for structured logs:
- BackendLogRecord: A serializable struct containing level, target, message, fields, timestamp, and span information
- BACKEND_LOG_SENTINEL: A sentinel prefix (\u{1f}pixi-log\u{1f}) that marks stderr lines as structured records
- Environment variable BACKEND_LOG_FORMAT_ENV that the frontend uses to signal the backend to emit JSON logs
New JsonLogLayer in backend - A tracing layer that:
- Captures all tracing events and converts them to BackendLogRecord JSON
- Writes records to stderr prefixed with the sentinel and followed by a newline
- Preserves field information, span context, and timestamps
- Uses atomic writes to prevent interleaving with raw stderr output
Enhanced stderr handling in frontend - Modified stream_stderr to:
- Classify each stderr line as either a structured record (if it has the sentinel) or raw output
- Parse sentinel-prefixed lines as BackendLogRecord JSON
- Re-emit parsed records through the frontend's tracing subscriber with target rewritten to pixi_build_backend::<original-target>
- Forward non-sentinel lines to the existing on_log handler unchanged
- Gracefully handle malformed JSON by treating it as raw output
Backend integration - Modified cli.rs to:
- Check for the PIXI_BUILD_BACKEND_LOG_FORMAT=json environment variable
- Use JsonLogLayer when invoked by the frontend, or the human-readable LoggingOutputHandler for standalone invocations
Frontend integration - Modified json_rpc.rs to:
- Set PIXI_BUILD_BACKEND_LOG_FORMAT=json when spawning the backend process

The implementation ensures backward compatibility: raw build output (compiler messages, etc.) continues to flow through unchanged, while structured logs are captured and re-emitted with full context preservation.

How Has This Been Tested?

Added unit tests in pixi_build_frontend/src/backend/stderr.rs covering:
- Raw lines without sentinel are forwarded unchanged
- Sentinel-prefixed lines with valid JSON are parsed as records
- Sentinel-prefixed lines with malformed JSON fall back to raw handling
Added unit tests in pixi_build_types/src/log.rs covering:
- BackendLogRecord round-trips through JSON serialization
- Empty collections are omitted from the wire format

Checklist:

I have performed a self-review of my own code
I have commented my code, particularly in hard-to-understand areas
I have added sufficient tests to cover my changes

https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

The frontend now sets PIXI_BUILD_BACKEND_LOG_FORMAT=json when spawning a build backend. In that mode the backend installs a custom tracing Layer that serializes each event to `{sentinel}{json}\n` on stderr; the frontend's stderr reader recognises the sentinel, parses the envelope into a BackendLogRecord, and re-emits it through the frontend's own tracing subscriber. Untagged lines (raw build output) flow to BackendOutputStream unchanged. Standalone backend invocations keep the pretty LoggingOutputHandler, so interactive debugging is unaffected. https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

baszalmstra · 2026-06-09T11:02:59Z

This is fantastic! The only thing that would be nice to have is if we could properly nest spans! Maybe you can ask clanker to do that? Im not sure how that works internally.

https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

For each BackendLogRecord, open and enter a frontend tracing span per name in record.spans before emitting the event, so the frontend subscriber sees the same hierarchy the backend reported. tracing requires &'static names at every callsite, so we leak one Callsite/Metadata pair per unique span name; the set of names is small and bounded in practice. https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

tdejager · 2026-06-09T11:32:35Z

+    pub(super) fn callsite_for(name: &str) -> &'static DynCallsite {
+        static INTERN: OnceLock<Mutex<HashMap<String, &'static DynCallsite>>> = OnceLock::new();
+        let intern = INTERN.get_or_init(|| Mutex::new(HashMap::new()));
+        let mut guard = intern.lock().expect("dyn_span intern poisoned");
+        if let Some(&cs) = guard.get(name) {
+            return cs;
+        }
+        let leaked_name: &'static str = Box::leak(name.to_owned().into_boxed_str());
+        let cs: &'static DynCallsite = Box::leak(Box::new(DynCallsite {
+            name: leaked_name,
+            metadata: OnceLock::new(),
+        }));
+        // Initialise the metadata before publishing the entry so `Callsite::metadata`
+        // never observes an uninitialised slot.
+        let _ = cs.metadata_ref();
+        guard.insert(name.to_owned(), cs);
+        cs
+    }
+


All iof this code is quite complex and a bit ugly t.b.h :), could we refactor this?

baszalmstra · 2026-06-09T11:32:48Z

This is now the build output:

NFO Running build for:Packaging new files: pixi_build_backend:   ├─ info/about.json (2 B) backend.target=pixi_build_backend::rattler_build_core::packaging backend.fields=
 INFO Running build for:Packaging new files: pixi_build_backend:   ├─ info/hash_input.json (31 B) backend.target=pixi_build_backend::rattler_build_core::packaging backend.fields=
 INFO Running build for:Packaging new files: pixi_build_backend:   ├─ info/index.json (239 B) backend.target=pixi_build_backend::rattler_build_core::packaging backend.fields=
 INFO Running build for:Packaging new files: pixi_build_backend:   ├─ info/paths.json (39 B) backend.target=pixi_build_backend::rattler_build_core::packaging backend.fields=
 INFO Running build for:Packaging new files: pixi_build_backend:   └─ info/tests/tests.yaml (3 B) backend.target=pixi_build_backend::rattler_build_core::packaging backend.fields=
 INFO Running build for:Packaging new files: pixi_build_backend:

I think rattler-build also outputs the build output as logs.

Replace the per-event span name list with a tagged BackendLogRecord enum (Event/SpanOpen/SpanClose). The backend layer now implements on_new_span and on_close in addition to on_event, emitting lifecycle records with stable ids and parent links. The frontend stderr reader maintains a HashMap<u64, Span> mapping backend span ids to real frontend tracing spans created via Span::child_of, so spans live for their actual backend lifetime and events are emitted with the correct parent in scope. The leaked-callsite interner is still required to give the runtime span names a static identity for tracing's dispatcher, but it is now used once per span rather than once per event. https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

wolfv · 2026-06-09T11:35:57Z

Thanks for testing! Indeed, we use the info level logs as the plaintext streaming logs in rattler-build and filter out tracing headers, per usual. I think we should maybe only forward WARNING from the backend this way? Or filter all rattler-build logs?

rattler-build emits its plaintext build-output channel as INFO-level tracing events. Passing those through the structured JSON pipeline turned nicely-rendered output into double-encoded events with field cruft on the frontend. In JSON mode, install LoggingOutputHandler alongside JsonLogLayer with an info-only filter so INFO events still reach the user as formatted text (read by the frontend as untagged stderr), and have JsonLogLayer skip INFO events so they're not also emitted as structured records. Span lifecycle records still flow for all levels so non-INFO events under INFO spans keep their parent context. https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

baszalmstra · 2026-06-09T11:41:02Z

Thanks for testing! Indeed, we use the info level logs as the plaintext streaming logs in rattler-build and filter out tracing headers, per usual. I think we should maybe only forward WARNING from the backend this way? Or filter all rattler-build logs?

What I like is that if we just pass all, we can let default log filtering handle that! Would it be possible to not emit the build logs as tracing logs perhaps?

wolfv · 2026-06-09T15:50:52Z

What I like is that if we just pass all, we can let default log filtering handle that! Would it be possible to not emit the build logs as tracing logs perhaps?

We can filter logs from rattler-build::* crates - or we could implement the tracing -> log logic in pixi (to add the | | | ... and the span headers.

Or we could filter all INFO and below tracing messages and only push back WARN and above.

I didn't fully understand what your preference is?

wolfv changed the title ~~Add structured logging from backend to frontend via stderr~~ feat: surface backend tracing logs to the frontend via stderr Jun 9, 2026

claude added 2 commits June 9, 2026 11:05

style: apply rustfmt to backend log wiring

0278873

https://claude.ai/code/session_01BGkocbCqTAjevABSqYxcWR

tdejager reviewed Jun 9, 2026

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: surface backend tracing logs to the frontend via stderr#6312

feat: surface backend tracing logs to the frontend via stderr#6312
wolfv wants to merge 5 commits into
mainfrom
claude/relaxed-goodall-r7fu7i

wolfv commented Jun 9, 2026

Uh oh!

baszalmstra commented Jun 9, 2026

Uh oh!

tdejager Jun 9, 2026 •

edited

Loading

Uh oh!

baszalmstra commented Jun 9, 2026

Uh oh!

wolfv commented Jun 9, 2026

Uh oh!

baszalmstra commented Jun 9, 2026

Uh oh!

wolfv commented Jun 9, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

Conversation

wolfv commented Jun 9, 2026

Description

How Has This Been Tested?

Checklist:

Uh oh!

baszalmstra commented Jun 9, 2026

Uh oh!

tdejager Jun 9, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

baszalmstra commented Jun 9, 2026

Uh oh!

wolfv commented Jun 9, 2026

Uh oh!

baszalmstra commented Jun 9, 2026

Uh oh!

wolfv commented Jun 9, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

tdejager Jun 9, 2026 •

edited

Loading