返回 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 #[allow(dead_code)]
69 log_path: PathBuf,
70 }
71
72 impl TuiLogGuard {
73 /// Path the subscriber is writing to.
74 #[allow(dead_code)]
75 #[must_use]
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 unsafe {
102 let _ = windows::Win32::System::Console::SetStdHandle(
103 windows::Win32::System::Console::STD_ERROR_HANDLE,
104 handle,
105 );
106 }
107 }
108 // Close the duplicated handle that was serving as the redirected
109 // stderr target. This is safe because `SetStdHandle` above already
110 // restored the original handle, so nothing references this one.
111 if let Some(dup) = self.redirected_stderr_handle.take() {
112 unsafe {
113 let _ = windows::Win32::Foundation::CloseHandle(dup);
114 }
115 }
116 }
117 }
118
119 #[cfg(not(any(unix, windows)))]
120 impl Drop for TuiLogGuard {
121 fn drop(&mut self) {}
122 }
123
124 /// Initialize the TUI logging subsystem. Idempotent across re-entry by way
125 /// of `set_default` — if a global subscriber is already set we still install
126 /// the stderr redirect.
127 ///
128 /// Returns a guard that must outlive the alt-screen session. Drop it after
129 /// `LeaveAlternateScreen` so any shutdown messages reach the user.
130 pub fn init() -> Result<TuiLogGuard> {
131 let log_dir = log_directory().context("could not resolve TUI log directory")?;
132 fs::create_dir_all(&log_dir)
133 .with_context(|| format!("failed to create {}", log_dir.display()))?;
134 let _ = prune_old_logs(&log_dir, log_retention_days());
135
136 let date = chrono::Local::now().format("%Y-%m-%d").to_string();
137 let log_path = log_dir.join(log_file_name(&date, std::process::id()));
138
139 let file = OpenOptions::new()
140 .create(true)
141 .append(true)
142 .open(&log_path)
143 .with_context(|| format!("failed to open {}", log_path.display()))?;
144
145 // The tracing-subscriber consumes a clone of the file handle for its
146 // writer. We keep our own handle for the dup2 redirect below — we need
147 // the same on-disk file but a separate fd so the subscriber's writes
148 // and the raw-stderr writes don't fight over the same kernel offset.
149 let subscriber_file = file
150 .try_clone()
151 .context("failed to clone log file handle for subscriber")?;
152
153 let env_filter = EnvFilter::try_from_default_env()
154 .or_else(|_| EnvFilter::try_new("info"))
155 .unwrap_or_else(|_| EnvFilter::new("info"));
156
157 let log_path_clone = log_path.clone();
158 let subscriber = tracing_subscriber::registry().with(env_filter).with(
159 fmt::layer()
160 .with_writer(move || -> Box<dyn std::io::Write + Send> {
161 // Clone the file handle for each write. If clone fails (fd exhaustion),
162 // fall back to reopening the same path, or ultimately stderr.
163 match subscriber_file.try_clone() {
164 Ok(f) => Box::new(f),
165 Err(e) => {
166 tracing::warn!("Failed to clone log file handle: {e}, reopening");
167 match std::fs::OpenOptions::new()
168 .create(true)
169 .append(true)
170 .open(&log_path_clone)
171 {
172 Ok(f) => Box::new(f),
173 Err(_) => Box::new(std::io::stderr()),
174 }
175 }
176 }
177 })
178 .with_ansi(false)
179 .with_target(true)
180 .with_thread_ids(false),
181 );
182
183 // Best-effort: if a subscriber is already set (e.g., re-entry, or a
184 // host process installed one), we skip ours rather than panic. The
185 // stderr redirect below still happens.
186 let _ = tracing::subscriber::set_global_default(subscriber);
187
188 #[cfg(unix)]
189 let saved_stderr_fd = redirect_stderr_to(&file).ok();
190 #[cfg(windows)]
191 let (saved_stderr_handle, redirected_stderr_handle) = match redirect_stderr_to(&file) {
192 Ok((saved, dup)) => (Some(saved), Some(dup)),
193 Err(e) => {
194 tracing::warn!("Failed to redirect stderr to log file: {e}");
195 (None, None)
196 }
197 };
198
199 Ok(TuiLogGuard {
200 #[cfg(unix)]
201 saved_stderr_fd,
202 #[cfg(windows)]
203 saved_stderr_handle,
204 #[cfg(windows)]
205 redirected_stderr_handle,
206 _file: file,
207 log_path,
208 })
209 }
210
211 pub(crate) fn log_directory() -> Option<PathBuf> {
212 // $CODEWHALE_HOME is a hard override of the base data directory
213 // (docs/CONFIGURATION.md): when SET, logs live under it and we do NOT fall
214 // back to the legacy ~/.deepseek path — silent fallback would defeat the
215 // isolation the override promises (CI, containers, test harnesses). We
216 // check the env var directly rather than codewhale_home()'s Ok/Err because
217 // that helper succeeds (returns $HOME/.codewhale) even when the override is
218 // unset, which would short-circuit the legacy fallback below.
219 if let Some(home) = codewhale_paths::codewhale_home_override().ok().flatten() {
220 return Some(home.join("logs"));
221 }
222 let resolve = |base: PathBuf| -> Option<PathBuf> {
223 let primary = base.join(".codewhale").join("logs");
224 if primary.exists() {
225 return Some(primary);
226 }
227 let legacy = base.join(".deepseek").join("logs");
228 if legacy.exists() {
229 return Some(legacy);
230 }
231 Some(primary)
232 };
233 codewhale_paths::user_home().and_then(resolve)
234 }
235
236 fn log_file_name(date: &str, pid: u32) -> String {
237 format!("tui-{date}-{pid}.log")
238 }
239
240 fn log_retention_days() -> u64 {
241 std::env::var(LOG_RETENTION_ENV)
242 .ok()
243 .and_then(|raw| raw.trim().parse::<u64>().ok())
244 .filter(|days| *days > 0)
245 .unwrap_or(DEFAULT_LOG_RETENTION_DAYS)
246 }
247
248 fn prune_old_logs(log_dir: &Path, retention_days: u64) -> std::io::Result<usize> {
249 let retention = Duration::from_secs(retention_days.saturating_mul(SECONDS_PER_DAY));
250 let cutoff = SystemTime::now()
251 .checked_sub(retention)
252 .unwrap_or(SystemTime::UNIX_EPOCH);
253 let mut removed = 0usize;
254
255 for entry in fs::read_dir(log_dir)? {
256 let entry = entry?;
257 if !is_tui_log_file_name(&entry.file_name()) {
258 continue;
259 }
260 let metadata = match entry.metadata() {
261 Ok(metadata) if metadata.is_file() => metadata,
262 _ => continue,
263 };
264 let modified = match metadata.modified() {
265 Ok(modified) => modified,
266 Err(_) => continue,
267 };
268 if modified < cutoff && fs::remove_file(entry.path()).is_ok() {
269 removed += 1;
270 }
271 }
272
273 Ok(removed)
274 }
275
276 fn is_tui_log_file_name(file_name: &std::ffi::OsStr) -> bool {
277 file_name
278 .to_str()
279 .is_some_and(|name| name.starts_with("tui-") && name.ends_with(".log"))
280 }
281
282 #[cfg(unix)]
283 fn redirect_stderr_to(file: &File) -> Result<libc::c_int> {
284 use std::os::fd::AsRawFd;
285 let target = file.as_raw_fd();
286 // SAFETY: `libc::dup` and `libc::dup2` are the documented fd-management
287 // primitives. We save the current stderr fd before reassigning so the
288 // guard can restore it on drop.
289 unsafe {
290 let saved = libc::dup(libc::STDERR_FILENO);
291 if saved < 0 {
292 return Err(
293 anyhow::Error::from(std::io::Error::last_os_error()).context("dup(STDERR_FILENO)")
294 );
295 }
296 if libc::dup2(target, libc::STDERR_FILENO) < 0 {
297 let err = std::io::Error::last_os_error();
298 let _ = libc::close(saved);
299 return Err(anyhow::Error::from(err).context("dup2(log_file, STDERR_FILENO)"));
300 }
301 Ok(saved)
302 }
303 }
304
305 #[cfg(windows)]
306 fn redirect_stderr_to(
307 file: &File,
308 ) -> Result<(
309 windows::Win32::Foundation::HANDLE,
310 windows::Win32::Foundation::HANDLE,
311 )> {
312 use std::os::windows::io::AsRawHandle;
313 use windows::Win32::Foundation::{CloseHandle, DUPLICATE_SAME_ACCESS, DuplicateHandle, HANDLE};
314 use windows::Win32::System::Console::{GetStdHandle, STD_ERROR_HANDLE, SetStdHandle};
315 use windows::Win32::System::Threading::GetCurrentProcess;
316
317 // SAFETY: GetStdHandle is always available; returns INVALID_HANDLE_VALUE
318 // on failure or null-like handles for console-less processes.
319 let saved =
320 unsafe { GetStdHandle(STD_ERROR_HANDLE) }.context("GetStdHandle(STD_ERROR_HANDLE)")?;
321 if saved.is_invalid() {
322 return Err(anyhow::anyhow!("GetStdHandle(STD_ERROR_HANDLE) failed"));
323 }
324
325 // Duplicate the file handle so the redirected stderr owns an
326 // independent HANDLE — mirroring the Unix path's `libc::dup`.
327 // Without this, `_file` and stderr would alias the same HANDLE;
328 // a rogue `CloseHandle` on stderr would silently invalidate `_file`.
329 let raw = HANDLE(file.as_raw_handle());
330 let process = unsafe { GetCurrentProcess() };
331 let mut dup = HANDLE::default();
332 unsafe {
333 DuplicateHandle(
334 process,
335 raw,
336 process,
337 &mut dup,
338 0,
339 false,
340 DUPLICATE_SAME_ACCESS,
341 )
342 .context("DuplicateHandle for stderr redirect")?;
343 }
344
345 // SAFETY: SetStdHandle redirects stderr to the duplicated handle.
346 // We save the original handle so the guard can restore it on drop.
347 unsafe {
348 if let Err(e) = SetStdHandle(STD_ERROR_HANDLE, dup) {
349 let _ = CloseHandle(dup);
350 return Err(anyhow::anyhow!(
351 "SetStdHandle(STD_ERROR_HANDLE) failed: {e}"
352 ));
353 }
354 }
355 Ok((saved, dup))
356 }
357
358 #[cfg(test)]
359 mod tests {
360 use super::*;
361 use std::fs::FileTimes;
362
363 #[test]
364 fn whitespace_home_override_is_consistent_across_tui_state_entry_points() {
365 let _lock = crate::test_support::lock_test_env();
366 let tmp = tempfile::TempDir::new().expect("temporary root");
367 let home = tmp.path().join("home");
368 let userprofile = tmp.path().join("userprofile");
369 let _home = crate::test_support::EnvVarGuard::set("HOME", &home);
370 let _userprofile = crate::test_support::EnvVarGuard::set("USERPROFILE", &userprofile);
371 let _codewhale_home = crate::test_support::EnvVarGuard::set("CODEWHALE_HOME", " \t ");
372 let _config_path = crate::test_support::EnvVarGuard::remove("CODEWHALE_CONFIG_PATH");
373 let _legacy_config_path = crate::test_support::EnvVarGuard::remove("DEEPSEEK_CONFIG_PATH");
374 let primary = home.join(".codewhale");
375
376 assert_eq!(crate::config::effective_home_dir(), Some(home.clone()));
377 assert_eq!(
378 crate::config::workspace_trust_config_candidate_paths(),
379 vec![
380 primary.join("config.toml"),
381 home.join(".deepseek").join("config.toml")
382 ]
383 );
384 assert_eq!(log_directory(), Some(primary.join("logs")));
385 assert_eq!(
386 crate::automation_manager::default_automations_dir(),
387 primary.join("automations")
388 );
389 assert_eq!(
390 crate::session_manager::default_sessions_dir().expect("session directory"),
391 primary.join("sessions")
392 );
393 }
394
395 fn set_modified(path: &Path, modified: SystemTime) {
396 let file = OpenOptions::new().write(true).open(path).unwrap();
397 file.set_times(FileTimes::new().set_modified(modified))
398 .unwrap();
399 }
400
401 #[test]
402 fn log_directory_prefers_home() {
403 let _lock = crate::test_support::lock_test_env();
404 let tmp = tempfile::TempDir::new().unwrap();
405 let prev_home = std::env::var_os("HOME");
406 let prev_userprofile = std::env::var_os("USERPROFILE");
407 // SAFETY: serialised by lock_test_env.
408 unsafe {
409 std::env::set_var("HOME", tmp.path());
410 std::env::set_var("USERPROFILE", "");
411 }
412
413 let resolved = log_directory().expect("log_directory should resolve");
414 assert_eq!(resolved, tmp.path().join(".codewhale").join("logs"));
415
416 // SAFETY: cleanup under the same lock.
417 unsafe {
418 match prev_home {
419 Some(v) => std::env::set_var("HOME", v),
420 None => std::env::remove_var("HOME"),
421 }
422 match prev_userprofile {
423 Some(v) => std::env::set_var("USERPROFILE", v),
424 None => std::env::remove_var("USERPROFILE"),
425 }
426 }
427 }
428
429 #[test]
430 fn log_directory_uses_existing_legacy_deepseek_logs() {
431 let _lock = crate::test_support::lock_test_env();
432 let tmp = tempfile::TempDir::new().unwrap();
433 let legacy = tmp.path().join(".deepseek").join("logs");
434 fs::create_dir_all(&legacy).unwrap();
435 let prev_home = std::env::var_os("HOME");
436 let prev_userprofile = std::env::var_os("USERPROFILE");
437 // SAFETY: serialised by lock_test_env.
438 unsafe {
439 std::env::set_var("HOME", tmp.path());
440 std::env::set_var("USERPROFILE", "");
441 }
442
443 let resolved = log_directory().expect("log_directory should resolve");
444 assert_eq!(resolved, legacy);
445
446 // SAFETY: cleanup under the same lock.
447 unsafe {
448 match prev_home {
449 Some(v) => std::env::set_var("HOME", v),
450 None => std::env::remove_var("HOME"),
451 }
452 match prev_userprofile {
453 Some(v) => std::env::set_var("USERPROFILE", v),
454 None => std::env::remove_var("USERPROFILE"),
455 }
456 }
457 }
458
459 #[test]
460 fn log_file_name_includes_pid() {
461 assert_eq!(
462 log_file_name("2026-05-18", 12345),
463 "tui-2026-05-18-12345.log"
464 );
465 }
466
467 #[test]
468 fn log_retention_days_uses_positive_env_override() {
469 let _lock = crate::test_support::lock_test_env();
470 let previous = std::env::var_os(LOG_RETENTION_ENV);
471
472 // SAFETY: serialised by lock_test_env.
473 unsafe {
474 std::env::set_var(LOG_RETENTION_ENV, "14");
475 }
476 assert_eq!(log_retention_days(), 14);
477
478 // SAFETY: serialised by lock_test_env.
479 unsafe {
480 std::env::set_var(LOG_RETENTION_ENV, "0");
481 }
482 assert_eq!(log_retention_days(), DEFAULT_LOG_RETENTION_DAYS);
483
484 // SAFETY: cleanup under the same lock.
485 unsafe {
486 match previous {
487 Some(value) => std::env::set_var(LOG_RETENTION_ENV, value),
488 None => std::env::remove_var(LOG_RETENTION_ENV),
489 }
490 }
491 }
492
493 #[test]
494 fn prune_old_logs_drops_only_stale_tui_logs() {
495 let tmp = tempfile::TempDir::new().unwrap();
496 let fresh = tmp.path().join("tui-2026-05-18-1.log");
497 let stale = tmp.path().join("tui-2026-05-01-2.log");
498 let legacy_stale = tmp.path().join("tui-2026-05-01.log");
499 let unrelated = tmp.path().join("agent-2026-05-01.log");
500
501 fs::write(&fresh, "fresh").unwrap();
502 fs::write(&stale, "stale").unwrap();
503 fs::write(&legacy_stale, "legacy").unwrap();
504 fs::write(&unrelated, "other").unwrap();
505
506 let now = SystemTime::now();
507 let old = now - Duration::from_secs(10 * SECONDS_PER_DAY);
508 set_modified(&stale, old);
509 set_modified(&legacy_stale, old);
510 set_modified(&unrelated, old);
511
512 let removed = prune_old_logs(tmp.path(), 7).unwrap();
513
514 assert_eq!(removed, 2);
515 assert!(fresh.exists());
516 assert!(!stale.exists());
517 assert!(!legacy_stale.exists());
518 assert!(unrelated.exists());
519 }
520
521 #[test]
522 fn log_directory_honors_codewhale_home_as_hard_override() {
523 let _lock = crate::test_support::lock_test_env();
524 let tmp = tempfile::TempDir::new().unwrap();
525 // SAFETY: serialised by lock_test_env.
526 unsafe {
527 std::env::set_var("CODEWHALE_HOME", tmp.path());
528 }
529 // $CODEWHALE_HOME IS the home dir (no ".codewhale" appended), and the
530 // legacy ~/.deepseek fallback is bypassed entirely.
531 let resolved = log_directory().expect("log_directory should resolve");
532 assert_eq!(resolved, tmp.path().join("logs"));
533 // SAFETY: cleanup under the same lock.
534 unsafe {
535 std::env::remove_var("CODEWHALE_HOME");
536 }
537 }
538 }
539
539 lines RUST