Skip to main content

a3s_box_core/
log.rs

1//! Logging driver types and configuration.
2
3use serde::{Deserialize, Serialize};
4use std::collections::HashMap;
5
6/// Logging driver type.
7#[derive(Debug, Clone, Default, PartialEq, Eq, Serialize, Deserialize)]
8#[serde(rename_all = "kebab-case")]
9pub enum LogDriver {
10    /// Docker-compatible JSON lines format (default).
11    #[default]
12    JsonFile,
13    /// Forward logs to a syslog endpoint.
14    ///
15    /// Options:
16    /// - `syslog-address`: UDP/TCP address (e.g., "udp://localhost:514")
17    /// - `syslog-facility`: Syslog facility (default: "daemon")
18    /// - `tag`: Log tag template (default: box name)
19    Syslog,
20    /// Disable logging entirely.
21    None,
22}
23
24impl std::fmt::Display for LogDriver {
25    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
26        match self {
27            Self::JsonFile => write!(f, "json-file"),
28            Self::Syslog => write!(f, "syslog"),
29            Self::None => write!(f, "none"),
30        }
31    }
32}
33
34impl std::str::FromStr for LogDriver {
35    type Err = String;
36
37    fn from_str(s: &str) -> std::result::Result<Self, Self::Err> {
38        match s {
39            "json-file" => Ok(Self::JsonFile),
40            "syslog" => Ok(Self::Syslog),
41            "none" => Ok(Self::None),
42            _ => Err(format!(
43                "unknown log driver: '{}' (supported: json-file, syslog, none)",
44                s
45            )),
46        }
47    }
48}
49
50/// Logging configuration for a box.
51#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
52pub struct LogConfig {
53    pub driver: LogDriver,
54    #[serde(default)]
55    pub options: HashMap<String, String>,
56}
57
58impl Default for LogConfig {
59    fn default() -> Self {
60        Self {
61            driver: LogDriver::JsonFile,
62            options: HashMap::new(),
63        }
64    }
65}
66
67impl LogConfig {
68    /// Maximum log file size in bytes before rotation.
69    /// Default: 10 MiB. Set via `max-size` option (e.g., "10m", "1g").
70    pub fn max_size(&self) -> u64 {
71        self.options
72            .get("max-size")
73            .and_then(|s| parse_size(s).ok())
74            .unwrap_or(10 * 1024 * 1024)
75    }
76
77    /// Maximum number of rotated log files to keep.
78    /// Default: 3. Set via `max-file` option.
79    pub fn max_file(&self) -> u32 {
80        self.options
81            .get("max-file")
82            .and_then(|s| s.parse().ok())
83            .unwrap_or(3)
84    }
85
86    /// Syslog address (e.g., "udp://localhost:514").
87    /// Only relevant when driver is `Syslog`.
88    pub fn syslog_address(&self) -> &str {
89        self.options
90            .get("syslog-address")
91            .map(|s| s.as_str())
92            .unwrap_or("udp://localhost:514")
93    }
94
95    /// Syslog facility (e.g., "daemon", "local0").
96    /// Only relevant when driver is `Syslog`.
97    pub fn syslog_facility(&self) -> &str {
98        self.options
99            .get("syslog-facility")
100            .map(|s| s.as_str())
101            .unwrap_or("daemon")
102    }
103
104    /// Log tag (used by syslog driver as the program name).
105    pub fn tag(&self) -> Option<&str> {
106        self.options.get("tag").map(|s| s.as_str())
107    }
108}
109
110/// A single structured log entry (Docker-compatible JSON format).
111#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
112pub struct LogEntry {
113    /// The log message (including trailing newline).
114    pub log: String,
115    /// The output stream: "stdout" or "stderr".
116    pub stream: String,
117    /// RFC 3339 timestamp with nanosecond precision.
118    pub time: String,
119}
120
121/// Schema used to hand one Sandbox log worker its immutable generation data.
122pub const SANDBOX_LOG_WORKER_SCHEMA: &str = "a3s.box.sandbox-log-worker.v1";
123
124/// Configuration for the host process that projects Sandbox stdout/stderr into
125/// the configured logging driver after the launching client has detached.
126///
127/// The worker watches the exact `crun run` wrapper PID identity. Once that
128/// process exits, both inherited output descriptors are closed and EOF is
129/// authoritative, so the worker can drain the final bytes without a fixed
130/// late-write delay.
131#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
132pub struct SandboxLogWorkerSpec {
133    pub schema: String,
134    pub box_id: String,
135    pub console_log: PathBuf,
136    pub log_config: LogConfig,
137    pub watched_pid: u32,
138    pub watched_pid_start_time: u64,
139    pub ready_file: PathBuf,
140}
141
142/// Parse a human-readable size string (e.g., "10m", "1g", "4096") into bytes.
143fn parse_size(s: &str) -> std::result::Result<u64, String> {
144    let s = s.trim().to_lowercase();
145    if let Ok(n) = s.parse::<u64>() {
146        return Ok(n);
147    }
148    let (num, mult) = if s.ends_with("gb") || s.ends_with('g') {
149        (
150            s.trim_end_matches("gb").trim_end_matches('g'),
151            1024u64 * 1024 * 1024,
152        )
153    } else if s.ends_with("mb") || s.ends_with('m') {
154        (
155            s.trim_end_matches("mb").trim_end_matches('m'),
156            1024u64 * 1024,
157        )
158    } else if s.ends_with("kb") || s.ends_with('k') {
159        (s.trim_end_matches("kb").trim_end_matches('k'), 1024u64)
160    } else if s.ends_with('b') {
161        (s.trim_end_matches('b'), 1u64)
162    } else {
163        return Err(format!("unrecognized size format: {s}"));
164    };
165    let n: u64 = num.parse().map_err(|_| format!("invalid number: {num}"))?;
166    Ok(n * mult)
167}
168
169// ===========================================================================
170// Log processor — tails the VM console (`console.log`) and produces structured
171// Docker-compatible output (`container.json`) or forwards to syslog.
172//
173// This runs in the SHIM (the box's own per-process lifetime), not the ephemeral
174// CLI: the CLI exits on `run -d` detach, which would kill an in-CLI processor
175// and truncate the logs. The shim writes `console.log` and lives exactly as
176// long as the VM, so it is the correct, daemonless home (like containerd-shim).
177// ===========================================================================
178
179use std::io::{BufRead, BufReader, Seek, Write};
180use std::path::{Path, PathBuf};
181use std::sync::atomic::{AtomicBool, Ordering};
182
183#[cfg(target_os = "windows")]
184type ConsoleFileIdentity = crate::windows_file::WindowsFileIdentity;
185#[cfg(not(target_os = "windows"))]
186type ConsoleFileIdentity = ();
187
188/// Whether the producer may still publish bytes after its apparent exit.
189///
190/// libkrun can return before its console backend's final host write becomes
191/// visible, whereas a reaped `crun run` wrapper has already closed stdout and
192/// stderr. Keeping the distinction explicit avoids imposing the MicroVM's
193/// half-second settle window on every short Sandbox execution.
194#[derive(Debug, Clone, Copy, PartialEq, Eq)]
195pub enum ConsoleEofPolicy {
196    MayReceiveLateWrites,
197    WriterClosed,
198}
199
200/// Truncate `path` to empty if it has grown past `cap` bytes; returns whether it
201/// truncated.
202///
203/// libkrun appends the guest console to the raw `console.log`/`console.err.log`
204/// for the VM's entire lifetime, so a chatty long-running box grows them without
205/// limit — only the rotated `container.json` was ever bounded. The tail loop
206/// calls this at a clean line boundary (every line so far is already durable in
207/// `container.json`), so truncation never drops queryable log data. libkrun
208/// holds the file `O_APPEND`, so its next write resumes at offset 0 — no hole.
209fn console_truncate_if_over(
210    path: &Path,
211    cap: u64,
212    expected_identity: Option<ConsoleFileIdentity>,
213) -> bool {
214    #[cfg(not(target_os = "windows"))]
215    let _ = expected_identity;
216
217    #[cfg(target_os = "windows")]
218    let file = crate::windows_file::open_regular_file_for_write(path, expected_identity)
219        .map(|(file, _)| file);
220    #[cfg(not(target_os = "windows"))]
221    let file = std::fs::OpenOptions::new().write(true).open(path);
222
223    let Ok(file) = file else {
224        return false;
225    };
226    if file
227        .metadata()
228        .map_or(true, |metadata| metadata.len() <= cap)
229    {
230        return false;
231    }
232    if file.set_len(0).is_ok() {
233        tracing::debug!(path = %path.display(), cap, "console log exceeded cap; truncated");
234        true
235    } else {
236        false
237    }
238}
239
240/// Path to the structured JSON log file inside a box's log dir.
241pub fn json_log_path(log_dir: &Path) -> PathBuf {
242    log_dir.join("container.json")
243}
244
245/// The phase-aware filter for libkrun's C-init console preamble.
246///
247/// C-init emits a small, fixed set of diagnostics before calling `execvp`.
248/// stdout and stderr must share one instance: the `execvp(...) starting` line
249/// can arrive on either stream and permanently ends filtering for both. Once
250/// that sentinel has been observed, every subsequent line is workload output,
251/// even if it has the same text as a preamble line.
252#[derive(Debug)]
253pub struct RuntimeConsoleFilter {
254    preamble_active: AtomicBool,
255}
256
257impl RuntimeConsoleFilter {
258    pub fn new() -> Self {
259        Self {
260            preamble_active: AtomicBool::new(true),
261        }
262    }
263
264    /// Return whether `line` should be exposed as workload output.
265    ///
266    /// This method expects a complete logical line. Byte-stream callers must
267    /// retain an unterminated final fragment rather than classify it.
268    pub fn keep_line(&self, line: &str) -> bool {
269        if !self.preamble_active.load(Ordering::Acquire) {
270            return true;
271        }
272
273        match classify_runtime_console_line(line) {
274            RuntimeConsoleLineKind::Workload => true,
275            RuntimeConsoleLineKind::Preamble => {
276                // A sentinel on the companion stream may have ended the phase
277                // after our first load. Recheck so completed sentinel calls
278                // globally disable filtering.
279                !self.preamble_active.load(Ordering::Acquire)
280            }
281            RuntimeConsoleLineKind::EndPreamble => {
282                // Exactly one concurrent sentinel ends the phase and is
283                // hidden. A sentinel-shaped workload line after that is kept.
284                !self.preamble_active.swap(false, Ordering::AcqRel)
285            }
286        }
287    }
288
289    pub fn preamble_active(&self) -> bool {
290        self.preamble_active.load(Ordering::Acquire)
291    }
292}
293
294impl Default for RuntimeConsoleFilter {
295    fn default() -> Self {
296        Self::new()
297    }
298}
299
300#[derive(Debug, Clone, Copy, PartialEq, Eq)]
301enum RuntimeConsoleLineKind {
302    Workload,
303    Preamble,
304    EndPreamble,
305}
306
307fn classify_runtime_console_line(line: &str) -> RuntimeConsoleLineKind {
308    let line = line.trim_end_matches(['\n', '\r']);
309
310    if matches!(
311        line,
312        "init.krun: mount_filesystems ok"
313            | "init.krun: root propagation ok"
314            | "init.krun: tty/session configured"
315            | "init.krun: config parsed"
316            | "init.krun: setup_redirects ok"
317    ) {
318        return RuntimeConsoleLineKind::Preamble;
319    }
320
321    if line
322        .strip_prefix("init.krun: entered main argc=")
323        .is_some_and(is_ascii_decimal)
324    {
325        return RuntimeConsoleLineKind::Preamble;
326    }
327
328    if let Some(fields) = line.strip_prefix("init.krun: after cmdline env import KRUN_INIT=") {
329        if let Some((krun_init, fields)) = fields.split_once(" KRUN_INIT_PID1=") {
330            if let Some((krun_init_pid1, box_exec_exec)) = fields.split_once(" BOX_EXEC_EXEC=") {
331                if [krun_init, krun_init_pid1, box_exec_exec]
332                    .iter()
333                    .all(|value| !value.is_empty())
334                {
335                    return RuntimeConsoleLineKind::Preamble;
336                }
337            }
338        }
339    }
340
341    if let Some(selected) = line.strip_prefix("init.krun: selected exec=") {
342        if let Some((executable, init_pid1)) = selected.rsplit_once(" init_pid1=") {
343            if !executable.is_empty() && matches!(init_pid1, "0" | "1") {
344                return RuntimeConsoleLineKind::Preamble;
345            }
346        }
347    }
348
349    if line
350        .strip_prefix("init.krun: execvp(")
351        .and_then(|rest| rest.strip_suffix(") starting"))
352        .is_some_and(|executable| !executable.is_empty())
353    {
354        return RuntimeConsoleLineKind::EndPreamble;
355    }
356
357    RuntimeConsoleLineKind::Workload
358}
359
360fn is_ascii_decimal(value: &str) -> bool {
361    !value.is_empty() && value.bytes().all(|byte| byte.is_ascii_digit())
362}
363
364/// True only for a line matching the known C-init preamble grammar.
365///
366/// This compatibility helper is phase-unaware. Consumers processing a stream
367/// should instead share one [`RuntimeConsoleFilter`] across stdout and stderr.
368pub fn is_runtime_console_noise(line: &str) -> bool {
369    classify_runtime_console_line(line) != RuntimeConsoleLineKind::Workload
370}
371
372/// Read the next COMPLETE line from a tailed `console.log`, returning it without
373/// the trailing newline. Polls on EOF like `tail -f` (so lines a container logs
374/// after a quiet period are not dropped), accumulating a partial line across
375/// reads. Returns `None` only when `stop` is set AND EOF is reached — i.e. the
376/// VM has exited and `console.log` is fully drained — flushing any final partial
377/// line as the last value before the subsequent `None`.
378fn tail_next_line_with_completeness<R: BufRead + Seek>(
379    reader: &mut R,
380    buf: &mut String,
381    stop: &AtomicBool,
382    on_eof: Option<&dyn Fn() -> bool>,
383    eof_policy: ConsoleEofPolicy,
384    reopen_at_eof: Option<&dyn Fn(u64) -> Option<(R, u64)>>,
385) -> Option<(String, bool)> {
386    // `krun_start_enter()` can return a few scheduler ticks before the
387    // virtio-console backend's final host write becomes visible. Treat the
388    // first stopped EOFs as provisional; otherwise a very short detached
389    // command can leave bytes in console.log after the processor has exited.
390    const STOPPED_EOF_SETTLE_MILLIS: u64 = 20;
391    let stopped_eof_settle_polls = stopped_eof_settle_polls(eof_policy);
392    let mut stopped_eof_polls = 0u8;
393    let mut refreshed_after_stop = false;
394    loop {
395        match reader.read_line(buf) {
396            Ok(0) | Err(_) => {
397                // Caught up at a clean line boundary (no partial line buffered):
398                // let the caller bound the file's growth. If it truncated, seek
399                // back to the start so reads don't sit forever past a stale EOF.
400                let mut position = reader.stream_position().ok();
401                if buf.is_empty() {
402                    if let Some(on_eof) = on_eof {
403                        if on_eof() {
404                            let _ = reader.seek(std::io::SeekFrom::Start(0));
405                            position = Some(0);
406                        }
407                    }
408                }
409
410                let stopping = stop.load(Ordering::Relaxed);
411
412                // Windows shared-filesystem producers can replace the path or
413                // append through a handle whose updates remain invisible to a
414                // reader already parked at EOF. Path metadata may be cached as
415                // well, so reopen unconditionally after each polling interval.
416                // On shutdown, perform a fresh-handle read before each
417                // late-write settle poll before declaring the source drained.
418                if let (Some(position), Some(reopen_at_eof)) = (position, reopen_at_eof) {
419                    if !(stopping && refreshed_after_stop) {
420                        if !stopping {
421                            std::thread::sleep(std::time::Duration::from_millis(100));
422                        }
423                        if let Some((mut replacement, replacement_position)) =
424                            reopen_at_eof(position)
425                        {
426                            if replacement_position != position {
427                                buf.clear();
428                            }
429                            std::mem::swap(reader, &mut replacement);
430                            refreshed_after_stop = stopping;
431                            continue;
432                        }
433                    }
434                }
435
436                if stopping {
437                    stopped_eof_polls = stopped_eof_polls.saturating_add(1);
438                    if stopped_eof_polls < stopped_eof_settle_polls {
439                        // A later poll must use another fresh Windows handle;
440                        // the producer may have replaced or appended the path.
441                        refreshed_after_stop = false;
442                        std::thread::sleep(std::time::Duration::from_millis(
443                            STOPPED_EOF_SETTLE_MILLIS,
444                        ));
445                        continue;
446                    }
447                    // The producer has stopped and the current path is drained:
448                    // flush a trailing partial line once, then finish.
449                    if buf.is_empty() {
450                        return None;
451                    }
452                    let line = std::mem::take(buf);
453                    return Some((line.trim_end_matches(['\n', '\r']).to_string(), false));
454                }
455                if reopen_at_eof.is_none() {
456                    std::thread::sleep(std::time::Duration::from_millis(100));
457                }
458                continue;
459            }
460            Ok(_) => {
461                stopped_eof_polls = 0;
462                refreshed_after_stop = false;
463            }
464        }
465        if !buf.ends_with('\n') {
466            // Partial line at EOF — keep it buffered and wait for the rest.
467            continue;
468        }
469        let line = std::mem::take(buf);
470        return Some((line.trim_end_matches(['\n', '\r']).to_string(), true));
471    }
472}
473
474#[cfg(test)]
475fn tail_next_line<R: BufRead + Seek>(
476    reader: &mut R,
477    buf: &mut String,
478    stop: &AtomicBool,
479    on_eof: Option<&dyn Fn() -> bool>,
480    eof_policy: ConsoleEofPolicy,
481    reopen_at_eof: Option<&dyn Fn(u64) -> Option<(R, u64)>>,
482) -> Option<String> {
483    tail_next_line_with_completeness(reader, buf, stop, on_eof, eof_policy, reopen_at_eof)
484        .map(|(line, _complete)| line)
485}
486
487fn stopped_eof_settle_polls(eof_policy: ConsoleEofPolicy) -> u8 {
488    const LATE_WRITE_POLLS: u8 = 25;
489    match eof_policy {
490        ConsoleEofPolicy::MayReceiveLateWrites => LATE_WRITE_POLLS,
491        ConsoleEofPolicy::WriterClosed => 1,
492    }
493}
494
495/// Run the log processor for a box, blocking until `stop` is set and the console
496/// is drained. Intended to run on a dedicated thread for the VM's lifetime; set
497/// `stop` after the VM exits, then join, to guarantee the final lines are
498/// captured (no teardown race).
499pub fn run_log_processor(
500    console_log: &Path,
501    log_dir: &Path,
502    config: &LogConfig,
503    stop: &AtomicBool,
504) {
505    run_log_processor_with_ready(console_log, log_dir, config, stop, None);
506}
507
508/// Run the processor and optionally count each console reader once it has
509/// opened its file. A VM launcher can wait for two ready readers before start,
510/// preventing a short guest from exiting before the tail threads are alive.
511pub fn run_log_processor_with_ready(
512    console_log: &Path,
513    log_dir: &Path,
514    config: &LogConfig,
515    stop: &AtomicBool,
516    ready: Option<&std::sync::atomic::AtomicUsize>,
517) {
518    run_log_processor_with_ready_and_eof_policy(
519        console_log,
520        log_dir,
521        config,
522        stop,
523        ready,
524        ConsoleEofPolicy::MayReceiveLateWrites,
525    );
526}
527
528/// Run the log processor with an explicit final-EOF policy.
529///
530/// Sandbox workers use [`ConsoleEofPolicy::WriterClosed`] only after the exact
531/// `crun run` wrapper has exited. Other callers should retain the conservative
532/// default exposed by [`run_log_processor_with_ready`].
533pub fn run_log_processor_with_ready_and_eof_policy(
534    console_log: &Path,
535    log_dir: &Path,
536    config: &LogConfig,
537    stop: &AtomicBool,
538    ready: Option<&std::sync::atomic::AtomicUsize>,
539    eof_policy: ConsoleEofPolicy,
540) {
541    let stderr_log = stderr_console_path(console_log);
542    run_log_processor_streams_with_ready_and_eof_policy(
543        console_log,
544        &stderr_log,
545        log_dir,
546        config,
547        stop,
548        ready,
549        eof_policy,
550    );
551}
552
553/// Run the log processor against explicitly selected stdout and stderr files.
554///
555/// Most VMM backends write the conventional `console.log` and
556/// `console.err.log` pair, which [`run_log_processor`] discovers automatically.
557/// Backends that persist completed guest streams elsewhere can use this entry
558/// point to process exactly those files without replaying an older raw console.
559pub fn run_log_processor_streams(
560    stdout_log: &Path,
561    stderr_log: &Path,
562    log_dir: &Path,
563    config: &LogConfig,
564    stop: &AtomicBool,
565) {
566    run_log_processor_streams_with_ready_and_eof_policy(
567        stdout_log,
568        stderr_log,
569        log_dir,
570        config,
571        stop,
572        None,
573        ConsoleEofPolicy::WriterClosed,
574    );
575}
576
577/// Run the log processor against live, explicitly selected stdout and stderr
578/// files, optionally counting each reader after its source has been opened.
579///
580/// This is the explicit-stream counterpart to [`run_log_processor_with_ready`]
581/// and retains the conservative late-write settle policy for live producers.
582pub fn run_log_processor_streams_with_ready(
583    stdout_log: &Path,
584    stderr_log: &Path,
585    log_dir: &Path,
586    config: &LogConfig,
587    stop: &AtomicBool,
588    ready: Option<&std::sync::atomic::AtomicUsize>,
589) {
590    run_log_processor_streams_with_ready_and_eof_policy(
591        stdout_log,
592        stderr_log,
593        log_dir,
594        config,
595        stop,
596        ready,
597        ConsoleEofPolicy::MayReceiveLateWrites,
598    );
599}
600
601fn run_log_processor_streams_with_ready_and_eof_policy(
602    stdout_log: &Path,
603    stderr_log: &Path,
604    log_dir: &Path,
605    config: &LogConfig,
606    stop: &AtomicBool,
607    ready: Option<&std::sync::atomic::AtomicUsize>,
608    eof_policy: ConsoleEofPolicy,
609) {
610    match config.driver {
611        // `none` produces no structured output, but libkrun still writes the raw
612        // console for the VM's lifetime — drain + bound it so a chatty box with
613        // logging disabled doesn't fill the disk (same hazard as the other
614        // drivers).
615        LogDriver::None => run_discard_processor(
616            stdout_log,
617            stderr_log,
618            Some(console_cap(config.max_size(), config.max_file())),
619            stop,
620            ready,
621            eof_policy,
622        ),
623        LogDriver::JsonFile => run_json_file_processor(
624            stdout_log, stderr_log, log_dir, config, stop, ready, eof_policy,
625        ),
626        LogDriver::Syslog => {
627            run_syslog_processor(stdout_log, stderr_log, config, stop, ready, eof_policy)
628        }
629    }
630}
631
632/// Wait (bounded) for `console.log` to appear, then open it. Returns `None` if it
633/// never shows up or `stop` fires first.
634fn open_console(
635    console_log: &Path,
636    stop: &AtomicBool,
637) -> Option<(std::fs::File, ConsoleFileIdentity)> {
638    for _ in 0..300 {
639        #[cfg(target_os = "windows")]
640        match crate::windows_file::open_regular_file(console_log, None) {
641            Ok(opened) => return Some(opened),
642            Err(error) if error.kind() == std::io::ErrorKind::NotFound => {}
643            Err(error) => {
644                tracing::warn!(path = %console_log.display(), %error, "Refusing unsafe Windows console source");
645                return None;
646            }
647        }
648        #[cfg(not(target_os = "windows"))]
649        match std::fs::File::open(console_log) {
650            Ok(file) => return Some((file, ())),
651            Err(error) if error.kind() == std::io::ErrorKind::NotFound => {}
652            Err(_) => return None,
653        }
654        if stop.load(Ordering::Relaxed) && !console_log.exists() {
655            return None;
656        }
657        std::thread::sleep(std::time::Duration::from_millis(100));
658    }
659    None
660}
661
662#[cfg(target_os = "windows")]
663fn reopen_console(
664    console_log: &Path,
665    position: u64,
666    expected_identity: ConsoleFileIdentity,
667) -> Option<(BufReader<std::fs::File>, u64)> {
668    let (mut file, _) =
669        crate::windows_file::open_regular_file(console_log, Some(expected_identity)).ok()?;
670    let visible_len = file.seek(std::io::SeekFrom::End(0)).ok()?;
671    let replacement_position = if visible_len < position { 0 } else { position };
672    file.seek(std::io::SeekFrom::Start(replacement_position))
673        .ok()?;
674    Some((BufReader::new(file), replacement_position))
675}
676
677/// Tail console.log and write one Docker-style JSON record per container line.
678/// The stderr companion to `console.log` (libkrun's 3-fd console sends guest
679/// stderr here, stdout to `console.log`).
680pub fn stderr_console_path(console_log: &Path) -> PathBuf {
681    console_log.with_file_name("console.err.log")
682}
683
684/// Tail one console file, emitting each container line via `emit(line, stream)`.
685/// `runtime_filter` drops the strict libkrun C-init preamble. Both stream
686/// tailers share the same filter. Blocks until `stop` is set and the file is
687/// drained.
688#[derive(Clone, Copy)]
689struct TaggedTailOptions<'a> {
690    stream: &'static str,
691    runtime_filter: Option<&'a RuntimeConsoleFilter>,
692    bound: Option<u64>,
693    ready: Option<&'a std::sync::atomic::AtomicUsize>,
694    eof_policy: ConsoleEofPolicy,
695}
696
697fn run_tagged_tail(
698    file: &Path,
699    stop: &AtomicBool,
700    emit: &(dyn Fn(&str, &str) + Sync),
701    options: TaggedTailOptions<'_>,
702) {
703    let (f, identity) = match open_console(file, stop) {
704        Some(opened) => opened,
705        None => return,
706    };
707    if let Some(ready) = options.ready {
708        ready.fetch_add(1, Ordering::Release);
709    }
710    let mut reader = BufReader::new(f);
711    let mut buf = String::new();
712    // Bound the raw console file's growth at clean line boundaries (see
713    // console_truncate_if_over). None = unbounded (used by tests).
714    let truncate = options
715        .bound
716        .map(|cap| move || console_truncate_if_over(file, cap, Some(identity)));
717    let on_eof: Option<&dyn Fn() -> bool> = truncate.as_ref().map(|t| t as &dyn Fn() -> bool);
718    #[cfg(target_os = "windows")]
719    let reopen = |position| reopen_console(file, position, identity);
720    #[cfg(target_os = "windows")]
721    let reopen_at_eof = Some(&reopen as &dyn Fn(u64) -> Option<(BufReader<std::fs::File>, u64)>);
722    #[cfg(not(target_os = "windows"))]
723    let reopen_at_eof = None;
724
725    while let Some((line, complete)) = tail_next_line_with_completeness(
726        &mut reader,
727        &mut buf,
728        stop,
729        on_eof,
730        options.eof_policy,
731        reopen_at_eof,
732    ) {
733        if complete
734            && options
735                .runtime_filter
736                .is_some_and(|filter| !filter.keep_line(&line))
737        {
738            continue;
739        }
740        emit(&line, options.stream);
741    }
742}
743
744/// The raw `console.log`/`console.err.log` byte budget before the tail loop
745/// truncates it. Tied to the rotated `container.json` budget (`max_size *
746/// max_file`) so the raw console never outgrows the queryable log it feeds.
747fn console_cap(max_size: u64, max_file: u32) -> u64 {
748    max_size.saturating_mul(u64::from(max_file.max(1)))
749}
750
751/// Drain and bound the console for the `none` driver: tail both console files
752/// (advancing to clean line boundaries) and truncate when over `cap`, emitting
753/// nothing. Without this, `--log-driver none` would leave libkrun's raw
754/// `console.log`/`console.err.log` to grow without limit.
755fn run_discard_processor(
756    console_log: &Path,
757    err_log: &Path,
758    cap: Option<u64>,
759    stop: &AtomicBool,
760    ready: Option<&std::sync::atomic::AtomicUsize>,
761    eof_policy: ConsoleEofPolicy,
762) {
763    let discard = |_line: &str, _stream: &str| {};
764    let discard: &(dyn Fn(&str, &str) + Sync) = &discard;
765    std::thread::scope(|s| {
766        s.spawn(|| {
767            run_tagged_tail(
768                console_log,
769                stop,
770                discard,
771                TaggedTailOptions {
772                    stream: "stdout",
773                    runtime_filter: None,
774                    bound: cap,
775                    ready,
776                    eof_policy,
777                },
778            )
779        });
780        s.spawn(|| {
781            run_tagged_tail(
782                err_log,
783                stop,
784                discard,
785                TaggedTailOptions {
786                    stream: "stderr",
787                    runtime_filter: None,
788                    bound: cap,
789                    ready,
790                    eof_policy,
791                },
792            )
793        });
794    });
795}
796
797fn run_json_file_processor(
798    console_log: &Path,
799    err_log: &Path,
800    log_dir: &Path,
801    config: &LogConfig,
802    stop: &AtomicBool,
803    ready: Option<&std::sync::atomic::AtomicUsize>,
804    eof_policy: ConsoleEofPolicy,
805) {
806    let max_size = config.max_size();
807    let max_file = config.max_file();
808    let json_path = json_log_path(log_dir);
809    let writer = std::sync::Mutex::new(
810        match OrderedJsonWriter::new(&json_path, max_size, max_file) {
811            Ok(writer) => writer,
812            Err(_) => return,
813        },
814    );
815    // Write one tagged JSON record per line; shared by the stdout and stderr
816    // tail threads. Timestamp assignment is inside the same critical section
817    // as the append, so file order cannot invert timestamps across streams.
818    let emit = |line: &str, stream: &str| {
819        if let Ok(mut writer) = writer.lock() {
820            writer.write_entry(line, stream, chrono::Utc::now());
821        }
822    };
823    let emit: &(dyn Fn(&str, &str) + Sync) = &emit;
824
825    let cap = Some(console_cap(max_size, max_file));
826    let runtime_filter = RuntimeConsoleFilter::new();
827    std::thread::scope(|s| {
828        s.spawn(|| {
829            run_tagged_tail(
830                console_log,
831                stop,
832                emit,
833                TaggedTailOptions {
834                    stream: "stdout",
835                    runtime_filter: Some(&runtime_filter),
836                    bound: cap,
837                    ready,
838                    eof_policy,
839                },
840            )
841        });
842        // libkrun's `init.krun:` preamble can land on EITHER stream, so filter
843        // the noise on stderr too.
844        s.spawn(|| {
845            run_tagged_tail(
846                err_log,
847                stop,
848                emit,
849                TaggedTailOptions {
850                    stream: "stderr",
851                    runtime_filter: Some(&runtime_filter),
852                    bound: cap,
853                    ready,
854                    eof_policy,
855                },
856            )
857        });
858    });
859}
860
861struct OrderedJsonWriter {
862    output: RotatingWriter,
863    last_timestamp: Option<chrono::DateTime<chrono::Utc>>,
864}
865
866impl OrderedJsonWriter {
867    fn new(path: &Path, max_size: u64, max_file: u32) -> std::io::Result<Self> {
868        Ok(Self {
869            output: RotatingWriter::new(path, max_size, max_file)?,
870            last_timestamp: None,
871        })
872    }
873
874    fn write_entry(&mut self, line: &str, stream: &str, timestamp: chrono::DateTime<chrono::Utc>) {
875        let timestamp = match &self.last_timestamp {
876            Some(previous) if previous > &timestamp => previous.to_owned(),
877            _ => timestamp,
878        };
879        let entry = LogEntry {
880            log: format!("{line}\n"),
881            stream: stream.to_string(),
882            time: timestamp.to_rfc3339_opts(chrono::SecondsFormat::Nanos, true),
883        };
884        self.last_timestamp = Some(timestamp);
885        if let Ok(json) = serde_json::to_string(&entry) {
886            let _ = self.output.write_line(&json);
887        }
888    }
889}
890
891/// Forward both console streams (stdout + stderr) to a syslog endpoint.
892fn run_syslog_processor(
893    console_log: &Path,
894    err_log: &Path,
895    config: &LogConfig,
896    stop: &AtomicBool,
897    ready: Option<&std::sync::atomic::AtomicUsize>,
898    eof_policy: ConsoleEofPolicy,
899) {
900    use std::net::UdpSocket;
901
902    let address = config.syslog_address();
903    let _facility = config.syslog_facility();
904    let tag = config.tag().unwrap_or("a3s-box");
905    let cap = Some(console_cap(config.max_size(), config.max_file()));
906    let runtime_filter = RuntimeConsoleFilter::new();
907    let (proto, addr) = if let Some(rest) = address.strip_prefix("udp://") {
908        ("udp", rest)
909    } else if let Some(rest) = address.strip_prefix("tcp://") {
910        ("tcp", rest)
911    } else {
912        ("udp", address)
913    };
914    match proto {
915        "udp" => {
916            let socket = match UdpSocket::bind("0.0.0.0:0") {
917                Ok(s) => s,
918                Err(_) => return,
919            };
920            // RFC 3164: <priority>tag: message; daemon(3)*8 + info(6) = 30.
921            let emit = |line: &str, _stream: &str| {
922                let msg = format!("<30>{tag}: {line}");
923                let _ = socket.send_to(msg.as_bytes(), addr);
924            };
925            let emit: &(dyn Fn(&str, &str) + Sync) = &emit;
926            std::thread::scope(|s| {
927                s.spawn(|| {
928                    run_tagged_tail(
929                        console_log,
930                        stop,
931                        emit,
932                        TaggedTailOptions {
933                            stream: "stdout",
934                            runtime_filter: Some(&runtime_filter),
935                            bound: cap,
936                            ready,
937                            eof_policy,
938                        },
939                    )
940                });
941                s.spawn(|| {
942                    run_tagged_tail(
943                        err_log,
944                        stop,
945                        emit,
946                        TaggedTailOptions {
947                            stream: "stderr",
948                            runtime_filter: Some(&runtime_filter),
949                            bound: cap,
950                            ready,
951                            eof_policy,
952                        },
953                    )
954                });
955            });
956        }
957        "tcp" => {
958            let stream = match std::net::TcpStream::connect(addr) {
959                Ok(s) => std::sync::Mutex::new(s),
960                Err(_) => return,
961            };
962            let emit = |line: &str, _stream: &str| {
963                let msg = format!("<30>{tag}: {line}\n");
964                if let Ok(mut s) = stream.lock() {
965                    if s.write_all(msg.as_bytes()).is_err() {
966                        if let Ok(news) = std::net::TcpStream::connect(addr) {
967                            *s = news;
968                            let _ = s.write_all(msg.as_bytes());
969                        }
970                    }
971                }
972            };
973            let emit: &(dyn Fn(&str, &str) + Sync) = &emit;
974            std::thread::scope(|sc| {
975                sc.spawn(|| {
976                    run_tagged_tail(
977                        console_log,
978                        stop,
979                        emit,
980                        TaggedTailOptions {
981                            stream: "stdout",
982                            runtime_filter: Some(&runtime_filter),
983                            bound: cap,
984                            ready,
985                            eof_policy,
986                        },
987                    )
988                });
989                sc.spawn(|| {
990                    run_tagged_tail(
991                        err_log,
992                        stop,
993                        emit,
994                        TaggedTailOptions {
995                            stream: "stderr",
996                            runtime_filter: Some(&runtime_filter),
997                            bound: cap,
998                            ready,
999                            eof_policy,
1000                        },
1001                    )
1002                });
1003            });
1004        }
1005        _ => {}
1006    }
1007}
1008
1009/// A file writer that rotates (and gzips) when the file exceeds `max_size`.
1010struct RotatingWriter {
1011    path: PathBuf,
1012    file: std::fs::File,
1013    written: u64,
1014    max_size: u64,
1015    max_file: u32,
1016}
1017
1018impl RotatingWriter {
1019    fn new(path: &Path, max_size: u64, max_file: u32) -> std::io::Result<Self> {
1020        let file = std::fs::OpenOptions::new()
1021            .create(true)
1022            .append(true)
1023            .open(path)?;
1024        let written = file.metadata()?.len();
1025        Ok(Self {
1026            path: path.to_path_buf(),
1027            file,
1028            written,
1029            max_size,
1030            max_file,
1031        })
1032    }
1033
1034    fn write_line(&mut self, line: &str) -> std::io::Result<()> {
1035        let bytes = format!("{line}\n");
1036        self.file.write_all(bytes.as_bytes())?;
1037        self.file.flush()?;
1038        self.written += bytes.len() as u64;
1039        if self.written >= self.max_size {
1040            self.rotate()?;
1041        }
1042        Ok(())
1043    }
1044
1045    fn rotate(&mut self) -> std::io::Result<()> {
1046        for i in (1..self.max_file).rev() {
1047            let from = rotated_path(&self.path, i);
1048            let to = rotated_path(&self.path, i + 1);
1049            if from.exists() {
1050                std::fs::rename(&from, &to)?;
1051            }
1052        }
1053        let oldest = rotated_path(&self.path, self.max_file);
1054        if oldest.exists() {
1055            std::fs::remove_file(&oldest)?;
1056        }
1057        let rotated = rotated_path(&self.path, 1);
1058        compress_file(&self.path, &rotated)?;
1059        std::fs::remove_file(&self.path)?;
1060        self.file = std::fs::OpenOptions::new()
1061            .create(true)
1062            .append(true)
1063            .open(&self.path)?;
1064        self.written = 0;
1065        Ok(())
1066    }
1067}
1068
1069/// Compress a file with gzip.
1070fn compress_file(src: &Path, dst: &Path) -> std::io::Result<()> {
1071    use flate2::write::GzEncoder;
1072    use flate2::Compression;
1073    use std::io::Read;
1074
1075    let mut input = std::fs::File::open(src)?;
1076    let output = std::fs::File::create(dst)?;
1077    let mut encoder = GzEncoder::new(output, Compression::fast());
1078    let mut buf = [0u8; 8192];
1079    loop {
1080        let n = input.read(&mut buf)?;
1081        if n == 0 {
1082            break;
1083        }
1084        encoder.write_all(&buf[..n])?;
1085    }
1086    encoder.finish()?;
1087    Ok(())
1088}
1089
1090/// Generate a rotated file path: container.json → container.json.1.gz
1091fn rotated_path(base: &Path, index: u32) -> PathBuf {
1092    let mut p = base.as_os_str().to_owned();
1093    p.push(format!(".{index}.gz"));
1094    PathBuf::from(p)
1095}
1096
1097#[cfg(test)]
1098mod tests {
1099    use super::*;
1100
1101    #[test]
1102    fn test_log_driver_from_str() {
1103        assert_eq!(
1104            "json-file".parse::<LogDriver>().unwrap(),
1105            LogDriver::JsonFile
1106        );
1107        assert_eq!("syslog".parse::<LogDriver>().unwrap(), LogDriver::Syslog);
1108        assert_eq!("none".parse::<LogDriver>().unwrap(), LogDriver::None);
1109        assert!("unknown".parse::<LogDriver>().is_err());
1110    }
1111
1112    #[test]
1113    fn test_log_config_defaults() {
1114        let config = LogConfig::default();
1115        assert_eq!(config.driver, LogDriver::JsonFile);
1116        assert_eq!(config.max_size(), 10 * 1024 * 1024);
1117        assert_eq!(config.max_file(), 3);
1118    }
1119
1120    #[test]
1121    fn test_log_config_custom_options() {
1122        let mut config = LogConfig::default();
1123        config
1124            .options
1125            .insert("max-size".to_string(), "50m".to_string());
1126        config
1127            .options
1128            .insert("max-file".to_string(), "5".to_string());
1129        assert_eq!(config.max_size(), 50 * 1024 * 1024);
1130        assert_eq!(config.max_file(), 5);
1131    }
1132
1133    #[test]
1134    fn test_parse_size() {
1135        assert_eq!(parse_size("1024").unwrap(), 1024);
1136        assert_eq!(parse_size("10m").unwrap(), 10 * 1024 * 1024);
1137        assert_eq!(parse_size("1g").unwrap(), 1024 * 1024 * 1024);
1138        assert_eq!(parse_size("512k").unwrap(), 512 * 1024);
1139        assert!(parse_size("abc").is_err());
1140    }
1141
1142    #[test]
1143    fn test_log_entry_serialization() {
1144        let entry = LogEntry {
1145            log: "hello\n".to_string(),
1146            stream: "stdout".to_string(),
1147            time: "2026-02-12T06:00:00.000000000Z".to_string(),
1148        };
1149        let json = serde_json::to_string(&entry).unwrap();
1150        assert!(json.contains("\"log\":\"hello\\n\""));
1151        assert!(json.contains("\"stream\":\"stdout\""));
1152    }
1153
1154    #[test]
1155    fn sandbox_log_worker_spec_round_trips_generation_identity() {
1156        let spec = SandboxLogWorkerSpec {
1157            schema: SANDBOX_LOG_WORKER_SCHEMA.to_string(),
1158            box_id: "sandbox-id".to_string(),
1159            console_log: PathBuf::from("/tmp/sandbox-id/logs/console.log"),
1160            log_config: LogConfig::default(),
1161            watched_pid: 123,
1162            watched_pid_start_time: 456,
1163            ready_file: PathBuf::from("/tmp/sandbox-id/sandbox/log-worker.ready"),
1164        };
1165
1166        let encoded = serde_json::to_vec(&spec).unwrap();
1167        let decoded: SandboxLogWorkerSpec = serde_json::from_slice(&encoded).unwrap();
1168
1169        assert_eq!(decoded, spec);
1170    }
1171
1172    #[test]
1173    fn writer_closed_eof_skips_the_late_console_settle_window() {
1174        assert_eq!(
1175            stopped_eof_settle_polls(ConsoleEofPolicy::MayReceiveLateWrites),
1176            25
1177        );
1178        assert_eq!(stopped_eof_settle_polls(ConsoleEofPolicy::WriterClosed), 1);
1179    }
1180
1181    #[test]
1182    fn test_syslog_config_defaults() {
1183        let config = LogConfig {
1184            driver: LogDriver::Syslog,
1185            options: HashMap::new(),
1186        };
1187        assert_eq!(config.syslog_address(), "udp://localhost:514");
1188        assert_eq!(config.syslog_facility(), "daemon");
1189        assert_eq!(config.tag(), None);
1190    }
1191
1192    #[test]
1193    fn test_syslog_config_custom() {
1194        let mut options = HashMap::new();
1195        options.insert(
1196            "syslog-address".to_string(),
1197            "tcp://loghost:1514".to_string(),
1198        );
1199        options.insert("syslog-facility".to_string(), "local0".to_string());
1200        options.insert("tag".to_string(), "myapp".to_string());
1201        let config = LogConfig {
1202            driver: LogDriver::Syslog,
1203            options,
1204        };
1205        assert_eq!(config.syslog_address(), "tcp://loghost:1514");
1206        assert_eq!(config.syslog_facility(), "local0");
1207        assert_eq!(config.tag(), Some("myapp"));
1208    }
1209
1210    #[test]
1211    fn test_log_driver_display() {
1212        assert_eq!(LogDriver::JsonFile.to_string(), "json-file");
1213        assert_eq!(LogDriver::Syslog.to_string(), "syslog");
1214        assert_eq!(LogDriver::None.to_string(), "none");
1215    }
1216
1217    #[test]
1218    fn test_log_driver_serde_roundtrip() {
1219        let driver = LogDriver::Syslog;
1220        let json = serde_json::to_string(&driver).unwrap();
1221        assert_eq!(json, "\"syslog\"");
1222        let parsed: LogDriver = serde_json::from_str(&json).unwrap();
1223        assert_eq!(parsed, LogDriver::Syslog);
1224    }
1225
1226    #[test]
1227    fn test_tail_next_line_returns_complete_lines() {
1228        use std::io::Cursor;
1229        // Two complete lines (CRLF then LF) returned newline-stripped; a third
1230        // read at EOF with stop=true returns None (VM exited, console drained).
1231        let mut reader = BufReader::new(Cursor::new(b"alpha\r\nbeta\n".to_vec()));
1232        let mut buf = String::new();
1233        let stop = AtomicBool::new(true);
1234        assert_eq!(
1235            tail_next_line(
1236                &mut reader,
1237                &mut buf,
1238                &stop,
1239                None,
1240                ConsoleEofPolicy::MayReceiveLateWrites,
1241                None,
1242            ),
1243            Some("alpha".to_string())
1244        );
1245        assert_eq!(
1246            tail_next_line(
1247                &mut reader,
1248                &mut buf,
1249                &stop,
1250                None,
1251                ConsoleEofPolicy::MayReceiveLateWrites,
1252                None,
1253            ),
1254            Some("beta".to_string())
1255        );
1256        assert_eq!(
1257            tail_next_line(
1258                &mut reader,
1259                &mut buf,
1260                &stop,
1261                None,
1262                ConsoleEofPolicy::MayReceiveLateWrites,
1263                None,
1264            ),
1265            None
1266        );
1267        assert!(buf.is_empty());
1268    }
1269
1270    #[test]
1271    fn test_tail_next_line_flushes_trailing_partial_on_stop() {
1272        use std::io::Cursor;
1273        // A final line without a trailing newline is still flushed once when the
1274        // VM has exited (stop=true) — no dropped last line.
1275        let mut reader = BufReader::new(Cursor::new(b"only-partial".to_vec()));
1276        let mut buf = String::new();
1277        let stop = AtomicBool::new(true);
1278        assert_eq!(
1279            tail_next_line(
1280                &mut reader,
1281                &mut buf,
1282                &stop,
1283                None,
1284                ConsoleEofPolicy::MayReceiveLateWrites,
1285                None,
1286            ),
1287            Some("only-partial".to_string())
1288        );
1289        assert_eq!(
1290            tail_next_line(
1291                &mut reader,
1292                &mut buf,
1293                &stop,
1294                None,
1295                ConsoleEofPolicy::MayReceiveLateWrites,
1296                None,
1297            ),
1298            None
1299        );
1300    }
1301
1302    #[test]
1303    fn test_console_truncate_if_over_only_when_over_cap() {
1304        let dir = tempfile::tempdir().unwrap();
1305        let path = dir.path().join("c.log");
1306        std::fs::write(&path, b"hello").unwrap(); // 5 bytes
1307
1308        assert!(!console_truncate_if_over(&path, 10, None)); // under cap → untouched
1309        assert_eq!(std::fs::metadata(&path).unwrap().len(), 5);
1310
1311        assert!(console_truncate_if_over(&path, 4, None)); // over cap → truncated
1312        assert_eq!(std::fs::metadata(&path).unwrap().len(), 0);
1313
1314        // Missing file: false, no panic.
1315        assert!(!console_truncate_if_over(&dir.path().join("nope"), 0, None));
1316    }
1317
1318    #[test]
1319    fn test_run_tagged_tail_truncates_over_cap_and_keeps_emitting() {
1320        use std::sync::{Arc, Mutex};
1321        use std::time::Duration;
1322
1323        let dir = tempfile::tempdir().unwrap();
1324        let path = dir.path().join("console.log");
1325        // Pre-fill past a tiny cap with three complete lines.
1326        std::fs::write(&path, b"l1\nl2\nl3\n").unwrap();
1327        let cap = 4u64;
1328
1329        let collected = Arc::new(Mutex::new(Vec::<String>::new()));
1330        let stop = Arc::new(AtomicBool::new(false));
1331        let (c2, s2, p2) = (collected.clone(), stop.clone(), path.clone());
1332        let handle = std::thread::spawn(move || {
1333            let emit = move |line: &str, _stream: &str| c2.lock().unwrap().push(line.to_string());
1334            let emit: &(dyn Fn(&str, &str) + Sync) = &emit;
1335            run_tagged_tail(
1336                &p2,
1337                &s2,
1338                emit,
1339                TaggedTailOptions {
1340                    stream: "stdout",
1341                    runtime_filter: None,
1342                    bound: Some(cap),
1343                    ready: None,
1344                    eof_policy: ConsoleEofPolicy::MayReceiveLateWrites,
1345                },
1346            );
1347        });
1348
1349        // Let the tail drain l1..l3, hit EOF, and truncate (9 bytes > cap 4).
1350        std::thread::sleep(Duration::from_millis(300));
1351        // libkrun-style O_APPEND write after the truncation.
1352        {
1353            use std::io::Write as _;
1354            let mut f = std::fs::OpenOptions::new()
1355                .append(true)
1356                .open(&path)
1357                .unwrap();
1358            f.write_all(b"l4\nl5\n").unwrap();
1359        }
1360        std::thread::sleep(Duration::from_millis(300));
1361        stop.store(true, Ordering::Relaxed);
1362        handle.join().unwrap();
1363
1364        let got = collected.lock().unwrap().clone();
1365        // No data lost across the truncation: pre- and post-truncation lines both emit.
1366        for line in ["l1", "l3", "l4", "l5"] {
1367            assert!(got.contains(&line.to_string()), "missing {line} in {got:?}");
1368        }
1369        // And the raw file stayed bounded (truncated, not left at full history).
1370        let final_len = std::fs::metadata(&path).unwrap().len();
1371        assert!(
1372            final_len <= cap + 6,
1373            "console.log unbounded: {final_len} bytes"
1374        );
1375    }
1376
1377    #[cfg(target_os = "windows")]
1378    #[test]
1379    fn test_run_tagged_tail_refuses_replaced_source_identity() {
1380        use std::sync::{Arc, Mutex};
1381        use std::time::Duration;
1382
1383        let dir = tempfile::tempdir().unwrap();
1384        let path = dir.path().join("guest-init.stdout.log");
1385        let retired = dir.path().join("guest-init.stdout.log.retired");
1386        std::fs::write(&path, b"").unwrap();
1387
1388        let collected = Arc::new(Mutex::new(Vec::<String>::new()));
1389        let stop = Arc::new(AtomicBool::new(false));
1390        let (c2, s2, p2) = (collected.clone(), stop.clone(), path.clone());
1391        let handle = std::thread::spawn(move || {
1392            let emit = move |line: &str, _stream: &str| c2.lock().unwrap().push(line.to_string());
1393            let emit: &(dyn Fn(&str, &str) + Sync) = &emit;
1394            run_tagged_tail(
1395                &p2,
1396                &s2,
1397                emit,
1398                TaggedTailOptions {
1399                    stream: "stdout",
1400                    runtime_filter: None,
1401                    bound: None,
1402                    ready: None,
1403                    eof_policy: ConsoleEofPolicy::MayReceiveLateWrites,
1404                },
1405            );
1406        });
1407
1408        // A guest may replace the path after the host tailer has pinned the
1409        // original handle. Reopening must never switch to the replacement.
1410        std::thread::sleep(Duration::from_millis(300));
1411        std::fs::rename(&path, &retired).unwrap();
1412        std::fs::write(&path, b"late-line\n").unwrap();
1413
1414        std::thread::sleep(Duration::from_millis(300));
1415
1416        stop.store(true, Ordering::Relaxed);
1417        handle.join().unwrap();
1418        let got = collected.lock().unwrap().clone();
1419        assert!(!got.iter().any(|line| line == "late-line"), "{got:?}");
1420    }
1421
1422    #[test]
1423    fn explicit_streams_with_ready_reports_both_open_readers() {
1424        use std::sync::Arc;
1425        use std::time::{Duration, Instant};
1426
1427        let dir = tempfile::tempdir().unwrap();
1428        let stdout = dir.path().join("guest.stdout.log");
1429        let stderr = dir.path().join("guest.stderr.log");
1430        std::fs::write(&stdout, b"").unwrap();
1431        std::fs::write(&stderr, b"").unwrap();
1432
1433        let stop = Arc::new(AtomicBool::new(false));
1434        let ready = Arc::new(std::sync::atomic::AtomicUsize::new(0));
1435        let (thread_stop, thread_ready) = (Arc::clone(&stop), Arc::clone(&ready));
1436        let log_dir = dir.path().to_path_buf();
1437        let handle = std::thread::spawn(move || {
1438            run_log_processor_streams_with_ready(
1439                &stdout,
1440                &stderr,
1441                &log_dir,
1442                &LogConfig::default(),
1443                &thread_stop,
1444                Some(&thread_ready),
1445            );
1446        });
1447
1448        let deadline = Instant::now() + Duration::from_secs(2);
1449        while ready.load(Ordering::Acquire) < 2 && Instant::now() < deadline {
1450            std::thread::sleep(Duration::from_millis(10));
1451        }
1452        assert_eq!(ready.load(Ordering::Acquire), 2);
1453
1454        stop.store(true, Ordering::Release);
1455        handle.join().unwrap();
1456    }
1457
1458    #[test]
1459    fn test_stopped_tail_waits_for_delayed_final_console_write() {
1460        use std::io::Write as _;
1461
1462        let dir = tempfile::tempdir().unwrap();
1463        let path = dir.path().join("console.log");
1464        std::fs::write(&path, b"").unwrap();
1465        let writer_path = path.clone();
1466        let writer = std::thread::spawn(move || {
1467            std::thread::sleep(std::time::Duration::from_millis(30));
1468            let mut file = std::fs::OpenOptions::new()
1469                .append(true)
1470                .open(writer_path)
1471                .unwrap();
1472            file.write_all(b"late-final-line\n").unwrap();
1473            file.flush().unwrap();
1474        });
1475
1476        let file = std::fs::File::open(&path).unwrap();
1477        let mut reader = BufReader::new(file);
1478        let mut buffer = String::new();
1479        let stop = AtomicBool::new(true);
1480        assert_eq!(
1481            tail_next_line(
1482                &mut reader,
1483                &mut buffer,
1484                &stop,
1485                None,
1486                ConsoleEofPolicy::MayReceiveLateWrites,
1487                None,
1488            ),
1489            Some("late-final-line".to_string())
1490        );
1491        assert_eq!(
1492            tail_next_line(
1493                &mut reader,
1494                &mut buffer,
1495                &stop,
1496                None,
1497                ConsoleEofPolicy::MayReceiveLateWrites,
1498                None,
1499            ),
1500            None
1501        );
1502        writer.join().unwrap();
1503    }
1504
1505    #[test]
1506    fn test_none_driver_still_bounds_console() {
1507        use std::sync::Arc;
1508        use std::time::Duration;
1509
1510        let dir = tempfile::tempdir().unwrap();
1511        let console = dir.path().join("console.log");
1512        std::fs::write(&console, b"l1\nl2\nl3\n").unwrap(); // 9 bytes
1513        std::fs::write(dir.path().join("console.err.log"), b"").unwrap();
1514
1515        // none driver, tiny cap (max_size 4 * max_file 1).
1516        let mut options = HashMap::new();
1517        options.insert("max-size".to_string(), "4".to_string());
1518        options.insert("max-file".to_string(), "1".to_string());
1519        let config = LogConfig {
1520            driver: LogDriver::None,
1521            options,
1522        };
1523
1524        let stop = Arc::new(AtomicBool::new(false));
1525        let (s2, c2, d2) = (stop.clone(), console.clone(), dir.path().to_path_buf());
1526        let handle = std::thread::spawn(move || run_log_processor(&c2, &d2, &config, &s2));
1527
1528        std::thread::sleep(Duration::from_millis(300));
1529        stop.store(true, Ordering::Relaxed);
1530        handle.join().unwrap();
1531
1532        // The raw console was bounded even though `none` produces no output, and
1533        // no container.json was written.
1534        assert!(std::fs::metadata(&console).unwrap().len() <= 4);
1535        assert!(!dir.path().join("container.json").exists());
1536    }
1537
1538    #[test]
1539    fn test_is_runtime_console_noise() {
1540        assert!(is_runtime_console_noise("init.krun: mount_filesystems ok"));
1541        assert!(is_runtime_console_noise("init.krun: entered main argc=1"));
1542        assert!(is_runtime_console_noise(
1543            "init.krun: selected exec=/bin/app init_pid1=0"
1544        ));
1545        assert!(is_runtime_console_noise(
1546            "init.krun: execvp(/bin/app) starting"
1547        ));
1548        assert!(!is_runtime_console_noise("init.krun: business"));
1549        assert!(!is_runtime_console_noise(
1550            "init.krun: entered main argc=not-a-number"
1551        ));
1552        assert!(!is_runtime_console_noise(
1553            "init.krun: execvp(/bin/app) failed errno=2"
1554        ));
1555        assert!(!is_runtime_console_noise("L1"));
1556        assert!(!is_runtime_console_noise(
1557            "starting app (init.krun: ignored)"
1558        ));
1559        assert!(!is_runtime_console_noise(""));
1560    }
1561
1562    #[test]
1563    fn runtime_console_filter_shares_sentinel_phase_across_streams() {
1564        let filter = RuntimeConsoleFilter::new();
1565
1566        // Treat these calls as interleaved stdout/stderr records using the
1567        // same shared filter, as the structured log processor does.
1568        assert!(!filter.keep_line("init.krun: mount_filesystems ok"));
1569        assert!(filter.keep_line("init.krun: business"));
1570        assert!(!filter.keep_line("init.krun: execvp(/bin/app) starting"));
1571        assert!(!filter.preamble_active());
1572        assert!(filter.keep_line("init.krun: mount_filesystems ok"));
1573        assert!(filter.keep_line("init.krun: execvp(/bin/app) starting"));
1574        assert!(filter.keep_line("init.krun: execvp(/bin/app) failed errno=2"));
1575    }
1576
1577    #[test]
1578    fn test_run_json_file_processor_captures_all_lines_after_stop() {
1579        // The processor must emit a record for EVERY console line, then stop
1580        // cleanly once the VM has exited (stop=true). The original bug dropped
1581        // every line logged after the first EOF (here: BBB after a quiet line).
1582        let dir = tempfile::tempdir().unwrap();
1583        let console = dir.path().join("console.log");
1584        let stderr = dir.path().join("persisted-stderr.log");
1585        std::fs::write(
1586            &console,
1587            concat!(
1588                "init.krun: entered main argc=1\n",
1589                "init.krun: mount_filesystems ok\n",
1590                "init.krun: execvp(/bin/app) starting\n",
1591                "AAA\n",
1592                "init.krun: business\n",
1593                "BBB\n",
1594            ),
1595        )
1596        .unwrap();
1597        std::fs::write(&stderr, "ERR\n").unwrap();
1598        let stop = AtomicBool::new(true);
1599        run_log_processor_streams(&console, &stderr, dir.path(), &LogConfig::default(), &stop);
1600        let json = std::fs::read_to_string(json_log_path(dir.path())).unwrap();
1601        assert!(json.contains("\"log\":\"AAA\\n\""), "AAA missing: {json}");
1602        assert!(
1603            json.contains("\"log\":\"BBB\\n\""),
1604            "BBB (after a quiet line) missing: {json}"
1605        );
1606        assert!(
1607            json.contains("\"log\":\"ERR\\n\"") && json.contains("\"stream\":\"stderr\""),
1608            "custom stderr stream missing: {json}"
1609        );
1610        assert!(
1611            json.contains("\"log\":\"init.krun: business\\n\""),
1612            "generic init.krun workload output missing: {json}"
1613        );
1614        assert!(
1615            !json.contains("entered main"),
1616            "C-init noise leaked: {json}"
1617        );
1618        assert!(
1619            !json.contains("mount_filesystems ok"),
1620            "C-init noise leaked: {json}"
1621        );
1622        assert!(
1623            !json.contains("execvp(/bin/app) starting"),
1624            "C-init sentinel leaked: {json}"
1625        );
1626    }
1627
1628    #[test]
1629    fn test_run_json_file_processor_preserves_unterminated_prefix_line() {
1630        let dir = tempfile::tempdir().unwrap();
1631        let console = dir.path().join("console.log");
1632        let stderr = dir.path().join("console.err.log");
1633        std::fs::write(&console, "init.krun: mount_filesystems ok").unwrap();
1634        std::fs::write(&stderr, "").unwrap();
1635
1636        let stop = AtomicBool::new(true);
1637        run_log_processor_streams(&console, &stderr, dir.path(), &LogConfig::default(), &stop);
1638
1639        let json = std::fs::read_to_string(json_log_path(dir.path())).unwrap();
1640        assert!(
1641            json.contains("\"log\":\"init.krun: mount_filesystems ok\\n\""),
1642            "unterminated workload fragment was dropped: {json}"
1643        );
1644    }
1645
1646    #[test]
1647    fn ordered_json_writer_clamps_a_regressed_clock() {
1648        let dir = tempfile::tempdir().unwrap();
1649        let path = dir.path().join("container.json");
1650        let mut writer = OrderedJsonWriter::new(&path, 10 * 1024 * 1024, 3).unwrap();
1651        let newer = chrono::DateTime::parse_from_rfc3339("2026-07-19T12:00:01Z")
1652            .unwrap()
1653            .to_utc();
1654        let older = chrono::DateTime::parse_from_rfc3339("2026-07-19T12:00:00Z")
1655            .unwrap()
1656            .to_utc();
1657
1658        writer.write_entry("first", "stdout", newer);
1659        writer.write_entry("second", "stderr", older);
1660        drop(writer);
1661
1662        let entries = std::fs::read_to_string(path)
1663            .unwrap()
1664            .lines()
1665            .map(|line| serde_json::from_str::<LogEntry>(line).unwrap())
1666            .collect::<Vec<_>>();
1667        assert_eq!(entries.len(), 2);
1668        assert_eq!(entries[0].time, entries[1].time);
1669    }
1670
1671    #[test]
1672    fn test_rotating_writer_rotates_and_gzips() {
1673        let dir = tempfile::tempdir().unwrap();
1674        let path = dir.path().join("container.json");
1675        let mut w = RotatingWriter::new(&path, 20, 3).unwrap();
1676        for i in 0..10 {
1677            w.write_line(&format!("line-{i}")).unwrap();
1678        }
1679        assert!(
1680            rotated_path(&path, 1).exists(),
1681            "expected a rotated .1.gz file"
1682        );
1683    }
1684}