返回 CodeWhale
runtime_log.rs
根目录 / crates / tui / src / runtime_log.rs
1 //! TUI runtime logging. Initializes a `tracing-subscriber` that writes to a
2 //! per-process file under `~/.codewhale/logs/tui-YYYY-MM-DD-PID.log`, and (on
3 //! Unix and Windows) redirects the process's `stderr` handle/fd to that same
4 //! file for the lifetime of the alt-screen TUI.
5 //!
6 //! Why this exists:
7 //!
8 //! The TUI runs inside an alt-screen buffer drawn by `ratatui` using an
9 //! incremental diff renderer. The renderer assumes nothing else is writing
10 //! to the terminal — its internal "current cells" model is the only source
11 //! of truth for what's on screen. If anything emits raw bytes to stdout or
12 //! stderr while the alt-screen is active (an `eprintln!` from a sub-agent,
13 //! a `tracing` warning that defaulted to `stderr`, a panic message, a
14 //! third-party crate's verbose output, …) those bytes land in the alt-screen
15 //! buffer at the current cursor position, scroll the buffer up, and leave
16 //! the renderer's model out of sync with reality. The visible symptom is
17 //! "scroll demon": the TUI content drifts down, leaving a band of blank
18 //! rows above the header. This was the regression in issue #1085 (fixed in
19 //! v0.8.18 by adding a viewport-reset path) and re-surfaced in v0.8.27
20 //! when the flicker fix dropped the `\x1b[2J\x1b[3J` deep-clear that had
21 //! been masking the underlying leak.
22 //!
23 //! Defence-in-depth:
24 //! 1. A `tracing-subscriber` writes formatted logs to
25 //! `~/.codewhale/logs/tui-YYYY-MM-DD-PID.log` so `tracing::warn!` /
26 //! `tracing::error!` calls go somewhere observable instead of
27 //! disappearing into the void (the TUI previously had no global
28 //! subscriber, so contributors reached for `eprintln!`).
29 //! 2. On Unix and Windows the process's stderr handle/fd is redirected to
30 //! the same log file for the lifetime of `TuiLogGuard`. Any raw stderr
31 //! write — ours, a dependency's, a panic message — lands in the log
32 //! file instead of the alt-screen. The guard restores the original
33 //! stderr handle/fd on drop so post-TUI shutdown messages still reach
34 //! the user's terminal.
35 //! 3. Crate-level `#![deny(clippy::print_stderr, clippy::print_stdout)]`
36 //! on the TUI runtime modules forbids new `eprintln!` / `println!`
37 //! calls at compile time. CLI-output paths (`main.rs` eval, init,
38 //! `runtime_api::print_*`, `logging::info`/`warn`) keep their existing
39 //! prints via `#[allow(clippy::print_stderr)]` because they run before
40 //! the alt-screen is entered.
41
42 use std::fs::{self, File, OpenOptions};
43 use std::path::{Path, PathBuf};
44 use std::time::{Duration, SystemTime};
45
46 use anyhow::{Context, Result};
47 use tracing_subscriber::{EnvFilter, fmt, prelude::*};
48
49 const DEFAULT_LOG_RETENTION_DAYS: u64 = 7;
50 const LOG_RETENTION_ENV: &str = "DEEPSEEK_LOG_RETENTION_DAYS";
51 const SECONDS_PER_DAY: u64 = 24 * 60 * 60;
52
53 /// Owns the active tracing subscriber and (on Unix/Windows) a saved copy of
54 /// the original `stderr` handle/fd so it can be restored on drop. Dropped when
55 /// the TUI exits the alt-screen.
56 pub struct TuiLogGuard {
57 #[cfg(unix)]
58 saved_stderr_fd: Option<libc::c_int>,
59 #[cfg(windows)]
60 saved_stderr_handle: Option<windows::Win32::Foundation::HANDLE>,
61 #[cfg(windows)]
62 redirected_stderr_handle: Option<windows::Win32::Foundation::HANDLE>,
63 _file: File,
64 // Exposed via `log_path()` for diagnostics (e.g. `/doctor`,
65 // `--print-log-path`). Currently no caller — keep the accessor
66 // wired up so adding one later doesn't require revisiting the
67 // guard struct.
68 #[expect(dead_code)]
69 log_path: PathBuf,
70 }
71
72 impl TuiLogGuard {
73 /// Path the subscriber is writing to.
74 #[must_use]
75 #[expect(dead_code)]
76 pub fn log_path(&self) -> &std::path::Path {
77 &self.log_path
78 }
79 }
80
81 #[cfg(unix)]
82 impl Drop for TuiLogGuard {
83 fn drop(&mut self) {
84 if let Some(saved) = self.saved_stderr_fd.take() {
85 // SAFETY: `saved` came from `libc::dup` of the original stderr
86 // fd in `init`; calling `dup2` to restore it is the standard
87 // pairing. If `dup2` fails we just leak the saved fd — the
88 // process is exiting anyway.
89 unsafe {
90 let _ = libc::dup2(saved, libc::STDERR_FILENO);
91 let _ = libc::close(saved);
92 }
93 }
94 }
95 }
96
97 #[cfg(windows)]
98 impl Drop for TuiLogGuard {
99 fn drop(&mut self) {
100 if let Some(handle) = self.saved_stderr_handle.take() {
101 // SAFETY: `handle` is owned here via take; Drop runs once.
102 unsafe {
103 let _ = windows::Win32::System::Console::SetStdHandle(
104 windows::Win32::System::Console::STD_ERROR_HANDLE,
105 handle,
106 );
107 }
108 }
109 // Close the duplicated handle that was serving as the redirected
110 // stderr target. This is safe because `SetStdHandle` above already
111 // restored the original handle, so nothing references this one.
112 if let Some(dup) = self.redirected_stderr_handle.take() {
113 // SAFETY: `dup` is owned here via take; nothing references it.
114 unsafe {
115 let _ = windows::Win32::Foundation::CloseHandle(dup);
116 }
117 }
118 }
119 }
120
121 #[cfg(not(any(unix, windows)))]
122 impl Drop for TuiLogGuard {
123 fn drop(&mut self) {}
124 }
125
126 /// Initialize the TUI logging subsystem. Idempotent across re-entry by way
127 /// of `set_default` — if a global subscriber is already set we still install
128 /// the stderr redirect.
129 ///
130 /// Returns a guard that must outlive the alt-screen session. Drop it after
131 /// `LeaveAlternateScreen` so any shutdown messages reach the user.
132 pub fn init() -> Result<TuiLogGuard> {
133 let log_dir = log_directory().context("could not resolve TUI log directory")?;
134 fs::create_dir_all(&log_dir)
135 .with_context(|| format!("failed to create {}", log_dir.display()))?;
136 let _ = prune_old_logs(&log_dir, log_retention_days());
137
138 let date = chrono::Local::now().format("%Y-%m-%d").to_string();
139 let log_path = log_dir.join(log_file_name(&date, std::process::id()));
140
141 let file = OpenOptions::new()
142 .create(true)
143 .append(true)
144 .open(&log_path)
145 .with_context(|| format!("failed to open {}", log_path.display()))?;
146
147 // The tracing-subscriber consumes a clone of the file handle for its
148 // writer. We keep our own handle for the dup2 redirect below — we need
149 // the same on-disk file but a separate fd so the subscriber's writes
150 // and the raw-stderr writes don't fight over the same kernel offset.
151 let subscriber_file = file
152 .try_clone()
153 .context("failed to clone log file handle for subscriber")?;
154
155 let env_filter = EnvFilter::try_from_default_env()
156 .or_else(|_| EnvFilter::try_new("info"))
157 .unwrap_or_else(|_| EnvFilter::new("info"));
158
159 let log_path_clone = log_path.clone();
160 let subscriber = tracing_subscriber::registry().with(env_filter).with(
161 fmt::layer()
162 .with_writer(move || -> Box<dyn std::io::Write + Send> {
163 // Clone the file handle for each write. If clone fails (fd exhaustion),
164 // fall back to reopening the same path, or ultimately stderr.
165 match subscriber_file.try_clone() {
166 Ok(f) => Box::new(f),
167 Err(e) => {
168 tracing::warn!("Failed to clone log file handle: {e}, reopening");
169 match std::fs::OpenOptions::new()
170 .create(true)
171 .append(true)
172 .open(&log_path_clone)
173 {
174 Ok(f) => Box::new(f),
175 Err(_) => Box::new(std::io::stderr()),
176 }
177 }
178 }
179 })
180 .with_ansi(false)
181 .with_target(true)
182 .with_thread_ids(false),
183 );
184
185 // Best-effort: if a subscriber is already set (e.g., re-entry, or a
186 // host process installed one), we skip ours rather than panic. The
187 // stderr redirect below still happens.
188 let _ = tracing::subscriber::set_global_default(subscriber);
189
190 #[cfg(unix)]
191 let saved_stderr_fd = redirect_stderr_to(&file).ok();
192 #[cfg(windows)]
193 let (saved_stderr_handle, redirected_stderr_handle) = match redirect_stderr_to(&file) {
194 Ok((saved, dup)) => (Some(saved), Some(dup)),
195 Err(e) => {
196 tracing::warn!("Failed to redirect stderr to log file: {e}");
197 (None, None)
198 }
199 };
200
201 Ok(TuiLogGuard {
202 #[cfg(unix)]
203 saved_stderr_fd,
204 #[cfg(windows)]
205 saved_stderr_handle,
206 #[cfg(windows)]
207 redirected_stderr_handle,
208 _file: file,
209 log_path,
210 })
211 }
212
213 pub(crate) fn log_directory() -> Option<PathBuf> {
214 // $CODEWHALE_HOME is a hard override of the base data directory
215 // (docs/CONFIGURATION.md): when SET, logs live under it and we do NOT fall
216 // back to the legacy ~/.deepseek path — silent fallback would defeat the
217 // isolation the override promises (CI, containers, test harnesses). We
218 // check the env var directly rather than codewhale_home()'s Ok/Err because
219 // that helper succeeds (returns $HOME/.codewhale) even when the override is
220 // unset, which would short-circuit the legacy fallback below.
221 if let Some(home) = codewhale_paths::codewhale_home_override().ok().flatten() {
222 return Some(home.join("logs"));
223 }
224 let resolve = |base: PathBuf| -> Option<PathBuf> {
225 let primary = base.join(".codewhale").join("logs");
226 if primary.exists() {
227 return Some(primary);
228 }
229 let legacy = base.join(".deepseek").join("logs");
230 if legacy.exists() {
231 return Some(legacy);
232 }
233 Some(primary)
234 };
235 codewhale_paths::user_home().and_then(resolve)
236 }
237
238 fn log_file_name(date: &str, pid: u32) -> String {
239 format!("tui-{date}-{pid}.log")
240 }
241
242 fn log_retention_days() -> u64 {
243 std::env::var(LOG_RETENTION_ENV)
244 .ok()
245 .and_then(|raw| raw.trim().parse::<u64>().ok())
246 .filter(|days| *days > 0)
247 .unwrap_or(DEFAULT_LOG_RETENTION_DAYS)
248 }
249
250 fn prune_old_logs(log_dir: &Path, retention_days: u64) -> std::io::Result<usize> {
251 let retention = Duration::from_secs(retention_days.saturating_mul(SECONDS_PER_DAY));
252 let cutoff = SystemTime::now()
253 .checked_sub(retention)
254 .unwrap_or(SystemTime::UNIX_EPOCH);
255 let mut removed = 0usize;
256
257 for entry in fs::read_dir(log_dir)? {
258 let entry = entry?;
259 if !is_tui_log_file_name(&entry.file_name()) {
260 continue;
261 }
262 let metadata = match entry.metadata() {
263 Ok(metadata) if metadata.is_file() => metadata,
264 _ => continue,
265 };
266 let modified = match metadata.modified() {
267 Ok(modified) => modified,
268 Err(_) => continue,
269 };
270 if modified < cutoff && fs::remove_file(entry.path()).is_ok() {
271 removed += 1;
272 }
273 }
274
275 Ok(removed)
276 }
277
278 fn is_tui_log_file_name(file_name: &std::ffi::OsStr) -> bool {
279 file_name
280 .to_str()
281 .is_some_and(|name| name.starts_with("tui-") && name.ends_with(".log"))
282 }
283
284 #[cfg(unix)]
285 fn redirect_stderr_to(file: &File) -> Result<libc::c_int> {
286 use std::os::fd::AsRawFd;
287 let target = file.as_raw_fd();
288 // SAFETY: `libc::dup` and `libc::dup2` are the documented fd-management
289 // primitives. We save the current stderr fd before reassigning so the
290 // guard can restore it on drop.
291 unsafe {
292 let saved = libc::dup(libc::STDERR_FILENO);
293 if saved < 0 {
294 return Err(
295 anyhow::Error::from(std::io::Error::last_os_error()).context("dup(STDERR_FILENO)")
296 );
297 }
298 if libc::dup2(target, libc::STDERR_FILENO) < 0 {
299 let err = std::io::Error::last_os_error();
300 let _ = libc::close(saved);
301 return Err(anyhow::Error::from(err).context("dup2(log_file, STDERR_FILENO)"));
302 }
303 Ok(saved)
304 }
305 }
306
307 #[cfg(windows)]
308 fn redirect_stderr_to(
309 file: &File,
310 ) -> Result<(
311 windows::Win32::Foundation::HANDLE,
312 windows::Win32::Foundation::HANDLE,
313 )> {
314 use std::os::windows::io::AsRawHandle;
315 use windows::Win32::Foundation::{CloseHandle, DUPLICATE_SAME_ACCESS, DuplicateHandle, HANDLE};
316 use windows::Win32::System::Console::{GetStdHandle, STD_ERROR_HANDLE, SetStdHandle};
317 use windows::Win32::System::Threading::GetCurrentProcess;
318
319 // SAFETY: GetStdHandle is always available; returns INVALID_HANDLE_VALUE
320 // on failure or null-like handles for console-less processes.
321 let saved =
322 unsafe { GetStdHandle(STD_ERROR_HANDLE) }.context("GetStdHandle(STD_ERROR_HANDLE)")?;
323 if saved.is_invalid() {
324 return Err(anyhow::anyhow!("GetStdHandle(STD_ERROR_HANDLE) failed"));
325 }
326
327 // Duplicate the file handle so the redirected stderr owns an
328 // independent HANDLE — mirroring the Unix path's `libc::dup`.
329 // Without this, `_file` and stderr would alias the same HANDLE;
330 // a rogue `CloseHandle` on stderr would silently invalidate `_file`.
331 let raw = HANDLE(file.as_raw_handle());
332 // SAFETY: pseudo-handle; no preconditions.
333 let process = unsafe { GetCurrentProcess() };
334 let mut dup = HANDLE::default();
335 // SAFETY: `file` and `dup` are live; pseudo-handle needs no close.
336 unsafe {
337 DuplicateHandle(
338 process,
339 raw,
340 process,
341 &mut dup,
342 0,
343 false,
344 DUPLICATE_SAME_ACCESS,
345 )
346 .context("DuplicateHandle for stderr redirect")?;
347 }
348
349 // SAFETY: SetStdHandle redirects stderr to the duplicated handle.
350 // We save the original handle so the guard can restore it on drop.
351 unsafe {
352 if let Err(e) = SetStdHandle(STD_ERROR_HANDLE, dup) {
353 let _ = CloseHandle(dup);
354 return Err(anyhow::anyhow!(
355 "SetStdHandle(STD_ERROR_HANDLE) failed: {e}"
356 ));
357 }
358 }
359 Ok((saved, dup))
360 }
361
362 #[cfg(test)]
363 mod tests {
364 use super::*;
365 use std::fs::FileTimes;
366
367 #[test]
368 fn whitespace_home_override_is_consistent_across_tui_state_entry_points() {
369 let _lock = crate::test_support::lock_test_env();
370 let tmp = tempfile::TempDir::new().expect("temporary root");
371 let home = tmp.path().join("home");
372 let userprofile = tmp.path().join("userprofile");
373 let _home = crate::test_support::EnvVarGuard::set("HOME", &home);
374 let _userprofile = crate::test_support::EnvVarGuard::set("USERPROFILE", &userprofile);
375 let _codewhale_home = crate::test_support::EnvVarGuard::set("CODEWHALE_HOME", " \t ");
376 let _config_path = crate::test_support::EnvVarGuard::remove("CODEWHALE_CONFIG_PATH");
377 let _legacy_config_path = crate::test_support::EnvVarGuard::remove("DEEPSEEK_CONFIG_PATH");
378 let primary = home.join(".codewhale");
379
380 assert_eq!(crate::config::effective_home_dir(), Some(home.clone()));
381 assert_eq!(
382 crate::config::workspace_trust_config_candidate_paths(),
383 vec![
384 primary.join("config.toml"),
385 home.join(".deepseek").join("config.toml")
386 ]
387 );
388 assert_eq!(log_directory(), Some(primary.join("logs")));
389 assert_eq!(
390 crate::automation_manager::default_automations_dir(),
391 primary.join("automations")
392 );
393 assert_eq!(
394 crate::session_manager::default_sessions_dir().expect("session directory"),
395 primary.join("sessions")
396 );
397 }
398
399 fn set_modified(path: &Path, modified: SystemTime) {
400 let file = OpenOptions::new().write(true).open(path).unwrap();
401 file.set_times(FileTimes::new().set_modified(modified))
402 .unwrap();
403 }
404
405 #[test]
406 fn log_directory_prefers_home() {
407 let _lock = crate::test_support::lock_test_env();
408 let tmp = tempfile::TempDir::new().unwrap();
409 let prev_home = std::env::var_os("HOME");
410 let prev_userprofile = std::env::var_os("USERPROFILE");
411 // SAFETY: serialised by lock_test_env.
412 unsafe {
413 std::env::set_var("HOME", tmp.path());
414 std::env::set_var("USERPROFILE", "");
415 }
416
417 let resolved = log_directory().expect("log_directory should resolve");
418 assert_eq!(resolved, tmp.path().join(".codewhale").join("logs"));
419
420 // SAFETY: cleanup under the same lock.
421 unsafe {
422 match prev_home {
423 Some(v) => std::env::set_var("HOME", v),
424 None => std::env::remove_var("HOME"),
425 }
426 match prev_userprofile {
427 Some(v) => std::env::set_var("USERPROFILE", v),
428 None => std::env::remove_var("USERPROFILE"),
429 }
430 }
431 }
432
433 #[test]
434 fn log_directory_uses_existing_legacy_deepseek_logs() {
435 let _lock = crate::test_support::lock_test_env();
436 let tmp = tempfile::TempDir::new().unwrap();
437 let legacy = tmp.path().join(".deepseek").join("logs");
438 fs::create_dir_all(&legacy).unwrap();
439 let prev_home = std::env::var_os("HOME");
440 let prev_userprofile = std::env::var_os("USERPROFILE");
441 // SAFETY: serialised by lock_test_env.
442 unsafe {
443 std::env::set_var("HOME", tmp.path());
444 std::env::set_var("USERPROFILE", "");
445 }
446
447 let resolved = log_directory().expect("log_directory should resolve");
448 assert_eq!(resolved, legacy);
449
450 // SAFETY: cleanup under the same lock.
451 unsafe {
452 match prev_home {
453 Some(v) => std::env::set_var("HOME", v),
454 None => std::env::remove_var("HOME"),
455 }
456 match prev_userprofile {
457 Some(v) => std::env::set_var("USERPROFILE", v),
458 None => std::env::remove_var("USERPROFILE"),
459 }
460 }
461 }
462
463 #[test]
464 fn log_file_name_includes_pid() {
465 assert_eq!(
466 log_file_name("2026-05-18", 12345),
467 "tui-2026-05-18-12345.log"
468 );
469 }
470
471 #[test]
472 fn log_retention_days_uses_positive_env_override() {
473 let _lock = crate::test_support::lock_test_env();
474 let previous = std::env::var_os(LOG_RETENTION_ENV);
475
476 // SAFETY: serialised by lock_test_env.
477 unsafe {
478 std::env::set_var(LOG_RETENTION_ENV, "14");
479 }
480 assert_eq!(log_retention_days(), 14);
481
482 // SAFETY: serialised by lock_test_env.
483 unsafe {
484 std::env::set_var(LOG_RETENTION_ENV, "0");
485 }
486 assert_eq!(log_retention_days(), DEFAULT_LOG_RETENTION_DAYS);
487
488 // SAFETY: cleanup under the same lock.
489 unsafe {
490 match previous {
491 Some(value) => std::env::set_var(LOG_RETENTION_ENV, value),
492 None => std::env::remove_var(LOG_RETENTION_ENV),
493 }
494 }
495 }
496
497 #[test]
498 fn prune_old_logs_drops_only_stale_tui_logs() {
499 let tmp = tempfile::TempDir::new().unwrap();
500 let fresh = tmp.path().join("tui-2026-05-18-1.log");
501 let stale = tmp.path().join("tui-2026-05-01-2.log");
502 let legacy_stale = tmp.path().join("tui-2026-05-01.log");
503 let unrelated = tmp.path().join("agent-2026-05-01.log");
504
505 fs::write(&fresh, "fresh").unwrap();
506 fs::write(&stale, "stale").unwrap();
507 fs::write(&legacy_stale, "legacy").unwrap();
508 fs::write(&unrelated, "other").unwrap();
509
510 let now = SystemTime::now();
511 let old = now - Duration::from_secs(10 * SECONDS_PER_DAY);
512 set_modified(&stale, old);
513 set_modified(&legacy_stale, old);
514 set_modified(&unrelated, old);
515
516 let removed = prune_old_logs(tmp.path(), 7).unwrap();
517
518 assert_eq!(removed, 2);
519 assert!(fresh.exists());
520 assert!(!stale.exists());
521 assert!(!legacy_stale.exists());
522 assert!(unrelated.exists());
523 }
524
525 #[test]
526 fn log_directory_honors_codewhale_home_as_hard_override() {
527 let _lock = crate::test_support::lock_test_env();
528 let tmp = tempfile::TempDir::new().unwrap();
529 // SAFETY: serialised by lock_test_env.
530 unsafe {
531 std::env::set_var("CODEWHALE_HOME", tmp.path());
532 }
533 // $CODEWHALE_HOME IS the home dir (no ".codewhale" appended), and the
534 // legacy ~/.deepseek fallback is bypassed entirely.
535 let resolved = log_directory().expect("log_directory should resolve");
536 assert_eq!(resolved, tmp.path().join("logs"));
537 // SAFETY: cleanup under the same lock.
538 unsafe {
539 std::env::remove_var("CODEWHALE_HOME");
540 }
541 }
542 }
543
543 lines RUST