A zone's log is bounded across launches, and by what is logged

compartments/kryptikd/src/serve.rs

@@ -562,12 +562,7 @@ fn spawn_launcher(
     args.extend(req.argv.iter().cloned());
 
     let log = cfg.log_dir.join(format!("zone-{}.log", req.zone));
-    let logf = std::fs::OpenOptions::new()
-        .create(true)
-        .append(true)
-        .mode(0o600)
-        .open(&log)
-        .map_err(|e| format!("{}: {e}", log.display()))?;
+    let logf = open_zone_log(&log)?;
     let cexe = CString::new(exe.display().to_string()).map_err(|_| "NUL in exe path".to_string())?;
     let cargs: Vec<CString> = std::iter::once(CString::new("kryptikd").unwrap())
         .chain(args.iter().map(|a| CString::new(a.as_str()).unwrap_or_else(|_| CString::new("?").unwrap())))
@@ -616,6 +611,29 @@ fn spawn_launcher(
     Ok(Launch { pid, ready: ready_r, log })
 }
 
+/// A zone's log past this size starts again at its next launch.
+const ZONE_LOG_KEEP: u64 = 8 << 20;
+
+/// Open a zone's log for a launch. Each launch adds a bounded amount
+/// (spawn.rs, ZoneOutput) and nothing else trims the file, so past
+/// ZONE_LOG_KEEP it becomes `.old`, replacing the one before, and a new file
+/// starts: a zone keeps two files of that size and a launch's worth each.
+fn open_zone_log(log: &Path) -> Result<std::fs::File, String> {
+    if std::fs::symlink_metadata(log).map(|m| m.len() > ZONE_LOG_KEEP).unwrap_or(false) {
+        let mut old = log.as_os_str().to_owned();
+        old.push(".old");
+        let _ = std::fs::rename(log, old);
+    }
+    // Never through a link at the name, as last_log_line reads it.
+    std::fs::OpenOptions::new()
+        .create(true)
+        .append(true)
+        .mode(0o600)
+        .custom_flags(libc::O_NOFOLLOW)
+        .open(log)
+        .map_err(|e| format!("{}: {e}", log.display()))
+}
+
 /// The launcher's last log line, printable and bounded, for an error reply.
 fn last_log_line(log: &Path) -> String {
     // Zone output can make the log any size and any bytes: read only the last 8 KiB.

compartments/kryptikd/src/serve/tests.rs

@@ -144,6 +144,34 @@ fn last_log_line_reads_tail() {
     let _ = std::fs::remove_dir_all(&dir);
 }
 
+#[test]
+fn zone_log_starts_again_past_its_bound() {
+    let dir = std::env::temp_dir().join(format!("kryptik-serve-log-test-{}", std::process::id()));
+    std::fs::create_dir_all(&dir).unwrap();
+    let log = dir.join("zone-x.log");
+    let old = dir.join("zone-x.log.old");
+    // Under the bound a launch appends to what is there.
+    std::fs::write(&log, "first launch\n").unwrap();
+    open_zone_log(&log).unwrap().write_all(b"second launch\n").unwrap();
+    assert_eq!(std::fs::read_to_string(&log).unwrap(), "first launch\nsecond launch\n");
+    assert!(!old.exists(), "a log under the bound was moved aside");
+    // Past it the file is kept as .old, in place of the one before, and a new one starts.
+    std::fs::write(&old, "the generation before\n").unwrap();
+    let grown = std::fs::OpenOptions::new().append(true).open(&log).unwrap();
+    grown.set_len(ZONE_LOG_KEEP + 1).unwrap(); // sparse: no large allocation or disk write
+    drop(grown);
+    open_zone_log(&log).unwrap().write_all(b"third launch\n").unwrap();
+    assert_eq!(std::fs::read_to_string(&log).unwrap(), "third launch\n");
+    assert_eq!(std::fs::metadata(&old).unwrap().len(), ZONE_LOG_KEEP + 1, "the grown log is not the one kept");
+    // A link at the name is refused, and nothing is made through it.
+    let target = dir.join("elsewhere");
+    std::fs::remove_file(&log).unwrap();
+    std::os::unix::fs::symlink(&target, &log).unwrap();
+    assert!(open_zone_log(&log).is_err(), "a log was opened through a link");
+    assert!(!target.exists(), "a file was made through a link at the log's name");
+    let _ = std::fs::remove_dir_all(&dir);
+}
+
 #[test]
 fn socketpair_peer_is_self() {
     let (a, _b) = UnixStream::pair().unwrap();

compartments/kryptikd/src/spawn.rs

@@ -223,8 +223,9 @@ pub(crate) fn log_line(line: &str) {
     }
 }
 
-/// Most zone output one launch logs (the rest is read and dropped, so an endless
-/// writer neither blocks nor fills the state partition), and the longest line.
+/// Most zone output one launch logs, marks and line ends counted (the rest is
+/// read and dropped, so an endless writer neither blocks nor fills the state
+/// partition), and the longest line.
 const ZONE_OUTPUT_MAX: usize = 1 << 20;
 const ZONE_LINE_MAX: usize = 1024;
 
@@ -247,6 +248,9 @@ impl ZoneOutput {
         if !self.line.is_empty() {
             emit(&format!("{}{}", self.mark, String::from_utf8_lossy(&self.line)));
             self.line.clear();
+            // The mark and the line end are logged too: one-byte lines would
+            // otherwise log many times what the zone wrote.
+            self.left = self.left.saturating_sub(self.mark.len() + 1);
         }
     }
 

compartments/kryptikd/src/spawn/tests.rs

@@ -25,13 +25,20 @@ fn zone_output_is_prefixed_and_sanitized() {
     let long = vec![b'a'; ZONE_LINE_MAX * 2 + 5];
     let got = relayed(&[&long]);
     assert_eq!(got.iter().map(|l| l.len() - "zone work| ".len()).collect::<Vec<_>>(), [ZONE_LINE_MAX, ZONE_LINE_MAX, 5]);
-    // Past the bound nothing more is logged, and it says so once.
+    // Past the bound nothing more is logged, and it says so once. The bound is
+    // on what reaches the log, each line's mark and end with it.
+    let logged = |got: &[String]| got.iter().filter(|l| !l.contains("is not logged")).map(|l| l.len() + 1).sum::<usize>();
+    let slack = ZONE_LINE_MAX + "zone work| ".len() + 1;
     let flood = vec![b'x'; ZONE_OUTPUT_MAX + 4096];
     let got = relayed(&[&flood, b"more\n"]);
-    let logged: usize = got.iter().filter(|l| !l.contains("is not logged")).map(|l| l.len() - "zone work| ".len()).sum();
-    assert_eq!(logged, ZONE_OUTPUT_MAX);
+    assert!(logged(&got) <= ZONE_OUTPUT_MAX + slack && logged(&got) > ZONE_OUTPUT_MAX - slack, "{} bytes logged", logged(&got));
     assert_eq!(got.iter().filter(|l| l.contains("is not logged")).count(), 1);
     assert!(!got.iter().any(|l| l.contains("more")));
+    // One-byte lines are mostly mark: they reach the bound sooner, not past it.
+    let short = b"a\n".repeat(ZONE_OUTPUT_MAX / 2);
+    let got = relayed(&[&short]);
+    assert!(logged(&got) <= ZONE_OUTPUT_MAX + slack, "{} bytes logged for {} written", logged(&got), short.len());
+    assert_eq!(got.iter().filter(|l| l.contains("is not logged")).count(), 1);
 }
 
 #[test]