From 6469fcd018db6edee8c766e0bf1282a3977fd3c2 Mon Sep 17 00:00:00 2001 From: Ashish Date: Wed, 15 Jul 2026 12:58:30 -0700 Subject: [PATCH] feat(transforms): language-aware stack-trace collapse for Go/Rust/.NET/Java/Node (#1791) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Description Stack-trace handling covered only Python tracebacks and a generic ` at symbol(` pattern. Go panics and Rust panics flowed to prose compression; .NET traces were unrecognized; Java chained exceptions split into separate traces at every `Caused by:` (so later chain heads fell off the `max_stack_traces` cliff); and oversized traces were blindly head-truncated — keeping runtime scheduler noise while dropping the app frames and chain heads an agent actually needs. This PR adds language-aware trace flavors (Go, Rust, .NET, Java chains, Node async) to the Rust core and both Python mirrors, and replaces blind truncation with a runtime-frame collapse: message lines, chain heads, the trace head, and app-code frames survive; contiguous runtime/stdlib frames fold into `[... N frames collapsed]` markers. A 147-line Go panic dump compresses to 19 lines with the panic message, signal line, and app frame intact. Note one intentional behavior change: now that Go/Rust panics are *detected*, panics ≤8KB in tool outputs gain the existing error-output protection (`protect_error_outputs`) they previously missed — small panics stay verbatim, exactly like small Python tracebacks already do. ## Type of Change - [x] New feature (non-breaking change which adds functionality) - [ ] Bug fix (non-breaking change which fixes an issue) - [ ] Breaking change (fix or feature that would cause existing functionality to not work as expected) - [ ] Documentation update - [ ] Performance improvement - [ ] Code refactoring ## Changes Made - `crates/headroom-core/src/transforms/log_compressor.rs`: - New `TraceFlavor::GoPanic` (`panic:` / `fatal error:` / `goroutine N [state]:` openers, tab-indented `.go:` frame lines, `created by` / call-line continuation, blank-separated goroutine blocks) and `TraceFlavor::DotNet` (`Unhandled exception.`, `at … ) in file:line N` frames — checked before Java since those frames also satisfy the Java shape — plus `--->` inner-exception heads and `--- End of` separators). - Renamed the misnamed `Go` flavor to `RustBacktrace` (its `is_go_frame` matched `N: 0x` — the Rust backtrace shape) and gave it real openers (`thread '…' panicked at`, `stack backtrace:`); the free-text panic-message line after the opener stays in the trace (`terminates` now receives `lines_so_far`). - Java: continues across `Caused by:` / `Suppressed:` / `... N more`, and `is_java_at_frame` admits `/` so JPMS module frames (`at java.base/…`) pass the opener re-check — without this, modern JDK traces fragmented at the parse cap into ≤20-line groups. - Frame collapse (`collapse_trace_frames`): for traces over `stack_trace_max_lines`, keeps message/chain-head lines, first `trace_head_frames` frames, up to `trace_app_frames` app frames; runtime frames (prefix + path marker tables per language) fold into `[... N frames collapsed]` markers that occupy the run's first line slot and carry score 0.8 so the global cap doesn't drop them first. Collapsed frame indices are excluded from the context-line pass (otherwise ±3 context re-added them), and the parse cap re-opens on continuation lines so selection sees one contiguous trace. New config: `collapse_runtime_frames=true`, `trace_head_frames=3`, `trace_app_frames=5`; new sidecar stat `runtime_frames_collapsed`. - `crates/headroom-py/src/lib.rs`: the three new knobs on the `LogCompressorConfig` PyO3 signature. - `headroom/transforms/log_compressor.py`: dataclass fields + constructor pass-through; `_parse_lines` opener patterns mirrored per the documented contract. - `headroom/transforms/content_detector.py`: `_LOG_PATTERNS` additions (Go panic/goroutine/frame lines, Rust panic/backtrace/numbered frames, .NET, Java chain heads, Node `at async`); JS/Java `at` pattern admits JPMS module paths. - `tests/test_transforms_stack_traces.py` (new, 10 tests) + 7 new Rust unit tests (flavor open/continue/terminate, chain grouping, collapse keeps chain heads/app frames, collapse-off comparison, small traces untouched). ## Testing - [x] Added new tests for the changes - [x] All existing tests pass ### Test Output ``` $ cargo test -p headroom-core 928 passed; 3 ignored $ python -m pytest tests/test_transforms_stack_traces.py tests/test_log_compressor.py \ tests/test_transforms_log_compressor.py tests/test_transforms_content_detection.py \ tests/test_transforms_content_router.py tests/test_transforms/test_content_router.py \ tests/test_lossless_mode.py tests/test_compression_fidelity_regression.py -q 191 passed ``` ## Real Behavior Proof - Environment: macOS arm64, Python 3.13, repo main @ e8151f05, `headroom._core` rebuilt via scripts/build_rust_extension.sh - Exact command / steps: fed a 147-line Go panic + 24-goroutine dump and a 66-line Java chained exception through `LogCompressor(LogCompressorConfig(enable_ccr=False)).compress(...)` - Observed result: Go dump 147 → 19 lines with `panic: runtime error…`, `[signal SIGSEGV…]`, and the `main.handler` app frame kept, scheduler frames as `[... 4 frames collapsed]` per goroutine; Java output keeps `Caused by: java.io.IOException`, `com.example.Disk.read`, and `... 17 more` — all three were lost under blind truncation (verified by the collapse-off comparison test) - Not tested: Windows; PHP/Ruby traces (out of scope); interplay with Kompress relevance-split on mixed log+trace payloads beyond the existing suite ## Review Readiness - [x] I have performed a self-review - [x] This PR is ready for human review Co-authored-by: Claude Fable 5 --- .../src/transforms/log_compressor.rs | 528 +++++++++++++++++- crates/headroom-py/src/lib.rs | 9 + headroom/transforms/content_detector.py | 14 +- headroom/transforms/log_compressor.py | 24 + tests/test_transforms_stack_traces.py | 180 ++++++ 5 files changed, 740 insertions(+), 15 deletions(-) create mode 100644 tests/test_transforms_stack_traces.py diff --git a/crates/headroom-core/src/transforms/log_compressor.rs b/crates/headroom-core/src/transforms/log_compressor.rs index 4ad8c9f15..ebcddfd51 100644 --- a/crates/headroom-core/src/transforms/log_compressor.rs +++ b/crates/headroom-core/src/transforms/log_compressor.rs @@ -168,6 +168,14 @@ pub struct LogCompressorConfig { /// Compression ratio threshold for CCR storage. Python defaults to /// 0.5 inline; promoted to a config field here. pub min_compression_ratio_for_ccr: f64, + /// When a trace exceeds `stack_trace_max_lines`, collapse runtime/stdlib + /// frames into a `[... N runtime frames collapsed]` marker instead of + /// blindly truncating the tail (which drops app frames and chain heads). + pub collapse_runtime_frames: bool, + /// First N frames always kept when collapsing (top of the trace). + pub trace_head_frames: usize, + /// App-code (non-runtime) frames kept beyond the head when collapsing. + pub trace_app_frames: usize, } impl Default for LogCompressorConfig { @@ -186,6 +194,9 @@ impl Default for LogCompressorConfig { enable_ccr: true, min_lines_for_ccr: 50, min_compression_ratio_for_ccr: 0.5, + collapse_runtime_frames: true, + trace_head_frames: 3, + trace_app_frames: 5, } } } @@ -222,6 +233,7 @@ pub struct LogCompressorStats { pub stack_traces_kept: usize, pub warnings_dropped_by_dedupe: usize, pub lines_dropped_by_global_cap: usize, + pub runtime_frames_collapsed: usize, pub ccr_emitted: bool, pub ccr_skip_reason: Option<&'static str>, } @@ -404,7 +416,13 @@ enum TraceFlavor { Js, Java, RustError, - Go, + /// Rust panic + `RUST_BACKTRACE` dump. Frames are `N: 0x` / + /// `N: ` lines. (Previously misnamed `Go`, whose real panic + /// shape — `goroutine N [state]:` + tab-indented `.go:` frames — is + /// `GoPanic` below.) + RustBacktrace, + GoPanic, + DotNet, } impl StackTraceDetector { @@ -414,14 +432,23 @@ impl StackTraceDetector { || Self::is_python_file_frame(trimmed) { Some(TraceFlavor::PythonTraceback) + } else if Self::is_dotnet_opener(trimmed) { + // Before Js/Java: a .NET `at Ns.Class.Method(...) in File.cs:line N` + // frame also satisfies the Java `at (` shape. + Some(TraceFlavor::DotNet) } else if Self::is_js_at_frame(trimmed) { Some(TraceFlavor::Js) } else if Self::is_java_at_frame(trimmed) { Some(TraceFlavor::Java) } else if trimmed.starts_with("--> ") && Self::has_line_col_suffix(trimmed) { Some(TraceFlavor::RustError) - } else if Self::is_go_frame(line) { - Some(TraceFlavor::Go) + } else if Self::is_rust_panic_opener(trimmed) + || trimmed.starts_with("stack backtrace:") + || Self::is_rust_backtrace_frame(line) + { + Some(TraceFlavor::RustBacktrace) + } else if Self::is_go_panic_opener(line) { + Some(TraceFlavor::GoPanic) } else { None } @@ -440,13 +467,17 @@ impl StackTraceDetector { } fn is_java_at_frame(s: &str) -> bool { - // Pattern: `at (` + // Pattern: `at (`. `/` admits JPMS module + // prefixes (`at java.base/java.util.Optional.get(...)`) and lambda + // frames (`$$Lambda$17/0x...`) — without it, modern JDK frames fail + // the opener re-check at the parse cap and one trace fragments into + // several groups. if !s.starts_with("at ") || !s.contains('(') { return false; } let body = &s[3..s.find('(').unwrap_or(s.len())]; body.chars() - .all(|c| c.is_ascii_alphanumeric() || matches!(c, '.' | '_' | '$')) + .all(|c| c.is_ascii_alphanumeric() || matches!(c, '.' | '_' | '$' | '/')) && !body.is_empty() } @@ -474,7 +505,68 @@ impl StackTraceDetector { false } - fn is_go_frame(s: &str) -> bool { + fn is_rust_panic_opener(s: &str) -> bool { + // Pattern: `thread '' panicked at ` (any rustc era). + s.starts_with("thread '") && s.contains("panicked at") + } + + fn is_go_panic_opener(line: &str) -> bool { + // `panic: ` / `fatal error: ` (column 0) or a goroutine + // header `goroutine []:`. + if line.starts_with("panic: ") || line.starts_with("fatal error: ") { + return true; + } + Self::is_goroutine_header(line) + } + + fn is_goroutine_header(line: &str) -> bool { + let Some(rest) = line.strip_prefix("goroutine ") else { + return false; + }; + let digits = rest.bytes().take_while(u8::is_ascii_digit).count(); + digits > 0 && rest[digits..].starts_with(" [") + } + + fn is_go_file_frame(line: &str) -> bool { + // Tab-indented `.go: +0x` (the second line of each + // goroutine frame pair). + let Some(rest) = line.strip_prefix('\t') else { + return false; + }; + rest.contains(".go:") && rest.contains(" +0x") + } + + fn is_go_call_frame(line: &str) -> bool { + // `pkg.func(...)` / `created by pkg.func` call lines inside a + // goroutine block (column 0, dotted symbol). + if line.starts_with("created by ") { + return true; + } + if line.starts_with([' ', '\t']) || !line.ends_with(')') { + return false; + } + let Some(open) = line.find('(') else { + return false; + }; + let symbol = &line[..open]; + !symbol.is_empty() + && symbol.contains('.') + && symbol + .chars() + .all(|c| c.is_ascii_alphanumeric() || matches!(c, '.' | '_' | '/' | '*')) + } + + fn is_dotnet_opener(s: &str) -> bool { + s.starts_with("Unhandled exception.") || Self::is_dotnet_frame(s) + } + + fn is_dotnet_frame(s: &str) -> bool { + // Pattern: `at () in :line ` — the ` in … :line` + // suffix is what distinguishes .NET from Java frames. + s.starts_with("at ") && s.contains(") in ") && s.contains(":line ") + } + + fn is_rust_backtrace_frame(s: &str) -> bool { // Pattern: `:0x` let trimmed = s.trim_start(); let mut chars = trimmed.chars().peekable(); @@ -503,7 +595,10 @@ impl StackTraceDetector { } /// True if `line` should end the current trace flavor's run. - fn terminates(flavor: TraceFlavor, line: &str) -> bool { + /// `lines_so_far` is how many lines the active trace has already + /// claimed (1 = only the opener) — RustBacktrace uses it to keep the + /// free-text panic-message line that follows `panicked at :`. + fn terminates(flavor: TraceFlavor, line: &str, lines_so_far: usize) -> bool { let trimmed = line.trim_start(); match flavor { TraceFlavor::PythonTraceback => { @@ -524,16 +619,230 @@ impl StackTraceDetector { !trimmed.starts_with(char::is_uppercase) } } - TraceFlavor::Js | TraceFlavor::Java => { + TraceFlavor::Js => { // Terminate on the first non-`at` line. !trimmed.starts_with("at ") && !line.is_empty() } + TraceFlavor::Java => { + // Continue across `Caused by:` / `Suppressed:` chain heads and + // the `... N more` frame-elision summary — terminating there + // split one chained exception into several traces, and the + // later chain heads got dropped under `max_stack_traces`. + let is_chain = trimmed.starts_with("Caused by:") + || trimmed.starts_with("Suppressed:") + || Self::is_java_more_summary(trimmed); + !trimmed.starts_with("at ") && !is_chain && !line.is_empty() + } + TraceFlavor::DotNet => { + // Continue across frames, inner-exception heads (`--->`), + // separator lines (`--- End of inner exception stack trace`, + // `--- End of stack trace from previous location`), and + // exception-type message lines. + if line.is_empty() { + return false; + } + let continues = trimmed.starts_with("at ") + || trimmed.starts_with("--->") + || trimmed.starts_with("--- End of") + || Self::is_dotnet_exception_head(trimmed); + !continues + } TraceFlavor::RustError => !trimmed.starts_with("--> ") && !line.is_empty(), - TraceFlavor::Go => { - !trimmed.chars().next().is_some_and(|c| c.is_ascii_digit()) && !line.is_empty() + TraceFlavor::RustBacktrace => { + if line.is_empty() || lines_so_far == 1 { + // The panic message is the unindented free-text line right + // after the `panicked at :` opener — keep it. + return false; + } + let is_frame = trimmed.chars().next().is_some_and(|c| c.is_ascii_digit()); + let is_continuation = line.starts_with([' ', '\t']) + || trimmed.starts_with("stack backtrace:") + || trimmed.starts_with("note: run with"); + !is_frame && !is_continuation + } + TraceFlavor::GoPanic => { + // A goroutine dump is blocks of `goroutine N [state]:` headers, + // `pkg.func(...)` call lines, and tab-indented `.go:` file + // lines, separated by blank lines. Signal lines (`[signal + // SIGSEGV...]`) and chained `panic:` lines continue it. + if line.is_empty() { + return false; + } + let continues = line.starts_with('\t') + || Self::is_goroutine_header(line) + || Self::is_go_call_frame(line) + || line.starts_with("panic: ") + || line.starts_with("fatal error: ") + || line.starts_with("[signal "); + !continues } } } + + fn is_dotnet_exception_head(trimmed: &str) -> bool { + // `System.InvalidOperationException: message` (dotted type ending in + // Exception, then a colon). + let Some(colon) = trimmed.find(':') else { + return false; + }; + let head = &trimmed[..colon]; + head.ends_with("Exception") + && head.contains('.') + && head + .chars() + .all(|c| c.is_ascii_alphanumeric() || matches!(c, '.' | '_' | '`' | '+')) + } + + fn is_java_more_summary(trimmed: &str) -> bool { + // `... 17 more` + let Some(rest) = trimmed.strip_prefix("... ") else { + return false; + }; + let digits = rest.bytes().take_while(u8::is_ascii_digit).count(); + digits > 0 && rest[digits..].trim() == "more" + } +} + +// ─── Frame-collapse pass ─────────────────────────────────────────────── + +/// Result of collapsing runtime frames in an oversized stack trace. +struct CollapsedTrace { + kept: Vec, + /// Original line numbers of the dropped frames — excluded from the + /// context-line pass so they don't ride back in as neighbors. + dropped_indices: Vec, +} + +/// True if `line` is a stack FRAME (vs. an exception message / chain head). +fn is_frame_line(line: &str) -> bool { + let trimmed = line.trim_start(); + trimmed.starts_with("at ") + || (trimmed.starts_with("File \"") && trimmed.contains("\", line ")) + || StackTraceDetector::is_rust_backtrace_frame(line) + || StackTraceDetector::is_go_file_frame(line) + || StackTraceDetector::is_go_call_frame(line) +} + +/// Chain heads and inter-trace markers that must always survive a collapse. +fn is_chain_head_line(line: &str) -> bool { + let trimmed = line.trim_start(); + trimmed.starts_with("Caused by:") + || trimmed.starts_with("Suppressed:") + || trimmed.starts_with("... ") + || trimmed.starts_with("--->") + || trimmed.starts_with("--- End of") + || trimmed.starts_with("During handling") + || trimmed.starts_with("The above exception") +} + +/// Runtime/stdlib frame markers, split by match mode: `starts_with` on the +/// trimmed line vs. `contains` anywhere (paths and dotted symbols). +const RUNTIME_FRAME_PREFIXES: &[&str] = &[ + "at java.", + "at jdk.", + "at sun.", + "at javax.", + "at scala.", + "at System.", + "at Microsoft.", + "runtime.", + "created by runtime.", +]; +const RUNTIME_FRAME_MARKERS: &[&str] = &[ + "site-packages/", + "/usr/lib/python", + "lib/python3.", + "node:internal/", + "node_modules/", + "(internal/", + "core::", + "std::", + "alloc::", + "rust_begin_unwind", + "__rust_", + "/rustc/", + "/usr/local/go/src/", + "/libexec/src/runtime/", +]; + +fn is_runtime_frame(line: &str) -> bool { + let trimmed = line.trim_start(); + RUNTIME_FRAME_PREFIXES + .iter() + .any(|p| trimmed.starts_with(p)) + || RUNTIME_FRAME_MARKERS.iter().any(|m| line.contains(m)) +} + +/// Collapse runtime frames in an oversized trace: keep every message / +/// chain-head line, the first `head_frames` frames, and up to `app_frames` +/// app-code frames; each contiguous dropped run becomes one +/// `[... N frames collapsed]` marker occupying the run's first line slot. +/// Indented continuations of a dropped frame (Python source echo) drop +/// with it. +fn collapse_trace_frames( + stack: &[LogLine], + head_frames: usize, + app_frames: usize, +) -> CollapsedTrace { + let mut kept: Vec = Vec::with_capacity(stack.len().min(64)); + let mut dropped_indices: Vec = Vec::new(); + let mut frames_seen = 0usize; + let mut app_kept = 0usize; + let mut run_start: Option = None; + let mut run_len = 0usize; + let mut prev_dropped = false; + + fn flush_run(kept: &mut Vec, run_start: &mut Option, run_len: &mut usize) { + if let Some(ln) = run_start.take() { + let mut marker = LogLine::new(ln, format!(" [... {run_len} frames collapsed]")); + // Survive the score-ranked global cap: the marker stands in for + // many lines and must not be the first thing dropped. + marker.score = 0.8; + marker.is_stack_trace = true; + kept.push(marker); + *run_len = 0; + } + } + + for line in stack { + if is_frame_line(&line.content) && !is_chain_head_line(&line.content) { + frames_seen += 1; + let runtime = is_runtime_frame(&line.content); + let keep = frames_seen <= head_frames || (!runtime && app_kept < app_frames); + if keep { + if !runtime { + app_kept += 1; + } + flush_run(&mut kept, &mut run_start, &mut run_len); + kept.push(line.clone()); + prev_dropped = false; + } else { + if run_start.is_none() { + run_start = Some(line.line_number); + } + run_len += 1; + dropped_indices.push(line.line_number); + prev_dropped = true; + } + } else if prev_dropped + && line.content.starts_with([' ', '\t']) + && !is_chain_head_line(&line.content) + { + // Indented continuation of a dropped frame (source echo, `at + // ` sub-line already caught as frame above). + run_len += 1; + dropped_indices.push(line.line_number); + } else { + flush_run(&mut kept, &mut run_start, &mut run_len); + kept.push(line.clone()); + prev_dropped = false; + } + } + flush_run(&mut kept, &mut run_start, &mut run_len); + CollapsedTrace { + kept, + dropped_indices, + } } // ─── Summary detector ────────────────────────────────────────────────── @@ -707,8 +1016,9 @@ impl LogCompressor { // `stack_trace_max_lines`. if let Some(flavor) = active { if trace_lines >= self.config.stack_trace_max_lines - || StackTraceDetector::terminates(flavor, line) + || StackTraceDetector::terminates(flavor, line, trace_lines) { + let cap_hit = trace_lines >= self.config.stack_trace_max_lines; active = None; trace_lines = 0; // Re-check the current line against opener — chained @@ -718,6 +1028,17 @@ impl LogCompressor { active = Some(new_flavor); trace_lines = 1; entry.is_stack_trace = true; + } else if cap_hit && !StackTraceDetector::terminates(flavor, line, 2) { + // Cap hit mid-trace on a line that is not an opener + // by itself but still continues the active flavor + // (goroutine file frames, Python source echoes, + // blank separators). Keep marking so the selection + // stage sees one contiguous trace and the frame + // collapse — not arbitrary cap alignment — decides + // what survives. + active = Some(flavor); + trace_lines = 1; + entry.is_stack_trace = true; } } else { entry.is_stack_trace = true; @@ -803,10 +1124,30 @@ impl LogCompressor { selected.insert(line); } + let mut collapsed_frame_indices: BTreeSet = BTreeSet::new(); for stack in stack_traces.iter().take(self.config.max_stack_traces) { stats.stack_traces_kept += 1; - for line in stack.iter().take(self.config.stack_trace_max_lines) { - selected.insert(line.clone()); + if self.config.collapse_runtime_frames + && stack.len() > self.config.stack_trace_max_lines + { + let collapsed = collapse_trace_frames( + stack, + self.config.trace_head_frames, + self.config.trace_app_frames, + ); + stats.runtime_frames_collapsed += collapsed.dropped_indices.len(); + collapsed_frame_indices.extend(collapsed.dropped_indices); + for line in collapsed + .kept + .into_iter() + .take(self.config.stack_trace_max_lines) + { + selected.insert(line); + } + } else { + for line in stack.iter().take(self.config.stack_trace_max_lines) { + selected.insert(line.clone()); + } } } @@ -829,7 +1170,12 @@ impl LogCompressor { } } for idx in context_indices { - if !selected_indices.contains(&idx) && idx < log_lines.len() { + // Deliberately-collapsed runtime frames must not ride back in as + // "context" around the kept frames — that would undo the collapse. + if !selected_indices.contains(&idx) + && idx < log_lines.len() + && !collapsed_frame_indices.contains(&idx) + { selected.insert(log_lines[idx].clone()); } } @@ -1292,4 +1638,158 @@ mod tests { // Third slot goes to the high-scoring middle line. assert!(line_nums.contains(&2)); } + + // ─── Language-aware stack-trace flavors ──────────────────────────── + + fn trace_flags(c: &LogCompressor, lines: &[&str]) -> Vec { + c.parse_lines(lines) + .iter() + .map(|l| l.is_stack_trace) + .collect() + } + + #[test] + fn go_panic_and_goroutine_dump_detected() { + let c = cmp(); + let lines = [ + "some build output", + "panic: runtime error: index out of range [3] with length 3", + "", + "goroutine 1 [running]:", + "main.lookup(0x1, 0x2)", + "\t/app/pkg/lookup.go:42 +0x1d", + "main.main()", + "\t/app/main.go:10 +0x20", + "exit status 2", + ]; + let flags = trace_flags(&c, &lines); + assert!(!flags[0]); + // panic opener through both frame pairs are all one trace. + assert!(flags[1..8].iter().all(|&f| f), "flags: {:?}", flags); + assert!(!flags[8]); + } + + #[test] + fn rust_panic_backtrace_detected_with_message_line() { + let c = cmp(); + let lines = [ + "thread 'main' panicked at src/main.rs:5:5:", + "index out of bounds: the len is 3 but the index is 99", + "stack backtrace:", + " 0: rust_begin_unwind", + " at /rustc/abc123/library/std/src/panicking.rs:645:5", + " 1: core::panicking::panic_fmt", + " 2: app::run", + "note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace", + "done", + ]; + let flags = trace_flags(&c, &lines); + // The free-text message line after the opener stays in the trace. + assert!(flags[..8].iter().all(|&f| f), "flags: {:?}", flags); + assert!(!flags[8]); + } + + #[test] + fn dotnet_trace_continues_across_inner_exception() { + let c = cmp(); + let lines = [ + "Unhandled exception. System.InvalidOperationException: outer failed", + " ---> System.ArgumentNullException: inner value was null", + " at App.Data.Load(String path) in /src/App/Data.cs:line 42", + " --- End of inner exception stack trace ---", + " at App.Program.Main(String[] args) in /src/App/Program.cs:line 12", + "Build finished.", + ]; + let flags = trace_flags(&c, &lines); + assert!(flags[..5].iter().all(|&f| f), "flags: {:?}", flags); + assert!(!flags[5]); + } + + #[test] + fn java_chain_continues_across_caused_by() { + let c = cmp(); + let lines = [ + "at com.example.Service.call(Service.java:10)", + "at com.example.Main.run(Main.java:5)", + "Caused by: java.io.IOException: disk gone", + "at com.example.Disk.read(Disk.java:77)", + "... 17 more", + "INFO next request", + ]; + let parsed = c.parse_lines(&lines); + let flags: Vec = parsed.iter().map(|l| l.is_stack_trace).collect(); + assert!(flags[..5].iter().all(|&f| f), "flags: {:?}", flags); + assert!(!flags[5]); + // And selection groups it as ONE trace, not three. + let mut stats = LogCompressorStats::default(); + let _ = c.select_lines(&parsed, 1.0, &mut stats); + assert_eq!(stats.stack_traces_seen, 1); + } + + // ─── Frame collapse ───────────────────────────────────────────────── + + fn java_chained_trace(runtime_frames: usize) -> String { + let mut lines = + vec!["Exception in thread \"main\" java.lang.IllegalStateException: boom".to_string()]; + lines.push("at com.example.App.handle(App.java:10)".into()); + lines.push("at com.example.App.dispatch(App.java:20)".into()); + for i in 0..runtime_frames { + lines.push(format!( + "at java.base/java.util.stream.Op{}.eval(Op{}.java:{})", + i, + i, + i + 1 + )); + } + lines.push("Caused by: java.io.IOException: disk gone".into()); + lines.push("at com.example.Disk.read(Disk.java:77)".into()); + for i in 0..runtime_frames { + lines.push(format!( + "at java.base/java.lang.Thread{}.run(Thread.java:{})", + i, + i + 1 + )); + } + lines.push("... 17 more".into()); + lines.join("\n") + } + + #[test] + fn collapse_keeps_chain_heads_and_app_frames() { + let c = cmp(); + let content = java_chained_trace(30); // 68 lines, way over max of 20 + let (result, stats) = c.compress(&content, 1.0); + assert!(stats.runtime_frames_collapsed > 0); + // The signal lines survive: + assert!(result.compressed.contains("Caused by: java.io.IOException")); + assert!(result.compressed.contains("com.example.Disk.read")); + assert!(result.compressed.contains("... 17 more")); + // Runtime frames collapse behind a marker: + assert!(result.compressed.contains("frames collapsed]")); + // The deep runtime tail is gone (frame 25 of the second run existed + // only past the old 20-line truncation point AND is runtime). + assert!(!result.compressed.contains("Thread25.run")); + } + + #[test] + fn collapse_beats_blind_truncation_on_chain_heads() { + // With collapse disabled, the old head-truncation loses the + // `Caused by:` head buried past max_lines; with it enabled, kept. + let content = java_chained_trace(30); + let mut cfg = LogCompressorConfig::default(); + cfg.collapse_runtime_frames = false; + let (result_off, _) = LogCompressor::new(cfg).compress(&content, 1.0); + assert!(!result_off.compressed.contains("com.example.Disk.read")); + let (result_on, _) = cmp().compress(&content, 1.0); + assert!(result_on.compressed.contains("com.example.Disk.read")); + } + + #[test] + fn small_traces_not_collapsed() { + let c = cmp(); + let content = java_chained_trace(2); // 12 lines, under max of 20 + let (result, stats) = c.compress(&content, 1.0); + assert_eq!(stats.runtime_frames_collapsed, 0); + assert!(!result.compressed.contains("frames collapsed]")); + } } diff --git a/crates/headroom-py/src/lib.rs b/crates/headroom-py/src/lib.rs index 390bbe400..52d9519a5 100644 --- a/crates/headroom-py/src/lib.rs +++ b/crates/headroom-py/src/lib.rs @@ -1346,6 +1346,9 @@ impl PyLogCompressorConfig { enable_ccr = true, min_lines_for_ccr = 50, min_compression_ratio_for_ccr = 0.5, + collapse_runtime_frames = true, + trace_head_frames = 3, + trace_app_frames = 5, ))] #[allow(clippy::too_many_arguments)] fn new( @@ -1362,6 +1365,9 @@ impl PyLogCompressorConfig { enable_ccr: bool, min_lines_for_ccr: usize, min_compression_ratio_for_ccr: f64, + collapse_runtime_frames: bool, + trace_head_frames: usize, + trace_app_frames: usize, ) -> Self { Self { inner: RustLogConfig { @@ -1378,6 +1384,9 @@ impl PyLogCompressorConfig { enable_ccr, min_lines_for_ccr, min_compression_ratio_for_ccr, + collapse_runtime_frames, + trace_head_frames, + trace_app_frames, }, } } diff --git a/headroom/transforms/content_detector.py b/headroom/transforms/content_detector.py index 01412dde0..92783627b 100644 --- a/headroom/transforms/content_detector.py +++ b/headroom/transforms/content_detector.py @@ -137,7 +137,19 @@ _LOG_PATTERNS = [ re.compile(r"^npm ERR!|^yarn error|^cargo error"), # build tools re.compile(r"Traceback \(most recent call last\)"), # Python traceback re.compile(r"^\w*(Error|Exception):"), # Python exception final line - re.compile(r"^\s*at\s+[\w.$]+\("), # JS/Java stack trace + re.compile(r"^\s*at\s+[\w.$/]+\("), # JS/Java stack trace (JPMS module frames incl.) + re.compile(r"^\s*at async \S"), # Node async stack frame (no paren form) + re.compile(r"^(panic|fatal error): "), # Go panic opener + re.compile(r"^goroutine \d+ \["), # Go goroutine dump header + re.compile(r"^\t\S+\.go:\d+ \+0x"), # Go frame file line + re.compile(r"^thread '[^']*' panicked at"), # Rust panic + re.compile(r"^stack backtrace:"), # Rust backtrace header + re.compile(r"^\s+\d+: \S"), # Rust numbered backtrace frame + re.compile(r"^\s+at \S+:\d+:\d+$"), # Rust/JS bare path frame sub-line + re.compile(r"^Unhandled exception\."), # .NET unhandled exception + re.compile(r"^\s*at .+\) in .+:line \d+"), # .NET frame with PDB info + re.compile(r"^Caused by: "), # Java exception chain head + re.compile(r"^\s*\.\.\. \d+ more$"), # Java elided-frames summary ] diff --git a/headroom/transforms/log_compressor.py b/headroom/transforms/log_compressor.py index 78c41b8ad..0fc798876 100644 --- a/headroom/transforms/log_compressor.py +++ b/headroom/transforms/log_compressor.py @@ -109,6 +109,13 @@ class LogCompressorConfig: max_total_lines: int = 100 enable_ccr: bool = True min_lines_for_ccr: int = 50 + # Frame collapse: when a trace exceeds stack_trace_max_lines, keep the + # message/chain-head lines, the first trace_head_frames frames, and up to + # trace_app_frames app-code frames; runtime/stdlib frames collapse into a + # `[... N frames collapsed]` marker instead of blind tail-truncation. + collapse_runtime_frames: bool = True + trace_head_frames: int = 3 + trace_app_frames: int = 5 @dataclass @@ -186,6 +193,9 @@ class LogCompressor: enable_ccr=cfg.enable_ccr, min_lines_for_ccr=cfg.min_lines_for_ccr, min_compression_ratio_for_ccr=0.5, + collapse_runtime_frames=cfg.collapse_runtime_frames, + trace_head_frames=cfg.trace_head_frames, + trace_app_frames=cfg.trace_app_frames, ) ) @@ -252,6 +262,20 @@ class LogCompressor: re.compile(r"^\s+at [\w.$]+\("), re.compile(r"^\s*--> .+:\d+:\d+"), re.compile(r"^\s*\d+:\s+0x[0-9a-f]+"), + # Rust panics (RustBacktrace flavor) + re.compile(r"^thread '[^']*' panicked at"), + re.compile(r"^stack backtrace:"), + re.compile(r"^\s+\d+: \S"), + # Go panics / goroutine dumps (GoPanic flavor) + re.compile(r"^(?:panic|fatal error): "), + re.compile(r"^goroutine \d+ \["), + re.compile(r"^\t\S+\.go:\d+(?: \+0x[0-9a-f]+)?$"), + # .NET (DotNet flavor) + re.compile(r"^Unhandled exception\."), + re.compile(r"^\s*at .+\) in .+:line \d+"), + # Java chained-exception continuations + re.compile(r"^Caused by: "), + re.compile(r"^\s*\.\.\. \d+ more$"), ] summary_patterns = [ re.compile(r"^={3,}"), diff --git a/tests/test_transforms_stack_traces.py b/tests/test_transforms_stack_traces.py new file mode 100644 index 000000000..25dafa02f --- /dev/null +++ b/tests/test_transforms_stack_traces.py @@ -0,0 +1,180 @@ +"""Language-aware stack-trace detection and frame collapse. + +Covers the new trace flavors (Go panics/goroutine dumps, Rust panics with +backtraces, .NET inner-exception chains, Java `Caused by:` continuation) and +the runtime-frame collapse that replaces blind tail truncation for oversized +traces. The Rust unit tests pin the state-machine behavior; these tests pin +the Python-visible surface: content detection, the shim's mirrored patterns, +and end-to-end compression through `LogCompressor`. +""" + +from __future__ import annotations + +import pytest + +from headroom.transforms.content_detector import ContentType, detect_content_type +from headroom.transforms.log_compressor import LogCompressor, LogCompressorConfig + +# Fixtures -------------------------------------------------------------------- + + +def go_panic_dump(goroutines: int = 24) -> str: + lines = [ + "panic: runtime error: invalid memory address or nil pointer dereference", + "", + "[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x4a2b3c]", + "", + "goroutine 1 [running]:", + "main.handler(0xc000010000)", + "\t/app/cmd/server/main.go:42 +0x1d", + ] + for g in range(2, goroutines + 2): + lines += [ + f"goroutine {g} [chan receive]:", + "runtime.gopark(0x0, 0x0, 0x0, 0x0, 0x0)", + "\t/usr/local/go/src/runtime/proc.go:381 +0xd6", + "runtime.chanrecv(0xc00006e0c0, 0x0, 0x1, 0x0)", + "\t/usr/local/go/src/runtime/chan.go:583 +0x49d", + "", + ] + return "\n".join(lines) + + +def rust_panic_backtrace(frames: int = 20) -> str: + lines = [ + "thread 'main' panicked at src/main.rs:5:5:", + "index out of bounds: the len is 3 but the index is 99", + "stack backtrace:", + ] + for i in range(frames): + lines += [ + f" {i}: core::panicking::panic_fmt", + f" at /rustc/abc123/library/core/src/panicking.rs:{i + 1}:5", + ] + lines += [" 20: app::run", " at ./src/main.rs:5:5"] + lines.append("note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace") + return "\n".join(lines) + + +def java_chained_trace(runtime_frames: int = 30) -> str: + lines = ['Exception in thread "main" java.lang.IllegalStateException: boom'] + lines.append("at com.example.App.handle(App.java:10)") + lines.append("at com.example.App.dispatch(App.java:20)") + for i in range(runtime_frames): + lines.append(f"at java.base/java.util.stream.Op{i}.eval(Op{i}.java:{i + 1})") + lines.append("Caused by: java.io.IOException: disk gone") + lines.append("at com.example.Disk.read(Disk.java:77)") + for i in range(runtime_frames): + lines.append(f"at java.base/java.lang.Thread{i}.run(Thread.java:{i + 1})") + lines.append("... 17 more") + return "\n".join(lines) + + +def dotnet_trace() -> str: + return "\n".join( + [ + "Unhandled exception. System.InvalidOperationException: outer failed", + " ---> System.ArgumentNullException: inner value was null", + " at App.Data.Load(String path) in /src/App/Data.cs:line 42", + " --- End of inner exception stack trace ---", + " at App.Program.Main(String[] args) in /src/App/Program.cs:line 12", + ] + ) + + +# Detection ------------------------------------------------------------------- + + +@pytest.mark.parametrize( + "content", + [ + go_panic_dump(), + rust_panic_backtrace(), + java_chained_trace(), + # .NET trace padded with neutral build lines to clear line-count floors + dotnet_trace() + "\n" + "\n".join(f"Restore complete {i}" for i in range(6)), + ], + ids=["go", "rust", "java", "dotnet"], +) +def test_traces_detected_as_build_output(content: str) -> None: + result = detect_content_type(content) + assert result.content_type is ContentType.BUILD_OUTPUT + + +def test_node_async_frames_count_toward_log_detection() -> None: + content = "\n".join( + [ + "Error: connect ECONNREFUSED 127.0.0.1:5432", + " at async Database.connect (/app/src/db.js:14:3)", + " at async Pool.acquire (/app/src/pool.js:88:9)", + " at async handleRequest (/app/src/routes.js:31:5)", + " at async main (/app/src/index.js:5:1)", + ] + + [f"request {i} handled" for i in range(10)] + ) + result = detect_content_type(content) + assert result.content_type is ContentType.BUILD_OUTPUT + + +# Shim pattern mirror ---------------------------------------------------------- + + +def test_parse_lines_marks_new_flavor_openers() -> None: + compressor = LogCompressor() + lines = [ + "panic: boom", + "goroutine 7 [select]:", + "\t/app/main.go:10 +0x20", + "thread 'main' panicked at src/lib.rs:1:1:", + "stack backtrace:", + " 0: rust_begin_unwind", + "Unhandled exception. System.Exception: x", + " at App.Main(String[] a) in /src/P.cs:line 3", + "Caused by: java.io.IOException: y", + " ... 3 more", + "", # blank resets the shim's legacy in-trace latch + "plain line", + ] + parsed = compressor._parse_lines(lines) + flags = [ln.is_stack_trace for ln in parsed] + assert all(flags[:-2]), f"unmarked opener among {flags}" + assert not flags[-1] + + +# End-to-end compression -------------------------------------------------------- + + +def test_go_dump_collapses_runtime_frames_keeps_panic_and_app_frame() -> None: + compressor = LogCompressor(LogCompressorConfig(enable_ccr=False)) + content = go_panic_dump() + result = compressor.compress(content) + assert result.compressed_line_count < result.original_line_count + assert "panic: runtime error" in result.compressed + assert "main.handler" in result.compressed # the app frame + assert "frames collapsed]" in result.compressed + # The runtime scheduler noise does not dominate the output. + assert result.compressed.count("runtime.gopark") <= 2 + + +def test_java_chain_heads_survive_collapse() -> None: + compressor = LogCompressor(LogCompressorConfig(enable_ccr=False, min_lines_for_ccr=10)) + result = compressor.compress(java_chained_trace()) + assert "Caused by: java.io.IOException" in result.compressed + assert "com.example.Disk.read" in result.compressed + assert "... 17 more" in result.compressed + assert "frames collapsed]" in result.compressed + + +def test_collapse_can_be_disabled() -> None: + compressor = LogCompressor(LogCompressorConfig(enable_ccr=False, collapse_runtime_frames=False)) + result = compressor.compress(go_panic_dump()) + assert "frames collapsed]" not in result.compressed + + +def test_collapse_config_plumbs_through() -> None: + # Constructor accepts the new knobs and forwards them to Rust without error. + compressor = LogCompressor( + LogCompressorConfig(trace_head_frames=1, trace_app_frames=2, enable_ccr=False) + ) + result = compressor.compress(go_panic_dump()) + assert result.compressed # smoke: no TypeError from the PyO3 signature