winx_code_agent/
logging.rs

1use std::fs::{self, File, OpenOptions};
2use std::io::{self, Write};
3use std::path::{Path, PathBuf};
4
5#[cfg(unix)]
6use std::os::unix::fs::{DirBuilderExt as _, OpenOptionsExt as _, PermissionsExt as _};
7use time::OffsetDateTime;
8use tracing_appender::non_blocking::{NonBlocking, NonBlockingBuilder, WorkerGuard};
9use tracing_subscriber::filter::filter_fn;
10use tracing_subscriber::layer::SubscriberExt as _;
11use tracing_subscriber::util::SubscriberInitExt as _;
12use tracing_subscriber::Layer as _;
13
14use crate::errors::{Result, WinxError};
15
16/// Keeps the non-blocking usage-log worker alive for the lifetime of the process.
17pub struct LoggingGuard {
18    _usage: Option<WorkerGuard>,
19}
20
21#[derive(Clone, Copy, Debug, Eq, PartialEq)]
22enum UsageRotation {
23    Never,
24    Hourly,
25    Daily,
26}
27
28impl UsageRotation {
29    fn parse(value: Option<&str>) -> Result<Self> {
30        match value.unwrap_or("daily").trim().to_ascii_lowercase().as_str() {
31            "never" => Ok(Self::Never),
32            "hourly" => Ok(Self::Hourly),
33            "daily" | "" => Ok(Self::Daily),
34            other => Err(WinxError::ConfigurationError(format!(
35                "invalid WINX_USAGE_LOG_ROTATION={other:?}; expected `never`, `hourly`, or `daily`"
36            ))),
37        }
38    }
39
40    fn period(self, now: OffsetDateTime) -> Option<String> {
41        let month = u8::from(now.month());
42        match self {
43            Self::Never => None,
44            Self::Daily => Some(format!("{:04}-{month:02}-{:02}", now.year(), now.day())),
45            Self::Hourly => {
46                Some(format!("{:04}-{month:02}-{:02}-{:02}", now.year(), now.day(), now.hour()))
47            }
48        }
49    }
50
51    fn max_files(self, keep_days: usize) -> Option<usize> {
52        if keep_days == 0 || self == Self::Never {
53            return None;
54        }
55        let files_per_day = if self == Self::Hourly { 24 } else { 1 };
56        // Retain one extra file so rotation never dips below the requested
57        // completed-history window while the active file is counted.
58        Some(keep_days.saturating_mul(files_per_day).saturating_add(1))
59    }
60
61    fn valid_period(self, suffix: &str) -> bool {
62        let expected_len = match self {
63            Self::Never => return false,
64            Self::Daily => 10,
65            Self::Hourly => 13,
66        };
67        suffix.len() == expected_len
68            && suffix.bytes().enumerate().all(|(index, byte)| {
69                let dash = index == 4 || index == 7 || (self == Self::Hourly && index == 10);
70                if dash {
71                    byte == b'-'
72                } else {
73                    byte.is_ascii_digit()
74                }
75            })
76    }
77}
78
79/// Minimal secure rolling writer used by the non-blocking tracing worker.
80/// Every file is opened with `O_NOFOLLOW` and mode `0600` on Unix, including
81/// files created after daily/hourly rotation. This avoids relying on the process
82/// umask and closes the short world-readable window a post-open chmod would have.
83struct SecureUsageWriter {
84    base_path: PathBuf,
85    rotation: UsageRotation,
86    keep_days: usize,
87    active_period: Option<String>,
88    active_path: PathBuf,
89    file: File,
90}
91
92impl SecureUsageWriter {
93    fn new(base_path: PathBuf, rotation: UsageRotation, keep_days: usize) -> io::Result<Self> {
94        let parent = log_parent(&base_path);
95        create_log_directory(parent)?;
96        validate_log_file_name(&base_path)?;
97
98        let active_period = rotation.period(OffsetDateTime::now_utc());
99        let active_path = rotated_path(&base_path, active_period.as_deref())?;
100        let file = open_secure_log_file(&active_path)?;
101        let writer = Self { base_path, rotation, keep_days, active_period, active_path, file };
102        writer.prune_old_logs()?;
103        Ok(writer)
104    }
105
106    fn rotate_if_needed(&mut self) -> io::Result<()> {
107        let period = self.rotation.period(OffsetDateTime::now_utc());
108        if period == self.active_period {
109            return Ok(());
110        }
111
112        let path = rotated_path(&self.base_path, period.as_deref())?;
113        let file = open_secure_log_file(&path)?;
114        self.file = file;
115        self.active_path = path;
116        self.active_period = period;
117        self.prune_old_logs()
118    }
119
120    fn prune_old_logs(&self) -> io::Result<()> {
121        let Some(max_files) = self.rotation.max_files(self.keep_days) else {
122            return Ok(());
123        };
124        let parent = log_parent(&self.base_path);
125        let base_name = validate_log_file_name(&self.base_path)?;
126        let prefix = format!("{base_name}.");
127        let mut candidates = Vec::new();
128
129        for entry in fs::read_dir(parent)? {
130            let entry = entry?;
131            let file_type = entry.file_type()?;
132            if !file_type.is_file() || file_type.is_symlink() {
133                continue;
134            }
135            let Some(name) = entry.file_name().to_str().map(ToString::to_string) else {
136                continue;
137            };
138            let Some(period) = name.strip_prefix(&prefix) else {
139                continue;
140            };
141            if self.rotation.valid_period(period) {
142                candidates.push((name, entry.path()));
143            }
144        }
145
146        candidates.sort_by(|left, right| left.0.cmp(&right.0));
147        let remove_count = candidates.len().saturating_sub(max_files);
148        for (_, path) in candidates.into_iter().take(remove_count) {
149            fs::remove_file(path)?;
150        }
151        Ok(())
152    }
153}
154
155impl Write for SecureUsageWriter {
156    fn write(&mut self, buffer: &[u8]) -> io::Result<usize> {
157        self.rotate_if_needed()?;
158        self.file.write(buffer)
159    }
160
161    fn flush(&mut self) -> io::Result<()> {
162        self.file.flush()
163    }
164}
165
166/// Install the stderr subscriber plus an optional JSONL usage-event sink.
167///
168/// `WINX_USAGE_LOG` enables a non-blocking file writer filtered to the
169/// `winx::usage` target. The sink never receives command text or file contents.
170/// Call this only after the optional Landlock domain has been applied so the
171/// writer thread inherits the same filesystem restrictions as every other child.
172pub fn initialize(verbose: bool, debug: bool) -> Result<LoggingGuard> {
173    initialize_inner(verbose, debug, true)
174}
175
176/// Install stderr logging without opening or rotating the usage sink. Offline
177/// inspection commands use this so observing logs cannot mutate them.
178pub fn initialize_without_usage(verbose: bool, debug: bool) -> Result<LoggingGuard> {
179    initialize_inner(verbose, debug, false)
180}
181
182fn initialize_inner(verbose: bool, debug: bool, usage_enabled: bool) -> Result<LoggingGuard> {
183    let level = if debug {
184        tracing::Level::DEBUG
185    } else if verbose {
186        tracing::Level::INFO
187    } else {
188        tracing::Level::WARN
189    };
190    let filter = tracing_subscriber::EnvFilter::from_default_env().add_directive(level.into());
191    let filter = match "winx::usage=info".parse() {
192        Ok(directive) => filter.add_directive(directive),
193        Err(_) => filter,
194    };
195    let stderr_json = crate::config::env_text("WINX_LOG_FORMAT")
196        .is_some_and(|format| format.eq_ignore_ascii_case("json"));
197    let usage = if usage_enabled { usage_log_writer()? } else { None };
198
199    let guard = match (stderr_json, usage) {
200        (true, Some((writer, guard))) => {
201            tracing_subscriber::registry()
202                .with(
203                    tracing_subscriber::fmt::layer()
204                        .json()
205                        .with_ansi(false)
206                        .with_writer(std::io::stderr)
207                        .with_filter(filter),
208                )
209                .with(usage_json_layer(writer))
210                .init();
211            Some(guard)
212        }
213        (false, Some((writer, guard))) => {
214            tracing_subscriber::registry()
215                .with(
216                    tracing_subscriber::fmt::layer()
217                        .with_ansi(true)
218                        .with_writer(std::io::stderr)
219                        .with_filter(filter),
220                )
221                .with(usage_json_layer(writer))
222                .init();
223            Some(guard)
224        }
225        (true, None) => {
226            tracing_subscriber::registry()
227                .with(
228                    tracing_subscriber::fmt::layer()
229                        .json()
230                        .with_ansi(false)
231                        .with_writer(std::io::stderr)
232                        .with_filter(filter),
233                )
234                .init();
235            None
236        }
237        (false, None) => {
238            tracing_subscriber::registry()
239                .with(
240                    tracing_subscriber::fmt::layer()
241                        .with_ansi(true)
242                        .with_writer(std::io::stderr)
243                        .with_filter(filter),
244                )
245                .init();
246            None
247        }
248    };
249    Ok(LoggingGuard { _usage: guard })
250}
251
252fn usage_json_layer<S>(writer: NonBlocking) -> impl tracing_subscriber::Layer<S>
253where
254    S: tracing::Subscriber + for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>,
255{
256    tracing_subscriber::fmt::layer()
257        .json()
258        .with_ansi(false)
259        .with_current_span(false)
260        .with_span_list(false)
261        .with_writer(writer)
262        .with_filter(filter_fn(|metadata| metadata.target() == "winx::usage"))
263}
264
265fn usage_log_writer() -> Result<Option<(NonBlocking, WorkerGuard)>> {
266    let Some(path) = crate::config::env_text("WINX_USAGE_LOG").map(PathBuf::from) else {
267        return Ok(None);
268    };
269    let rotation =
270        UsageRotation::parse(crate::config::env_text("WINX_USAGE_LOG_ROTATION").as_deref())?;
271    let keep_days = parse_keep_days()?;
272    let writer = SecureUsageWriter::new(path.clone(), rotation, keep_days).map_err(|error| {
273        WinxError::ConfigurationError(format!(
274            "cannot open WINX_USAGE_LOG {} securely: {error}",
275            path.display()
276        ))
277    })?;
278    Ok(Some(NonBlockingBuilder::default().thread_name("winx-usage-log").finish(writer)))
279}
280
281fn log_parent(path: &Path) -> &Path {
282    path.parent().filter(|parent| !parent.as_os_str().is_empty()).unwrap_or(Path::new("."))
283}
284
285fn validate_log_file_name(path: &Path) -> io::Result<&str> {
286    path.file_name().and_then(|name| name.to_str()).ok_or_else(|| {
287        io::Error::new(
288            io::ErrorKind::InvalidInput,
289            format!("usage log path must name a UTF-8 file: {}", path.display()),
290        )
291    })
292}
293
294fn rotated_path(base_path: &Path, period: Option<&str>) -> io::Result<PathBuf> {
295    let Some(period) = period else {
296        return Ok(base_path.to_path_buf());
297    };
298    let name = validate_log_file_name(base_path)?;
299    Ok(base_path.with_file_name(format!("{name}.{period}")))
300}
301
302fn create_log_directory(path: &Path) -> io::Result<()> {
303    #[cfg(unix)]
304    {
305        let mut builder = fs::DirBuilder::new();
306        builder.recursive(true).mode(0o700).create(path)
307    }
308    #[cfg(not(unix))]
309    {
310        fs::create_dir_all(path)
311    }
312}
313
314fn open_secure_log_file(path: &Path) -> io::Result<File> {
315    #[cfg(unix)]
316    {
317        let file = OpenOptions::new()
318            .append(true)
319            .create(true)
320            .mode(0o600)
321            .custom_flags(libc::O_NOFOLLOW | libc::O_CLOEXEC)
322            .open(path)?;
323        let metadata = file.metadata()?;
324        if !metadata.is_file() {
325            return Err(io::Error::new(
326                io::ErrorKind::InvalidInput,
327                format!("usage log is not a regular file: {}", path.display()),
328            ));
329        }
330        let mut permissions = metadata.permissions();
331        if permissions.mode() & 0o777 != 0o600 {
332            permissions.set_mode(0o600);
333            file.set_permissions(permissions)?;
334        }
335        Ok(file)
336    }
337    #[cfg(not(unix))]
338    {
339        let file = OpenOptions::new().append(true).create(true).open(path)?;
340        if !file.metadata()?.is_file() {
341            return Err(io::Error::new(
342                io::ErrorKind::InvalidInput,
343                format!("usage log is not a regular file: {}", path.display()),
344            ));
345        }
346        Ok(file)
347    }
348}
349
350fn parse_keep_days() -> Result<usize> {
351    let Some(raw) = crate::config::env_text("WINX_USAGE_LOG_KEEP_DAYS") else {
352        return Ok(7);
353    };
354    let days = raw.parse::<usize>().map_err(|error| {
355        WinxError::ConfigurationError(format!("invalid WINX_USAGE_LOG_KEEP_DAYS={raw:?}: {error}"))
356    })?;
357    if days > 3_650 {
358        return Err(WinxError::ConfigurationError(
359            "WINX_USAGE_LOG_KEEP_DAYS must be between 0 and 3650".to_string(),
360        ));
361    }
362    Ok(days)
363}
364
365#[cfg(test)]
366mod tests {
367    #![allow(clippy::unwrap_used)]
368
369    #[cfg(unix)]
370    use super::SecureUsageWriter;
371    use super::UsageRotation;
372    #[cfg(unix)]
373    use std::io::Write as _;
374
375    #[test]
376    fn usage_rotation_retention_is_bounded_and_explicit() {
377        assert!(matches!(UsageRotation::parse(None), Ok(UsageRotation::Daily)));
378        assert_eq!(UsageRotation::Daily.max_files(7), Some(8));
379        assert_eq!(UsageRotation::Hourly.max_files(2), Some(49));
380        assert_eq!(UsageRotation::Never.max_files(7), None);
381        assert_eq!(UsageRotation::Daily.max_files(0), None);
382    }
383
384    #[cfg(unix)]
385    #[test]
386    fn usage_files_are_private_for_initial_and_rotated_names() {
387        use std::os::unix::fs::PermissionsExt as _;
388
389        for rotation in [UsageRotation::Never, UsageRotation::Daily, UsageRotation::Hourly] {
390            let root = tempfile::tempdir().unwrap();
391            let nested = root.path().join("private/state");
392            let base = nested.join("usage.jsonl");
393            let mut writer = SecureUsageWriter::new(base, rotation, 1).unwrap();
394            writer.write_all(b"{}\n").unwrap();
395            writer.flush().unwrap();
396
397            let mode = writer.active_path.metadata().unwrap().permissions().mode() & 0o777;
398            assert_eq!(mode, 0o600, "{}", writer.active_path.display());
399            let directory_mode = nested.metadata().unwrap().permissions().mode() & 0o777;
400            assert_eq!(directory_mode, 0o700, "{}", nested.display());
401
402            if rotation != UsageRotation::Never {
403                let rotated_path = writer.active_path.clone();
404                std::fs::remove_file(&rotated_path).unwrap();
405                writer.active_period = Some("1970-01-01-00".to_string());
406                writer.write_all(b"rotated\n").unwrap();
407                writer.flush().unwrap();
408                let rotated_mode = rotated_path.metadata().unwrap().permissions().mode() & 0o777;
409                assert_eq!(rotated_mode, 0o600, "{}", rotated_path.display());
410            }
411        }
412    }
413
414    #[cfg(unix)]
415    #[test]
416    fn existing_usage_file_is_tightened_and_symlink_is_rejected() {
417        use std::os::unix::fs::{symlink, PermissionsExt as _};
418
419        let root = tempfile::tempdir().unwrap();
420        let existing = root.path().join("existing.jsonl");
421        std::fs::write(&existing, b"old\n").unwrap();
422        std::fs::set_permissions(&existing, std::fs::Permissions::from_mode(0o644)).unwrap();
423        let writer = SecureUsageWriter::new(existing.clone(), UsageRotation::Never, 0).unwrap();
424        let mode = writer.active_path.metadata().unwrap().permissions().mode() & 0o777;
425        assert_eq!(mode, 0o600);
426        drop(writer);
427
428        let target = root.path().join("target.jsonl");
429        std::fs::write(&target, b"target\n").unwrap();
430        let link = root.path().join("link.jsonl");
431        symlink(&target, &link).unwrap();
432        assert!(SecureUsageWriter::new(link, UsageRotation::Never, 0).is_err());
433    }
434}
winx_code_agent/logging.rs

winx_code_agent/
logging.rs
