claude_code_rust/
perf.rs

1// Claude Code Rust - A native Rust terminal interface for Claude Code
2// Copyright (C) 2025  Simon Peter Rothgang
3//
4// This program is free software: you can redistribute it and/or modify
5// it under the terms of the GNU Affero General Public License as
6// published by the Free Software Foundation, either version 3 of the
7// License, or (at your option) any later version.
8//
9// This program is distributed in the hope that it will be useful,
10// but WITHOUT ANY WARRANTY; without even the implied warranty of
11// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12// GNU Affero General Public License for more details.
13//
14// You should have received a copy of the GNU Affero General Public License
15// along with this program.  If not, see <https://www.gnu.org/licenses/>.
16
17//! Lightweight per-frame performance logger for rendering instrumentation.
18//!
19//! Gated behind `--features perf`. When the feature is disabled, all types
20//! become zero-size and all methods are no-ops that the compiler eliminates.
21//!
22//! # Usage
23//!
24//! ```bash
25//! cargo run --features perf -- --perf-log performance.log
26//! # Writes JSON lines:
27//! # {"run":"...","frame":1234,"ts_ms":1739599900793,"fn":"chat::render_msgs","ms":2.345,"n":42}
28//! ```
29
30#[cfg(feature = "perf")]
31mod enabled {
32    use std::cell::RefCell;
33    use std::fs::{File, OpenOptions};
34    use std::io::{BufWriter, Write};
35    use std::path::Path;
36    use std::time::{Instant, SystemTime, UNIX_EPOCH};
37
38    // Thread-local file handle so Timer::drop can log without borrowing PerfLogger.
39    thread_local! {
40        pub(crate) static LOG_FILE: RefCell<Option<BufWriter<File>>> = const { RefCell::new(None) };
41        static FRAME_COUNTER: RefCell<u64> = const { RefCell::new(0) };
42        static RUN_ID: RefCell<String> = const { RefCell::new(String::new()) };
43    }
44
45    pub struct PerfLogger {
46        _private: (),
47    }
48
49    fn unix_ms() -> u128 {
50        SystemTime::now().duration_since(UNIX_EPOCH).map_or(0, |duration| duration.as_millis())
51    }
52
53    pub(crate) fn write_entry(name: &'static str, ms: f64, extra: Option<(&'static str, usize)>) {
54        let frame = FRAME_COUNTER.with(|c| *c.borrow());
55        let ts_ms = unix_ms();
56        LOG_FILE.with(|f| {
57            if let Some(ref mut file) = *f.borrow_mut() {
58                RUN_ID.with(|run| {
59                    let run_id = run.borrow();
60                    if let Some((k, v)) = extra {
61                        let _ = writeln!(
62                            file,
63                            r#"{{"run":"{run_id}","frame":{frame},"ts_ms":{ts_ms},"fn":"{name}","ms":{ms:.3},"{k}":{v}}}"#,
64                        );
65                    } else {
66                        let _ = writeln!(
67                            file,
68                            r#"{{"run":"{run_id}","frame":{frame},"ts_ms":{ts_ms},"fn":"{name}","ms":{ms:.3}}}"#,
69                        );
70                    }
71                });
72            }
73        });
74    }
75
76    #[allow(clippy::unused_self)]
77    impl PerfLogger {
78        /// Open (or create) the log file. Returns `None` on I/O error.
79        pub fn open(path: &Path, append: bool) -> Option<Self> {
80            let mut options = OpenOptions::new();
81            options.create(true).write(true);
82            if append {
83                options.append(true);
84            } else {
85                options.truncate(true);
86            }
87            let file = options.open(path).ok()?;
88            let mut writer = BufWriter::new(file);
89            let run_id = uuid::Uuid::new_v4().to_string();
90            let ts_ms = unix_ms();
91            let _ = writeln!(
92                writer,
93                r#"{{"event":"run_start","run":"{run_id}","ts_ms":{ts_ms},"pid":{},"version":"{}","append":{append}}}"#,
94                std::process::id(),
95                env!("CARGO_PKG_VERSION")
96            );
97            let _ = writer.flush();
98            LOG_FILE.with(|f| *f.borrow_mut() = Some(writer));
99            RUN_ID.with(|r| *r.borrow_mut() = run_id);
100            FRAME_COUNTER.with(|c| *c.borrow_mut() = 0);
101            Some(Self { _private: () })
102        }
103
104        /// Increment the frame counter. Call once at the start of each render frame.
105        pub fn next_frame(&mut self) {
106            let frame = FRAME_COUNTER.with(|c| {
107                let mut value = c.borrow_mut();
108                *value += 1;
109                *value
110            });
111            if frame.is_multiple_of(240) {
112                LOG_FILE.with(|f| {
113                    if let Some(ref mut file) = *f.borrow_mut() {
114                        let _ = file.flush();
115                    }
116                });
117            }
118        }
119
120        /// Start a named timer. Logs duration on drop.
121        #[must_use]
122        pub fn start(&self, name: &'static str) -> Timer {
123            Timer { name, start: Instant::now(), extra: None }
124        }
125
126        /// Start a named timer with an extra numeric field (e.g. message count).
127        #[must_use]
128        pub fn start_with(
129            &self,
130            name: &'static str,
131            extra_name: &'static str,
132            extra_val: usize,
133        ) -> Timer {
134            Timer { name, start: Instant::now(), extra: Some((extra_name, extra_val)) }
135        }
136
137        /// Log an instant marker for the current frame (`ms = 0`).
138        pub fn mark(&self, name: &'static str) {
139            write_entry(name, 0.0, None);
140        }
141
142        /// Log an instant marker with an extra numeric field (`ms = 0`).
143        pub fn mark_with(&self, name: &'static str, extra_name: &'static str, extra_val: usize) {
144            write_entry(name, 0.0, Some((extra_name, extra_val)));
145        }
146    }
147
148    pub struct Timer {
149        pub(crate) name: &'static str,
150        pub(crate) start: Instant,
151        pub(crate) extra: Option<(&'static str, usize)>,
152    }
153
154    #[allow(clippy::unused_self)]
155    impl Timer {
156        /// Manually stop and log. Useful when you need to end timing before scope exit.
157        pub fn stop(self) {
158            // Drop impl handles logging
159        }
160    }
161
162    impl Drop for Timer {
163        fn drop(&mut self) {
164            let ms = self.start.elapsed().as_secs_f64() * 1000.0;
165            write_entry(self.name, ms, self.extra);
166        }
167    }
168}
169
170#[cfg(not(feature = "perf"))]
171mod disabled {
172    use std::path::Path;
173
174    pub struct PerfLogger;
175    pub struct Timer;
176
177    #[allow(clippy::unused_self)]
178    impl PerfLogger {
179        #[inline]
180        pub fn open(_path: &Path, _append: bool) -> Option<Self> {
181            None
182        }
183        #[inline]
184        pub fn next_frame(&mut self) {}
185        #[inline]
186        #[must_use]
187        pub fn start(&self, _name: &'static str) -> Timer {
188            Timer
189        }
190        #[inline]
191        #[must_use]
192        pub fn start_with(
193            &self,
194            _name: &'static str,
195            _extra_name: &'static str,
196            _extra_val: usize,
197        ) -> Timer {
198            Timer
199        }
200        #[inline]
201        pub fn mark(&self, _name: &'static str) {}
202        #[inline]
203        pub fn mark_with(&self, _name: &'static str, _extra_name: &'static str, _extra_val: usize) {
204        }
205    }
206
207    #[allow(clippy::unused_self)]
208    impl Timer {
209        #[inline]
210        pub fn stop(self) {}
211    }
212}
213
214/// Start a timer without needing a `PerfLogger` reference.
215/// Uses the thread-local log file directly. Returns `None` (and is a no-op)
216/// when the `perf` feature is disabled or no logger has been opened.
217#[cfg(feature = "perf")]
218#[must_use]
219#[inline]
220pub fn start(name: &'static str) -> Option<Timer> {
221    // Only create a timer if the log file is actually open
222    enabled::LOG_FILE.with(|f| {
223        if f.borrow().is_some() {
224            Some(Timer { name, start: std::time::Instant::now(), extra: None })
225        } else {
226            None
227        }
228    })
229}
230
231#[cfg(feature = "perf")]
232#[must_use]
233#[inline]
234pub fn start_with(name: &'static str, extra_name: &'static str, extra_val: usize) -> Option<Timer> {
235    enabled::LOG_FILE.with(|f| {
236        if f.borrow().is_some() {
237            Some(Timer {
238                name,
239                start: std::time::Instant::now(),
240                extra: Some((extra_name, extra_val)),
241            })
242        } else {
243            None
244        }
245    })
246}
247
248#[cfg(not(feature = "perf"))]
249#[must_use]
250#[inline]
251pub fn start(_name: &'static str) -> Option<Timer> {
252    None
253}
254
255#[cfg(not(feature = "perf"))]
256#[must_use]
257#[inline]
258pub fn start_with(
259    _name: &'static str,
260    _extra_name: &'static str,
261    _extra_val: usize,
262) -> Option<Timer> {
263    None
264}
265
266/// Write an instant marker for the current frame (`ms = 0`).
267#[cfg(feature = "perf")]
268#[inline]
269pub fn mark(name: &'static str) {
270    enabled::write_entry(name, 0.0, None);
271}
272
273#[cfg(not(feature = "perf"))]
274#[inline]
275pub fn mark(_name: &'static str) {}
276
277/// Write an instant marker with one numeric field (`ms = 0`).
278#[cfg(feature = "perf")]
279#[inline]
280pub fn mark_with(name: &'static str, extra_name: &'static str, extra_val: usize) {
281    enabled::write_entry(name, 0.0, Some((extra_name, extra_val)));
282}
283
284#[cfg(not(feature = "perf"))]
285#[inline]
286pub fn mark_with(_name: &'static str, _extra_name: &'static str, _extra_val: usize) {}
287
288#[cfg(feature = "perf")]
289pub use enabled::{PerfLogger, Timer};
290
291#[cfg(not(feature = "perf"))]
292pub use disabled::{PerfLogger, Timer};
claude_code_rust/perf.rs

claude_code_rust/
perf.rs
