atomcode_tuix/
trace.rs

1// crates/atomcode-tuix/src/trace.rs
2//
3// Opt-in file logger for diagnosing event-loop / render timing issues.
4//
5// Enabled via env var `ATOMCODE_TUIX_LOG=/path/to/file`. When unset
6// every `tuix_trace!` call compiles into a no-op fast path (single
7// atomic load + branch predict), so leaving trace points scattered
8// through hot paths costs nothing in release.
9//
10// Why not env_logger / tracing? We write to stderr-redirected-to-tty
11// in raw mode; any sloppy write corrupts the display. A dedicated file
12// sink with explicit category tags keeps the noise off the terminal
13// and keeps the format parseable (one event per line, microsecond
14// monotonic timestamps).
15//
16// Format: `+{elapsed_us} [{CAT}] {tid} {message}`
17//   elapsed_us — microseconds since the first log event in this process
18//   CAT        — 2-4 char category (IN, KEY, PH, THR, REN, RD, QUE)
19//   tid        — short thread name or id (so `event_loop` vs `tuix-render`
20//                is visible at a glance)
21
22use std::fs::{File, OpenOptions};
23use std::io::Write;
24use std::sync::{Mutex, OnceLock};
25use std::time::Instant;
26
27static SINK: OnceLock<Option<Mutex<File>>> = OnceLock::new();
28static ORIGIN: OnceLock<Instant> = OnceLock::new();
29
30pub fn enabled() -> bool {
31    sink().is_some()
32}
33
34fn sink() -> Option<&'static Mutex<File>> {
35    // STRICTLY opt-in. Earlier versions defaulted to writing
36    // `/tmp/tuix.log` unconditionally so users didn't have to set an
37    // env var to produce diagnostic logs. That turned the trace
38    // infrastructure into a production bottleneck:
39    //   - every `tuix_trace!` call on the main thread AND on the
40    //     `tuix-render` worker thread contends the same `Mutex<File>`
41    //   - main thread emits RD+IN+KEY per keystroke (~3 traces),
42    //     worker emits FOOT+REN+THR per paint (~3 traces)
43    //   - under IME burst (8 chars in 100µs), that's 50+ mutex ops
44    //     from two threads. Lock queueing added 1-3ms of main-thread
45    //     stall per burst, which the user perceives as "吞字" —
46    //     characters logically accepted but visually delayed.
47    //
48    // Now: opt-in only. Default build ships no trace overhead at all
49    // (the macro's `if enabled()` short-circuits to a single atomic
50    // load). Set ATOMCODE_TUIX_LOG=/path to enable diagnosis.
51    SINK.get_or_init(|| {
52        let path = std::env::var("ATOMCODE_TUIX_LOG").ok()?;
53        if path.is_empty() {
54            return None;
55        }
56        // Truncate on each run so stale events from prior sessions
57        // don't confuse diagnosis.
58        let file = OpenOptions::new()
59            .create(true)
60            .write(true)
61            .truncate(true)
62            .open(&path)
63            .ok()?;
64        Some(Mutex::new(file))
65    })
66    .as_ref()
67}
68
69fn origin() -> Instant {
70    *ORIGIN.get_or_init(Instant::now)
71}
72
73/// Low-level write. Don't call directly — use the `tuix_trace!` macro.
74pub fn write_line(cat: &str, args: std::fmt::Arguments<'_>) {
75    let Some(sink) = sink() else {
76        return;
77    };
78    let us = origin().elapsed().as_micros();
79    let tid = std::thread::current().name().unwrap_or("?").to_string();
80    let line = format!("+{:>10}us [{:>3}] {:>14} {}\n", us, cat, tid, args);
81    if let Ok(mut f) = sink.lock() {
82        let _ = f.write_all(line.as_bytes());
83    }
84}
85
86/// `tuix_trace!("CAT", "fmt {}", args)` — compiles to a cheap `enabled()`
87/// check when the env var is unset. Use short 2-4 char categories so
88/// log lines remain grep-able by column:
89///   IN  — input event entering handle_input
90///   KEY — key-handler outcome (Redraw / Commit / NoOp)
91///   PH  — UiPhase transition (Streaming → Idle, etc.)
92///   QUE — type-ahead queue push / pop
93///   THR — InputThrottle paint/park decision
94///   REN — render worker command processed
95///   RD  — raw reader thread event
96#[macro_export]
97macro_rules! tuix_trace {
98    ($cat:expr, $($arg:tt)*) => {{
99        if $crate::trace::enabled() {
100            $crate::trace::write_line($cat, format_args!($($arg)*));
101        }
102    }};
103}
atomcode_tuix/trace.rs

atomcode_tuix/
trace.rs
