diff --git a/crates/openjd-sessions/src/subprocess.rs b/crates/openjd-sessions/src/subprocess.rs index 79be9729..91c8831d 100644 --- a/crates/openjd-sessions/src/subprocess.rs +++ b/crates/openjd-sessions/src/subprocess.rs @@ -4,6 +4,7 @@ //! Async subprocess execution with real-time message streaming. +use std::borrow::Cow; use std::collections::HashMap; use std::path::{Path, PathBuf}; use std::time::Duration; @@ -66,6 +67,49 @@ pub(crate) fn truncate_line(line: &str) -> &str { } } +/// Lowercase hex digits, indexed by nibble value. +const HEX_DIGITS: [u8; 16] = *b"0123456789abcdef"; + +/// Decode subprocess output as UTF-8, escaping every byte that is not valid +/// UTF-8 as `\xNN` with lowercase hex. +/// +/// This mirrors CPython's `bytes.decode("utf-8", errors="backslashreplace")`, +/// which `openjd-sessions-for-python` uses when reading subprocess output. A +/// subprocess can emit bytes that are not valid UTF-8, for example a Windows +/// DCC application writing its output in the system code page, such as Unreal +/// Engine emitting the cp1252 em dash `0x97`. Escaping those bytes rather than +/// replacing them with U+FFFD preserves the original byte values in the session +/// log, which helps identify the code page the subprocess is emitting. +/// +/// Valid UTF-8, including multi-byte sequences, passes through unmodified, and a +/// borrowed string is returned without allocating when the whole input is +/// already valid. +pub(crate) fn decode_backslashreplace(bytes: &[u8]) -> Cow<'_, str> { + // Fast path: the overwhelmingly common case is fully valid UTF-8, which + // needs no allocation. + if let Ok(valid) = std::str::from_utf8(bytes) { + return Cow::Borrowed(valid); + } + + // `utf8_chunks` splits the input into (valid UTF-8 prefix, invalid byte + // sequence) pairs, so the valid parts need no re-validation and the invalid + // sequences are delimited exactly as UTF-8 validation defines them. + // CPython escapes every byte of an undecodable sequence individually, so a + // 3-byte invalid sequence becomes three `\xNN` escapes. + let mut out = String::with_capacity(bytes.len()); + for chunk in bytes.utf8_chunks() { + out.push_str(chunk.valid()); + for &byte in chunk.invalid() { + out.push('\\'); + out.push('x'); + // Both indices are nibbles, so they are always < 16. + out.push(HEX_DIGITS[(byte >> 4) as usize] as char); + out.push(HEX_DIGITS[(byte & 0x0f) as usize] as char); + } + } + Cow::Owned(out) +} + /// Result of running a subprocess action. #[derive(Debug)] pub struct SubprocessResult { @@ -697,7 +741,7 @@ pub async fn run_subprocess( if line_buf.last() == Some(&b'\r') { line_buf.pop(); } - let line = String::from_utf8_lossy(&line_buf); + let line = decode_backslashreplace(&line_buf); let line = truncate_line(&line).to_string(); line_buf.clear(); let (display, pass_through) = process_line(&line, filter, session_id, &message_tx, &mut saw_fail); @@ -1688,6 +1732,137 @@ mod tests { assert_eq!(truncate_line(s), "hello"); } + /// Conformance table for [`decode_backslashreplace`]. + /// + /// Every expected value was generated by CPython's + /// `bytes.decode("utf-8", errors="backslashreplace")`, which is what + /// `openjd-sessions-for-python` uses. These pin byte-for-byte parity with + /// the Python implementation, including how many escapes a multi-byte + /// invalid sequence produces (CPython escapes each byte individually). + #[test] + fn test_decode_backslashreplace_matches_cpython() { + let cases: &[(&[u8], &str)] = &[ + // The customer's byte: 0x97 is the cp1252 em dash (Unreal Engine on Windows). + ( + &[0x62, 0x61, 0x64, 0x20, 0x97, 0x20, 0x62, 0x79, 0x74, 0x65], + r"bad \x97 byte", + ), + // 0xff is never valid anywhere in UTF-8. + ( + &[0x62, 0x61, 0x64, 0x20, 0xff, 0x20, 0x62, 0x79, 0x74, 0x65], + r"bad \xff byte", + ), + // Consecutive invalid bytes are escaped separately. + ( + &[ + 0x62, 0x61, 0x64, 0x20, 0xc7, 0xff, 0x20, 0x62, 0x79, 0x74, 0x65, 0x73, + ], + r"bad \xc7\xff bytes", + ), + // A cp1252 text run ("Çé"), invalid as UTF-8. + ( + &[ + 0x62, 0x61, 0x64, 0x20, 0xc7, 0xe9, 0x20, 0x74, 0x65, 0x78, 0x74, + ], + r"bad \xc7\xe9 text", + ), + // Truncated 3-byte sequence followed by valid ASCII. + ( + &[ + 0x74, 0x72, 0x75, 0x6e, 0x63, 0x61, 0x74, 0x65, 0x64, 0x20, 0xe4, 0xbd, 0x20, + 0x74, 0x68, 0x65, 0x6e, 0x20, 0x6f, 0x6b, + ], + r"truncated \xe4\xbd then ok", + ), + // Truncated sequence at end of input: `Utf8Error::error_len()` is + // `None` here, so this pins the unterminated-sequence path. + ( + &[0x74, 0x61, 0x69, 0x6c, 0x20, 0xe4, 0xbd], + r"tail \xe4\xbd", + ), + // A lone continuation byte with no lead byte. + ( + &[0x80, 0x20, 0x6c, 0x65, 0x61, 0x64, 0x69, 0x6e, 0x67], + r"\x80 leading", + ), + // Valid 2- and 3-byte sequences pass through unmodified. + ( + &[ + 0x68, 0xc3, 0xa9, 0x6c, 0x6c, 0x6f, 0x20, 0x77, 0xc3, 0xb6, 0x72, 0x6c, 0x64, + 0x20, 0xc3, 0x87, 0x20, 0xe6, 0x98, 0x9f, 0xe6, 0x9c, 0x9f, 0xe4, 0xba, 0x94, + ], + "h\u{e9}llo w\u{f6}rld \u{c7} \u{661f}\u{671f}\u{4e94}", + ), + // Valid 4-byte sequence (emoji) passes through unmodified. + ( + &[ + 0x6f, 0x6b, 0x20, 0xf0, 0x9f, 0x98, 0x80, 0x20, 0x64, 0x6f, 0x6e, 0x65, + ], + "ok \u{1f600} done", + ), + // A UTF-8-encoded surrogate half: all three bytes are escaped. + ( + &[0x73, 0x20, 0xed, 0xa0, 0x80, 0x20, 0x65], + r"s \xed\xa0\x80 e", + ), + // An overlong encoding of '/': both bytes are escaped. + (&[0x6f, 0x20, 0xc0, 0xaf, 0x20, 0x65], r"o \xc0\xaf e"), + // A lead byte beyond the Unicode maximum: all four bytes are escaped. + ( + &[0x72, 0x20, 0xf5, 0x80, 0x80, 0x80, 0x20, 0x65], + r"r \xf5\x80\x80\x80 e", + ), + (&[], ""), + ( + &[ + 0x70, 0x6c, 0x61, 0x69, 0x6e, 0x20, 0x61, 0x73, 0x63, 0x69, 0x69, + ], + "plain ascii", + ), + // Invalid bytes at both edges of the input. + (&[0xff, 0x6d, 0x69, 0x64, 0xfe], r"\xffmid\xfe"), + // A backslash already in the output is not doubled: only + // undecodable bytes are escaped. + ( + &[ + 0x43, 0x3a, 0x5c, 0x70, 0x61, 0x74, 0x68, 0x5c, 0x78, 0x34, 0x31, 0x20, 0x97, + ], + r"C:\path\x41 \x97", + ), + // NUL and tab are valid UTF-8 and pass through unescaped. + (&[0x61, 0x00, 0x62, 0x09, 0x63], "a\0b\tc"), + ]; + + for (input, expected) in cases { + assert_eq!( + decode_backslashreplace(input), + *expected, + "input bytes: {input:02x?}" + ); + } + } + + #[test] + fn test_decode_backslashreplace_borrows_valid_input() { + // Fully valid input must not allocate: the common case is a hot path + // running once per line of subprocess output. + assert!(matches!( + decode_backslashreplace("valid \u{661f} text".as_bytes()), + Cow::Borrowed(_) + )); + assert!(matches!( + decode_backslashreplace(&[0x62, 0x61, 0x64, 0x20, 0x97]), + Cow::Owned(_) + )); + } + + #[test] + fn test_decode_backslashreplace_escapes_use_lowercase_hex() { + // CPython emits lowercase hex; an uppercase escape would be a visible + // divergence in the logs. + assert_eq!(decode_backslashreplace(&[0xab, 0xcd]), r"\xab\xcd"); + } + #[cfg(unix)] #[test] fn test_run_subprocess_invalid_utf8_continues() { @@ -1711,6 +1886,55 @@ mod tests { ); } + #[cfg(unix)] + #[test] + fn test_run_subprocess_invalid_utf8_is_escaped() { + // Undecodable bytes in subprocess output must be escaped as `\xNN`, + // preserving the original byte values in the session log rather than + // collapsing them to U+FFFD. 0x97 is the cp1252 em dash, the byte a + // customer's Unreal Engine renderer emitted on Windows. + let (r, _) = run_simple(vec![ + "sh".into(), + "-c".into(), + r#"printf 'bad \x97 byte!\n'"#.into(), + ]); + assert_eq!(r.state, ActionState::Success); + assert!( + r.stdout.contains(r"bad \x97 byte!"), + "undecodable byte should be escaped as \\x97, preserving its value: {:?}", + r.stdout + ); + assert!( + !r.stdout.contains('\u{fffd}'), + "the replacement character must not appear; the byte value must be preserved: {:?}", + r.stdout + ); + } + + #[cfg(unix)] + #[test] + fn test_run_subprocess_valid_utf8_not_escaped() { + // Valid multi-byte UTF-8 must pass through unmodified. Negative control + // against over-escaping. + let (r, _) = run_simple(vec![ + "sh".into(), + "-c".into(), + "printf 'h\u{e9}llo w\u{f6}rld \u{661f}\u{671f}\u{4e94}\\n'".into(), + ]); + assert_eq!(r.state, ActionState::Success); + assert!( + r.stdout + .contains("h\u{e9}llo w\u{f6}rld \u{661f}\u{671f}\u{4e94}"), + "valid UTF-8 should pass through unmodified: {:?}", + r.stdout + ); + assert!( + !r.stdout.contains(r"\x"), + "valid UTF-8 must not be escaped: {:?}", + r.stdout + ); + } + #[cfg(unix)] #[test] fn test_run_subprocess_progress_error_in_stdout() { diff --git a/reports/sessions-quality-evaluation-report.md b/reports/sessions-quality-evaluation-report.md index c0bd51be..a6812f93 100644 --- a/reports/sessions-quality-evaluation-report.md +++ b/reports/sessions-quality-evaluation-report.md @@ -273,7 +273,7 @@ Ordered by estimated impact: | 1 | `session.rs:503-513` | `redact()` does one full `String::replace` pass per value in the set, allocating a new String each iteration. For a 1MB log line with 100 redacted values, ~100MB of allocations. Use `aho-corasick` or a single-pass approach. | O(V × L) per line | | 2 | `session.rs:1414-…` | `evaluate_env_vars()` clones `HashMap` at least 3 times per action (process env → os_env_vars merge → per-environment overlays). At 500+ env vars × 10 environments × per-task invocation, this is measurable. | O(E × V) allocations | | 3 | `action_filter.rs:465-…` | `redact_openjd_redacted_env_requests(command)` iterates all redaction values per command formatted for log. Same concern as (1). | O(V × L) | -| 4 | `subprocess.rs:611-1041` `run_subprocess` | For every stdout line, `truncate_line` → `String::from_utf8_lossy` → to-string → filter → potential redact → format-string log. Each step allocates. A tight subprocess with megabytes/sec of stdout will amplify this. | O(L) per line, high constant | +| 4 | `subprocess.rs:611-1041` `run_subprocess` | For every stdout line, `truncate_line` → `decode_backslashreplace` → to-string → filter → potential redact → format-string log. Most steps allocate (`decode_backslashreplace` borrows when the line is valid UTF-8, so it does not). A tight subprocess with megabytes/sec of stdout will amplify this. | O(L) per line, high constant | | 5 | `action_filter.rs` `filter_message` | Every call rebuilds `msg = message.to_string()` up front even for lines that won't be modified. A `Cow` would avoid allocation on the common-case pass-through. | O(L) per line | | 6 | `session.rs:1450-…` `build_symbol_table` | Walks all `job_parameter_values` entries and path-maps each `PATH`/`LIST_PATH` value. For large list parameters (hundreds of entries), the inner loop applies all rules per element. The rules are already sorted by source-path length, so an Aho-Corasick-style index over source paths would let mapping be O(L) per element instead of O(R × L) where R is the rule count. | O(R × L × N) | | 7 | `cross_user_helper.rs` `run_via_helper` | Blocking stdin/stdout read loop; fine for the helper's synchronous design but the main helper IPC marshals JSON on every message. For high-frequency actions a length-prefixed binary protocol would be faster. This is a design choice, not a bug — flag for future perf work. | N/A | diff --git a/specs/sessions/subprocess.md b/specs/sessions/subprocess.md index 38d2b646..92addbe9 100644 --- a/specs/sessions/subprocess.md +++ b/specs/sessions/subprocess.md @@ -119,13 +119,13 @@ loop { // Timeout has second priority (continues draining, does not break) _ = &mut timeout_sleep => { /* send SIGKILL, continue reading until EOF */ } - // Stdout processing — reads raw bytes, lossy UTF-8 decoding + // Stdout processing: reads raw bytes, escapes undecodable ones n = reader.read_until(b'\n', &mut line_buf) => { match n { Ok(0) => break, // EOF Ok(_) => { if line_buf.last() == Some(&b'\n') { line_buf.pop(); } - let line = String::from_utf8_lossy(&line_buf); + let line = decode_backslashreplace(&line_buf); let line = truncate_line(&line).to_string(); line_buf.clear(); let (callbacks, pass_through, modified) = filter.filter_message(&line, session_id); @@ -161,6 +161,29 @@ random branch selection. Lines longer than 64KB are truncated. This prevents a misbehaving subprocess from consuming unbounded memory. The Python library has the same limit. +### Decoding Undecodable Output Bytes + +A subprocess can write bytes that are not valid UTF-8. The common case is a Windows +DCC application emitting its output in the system code page: for example Unreal +Engine writing the cp1252 em dash `0x97`, which is not a valid UTF-8 start byte. + +`decode_backslashreplace` decodes each line as UTF-8 and escapes every byte that is +not valid UTF-8 as `\xNN`, using lowercase hex. Valid UTF-8, including multi-byte +sequences, passes through unmodified, and a fully valid line is returned borrowed +without allocating. + +This matches the Python library, which decodes subprocess output with +`errors="backslashreplace"`. Escaping rather than replacing preserves the original +byte values in the session log, which helps identify the code page the subprocess is +emitting. CPython escapes each byte of an undecodable sequence individually, so a +3-byte invalid sequence such as an encoded surrogate produces three escapes +(`\xed\xa0\x80`); the Rust implementation matches this, and the conformance table in +`subprocess.rs` pins the expected output against values generated by CPython. + +Escaping expands each undecodable byte from 1 byte to 4 characters, so a line +consisting largely of undecodable bytes can grow up to fourfold before the 64KB +truncation above is applied. + ### 5-Second Process Exit Grace Time After the stdout loop ends (EOF), the subprocess waits up to 5 seconds for the child