diff --git a/docs/trust-boundary/security.md b/docs/trust-boundary/security.md index 706da122..85f01f6c 100644 --- a/docs/trust-boundary/security.md +++ b/docs/trust-boundary/security.md @@ -256,6 +256,7 @@ known operations; there is no arbitrary command pass-through: | ------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | `StartContainer` / `StopContainer` | `nixos-container start/stop ` | | `KillContainer` | `machinectl kill --signal=SIGKILL` (`nixos-container` has no kill verb) | +| `StartFailureLog` | `journalctl _SYSTEMD_UNIT=container@h-.service --since @ -n 30 -o cat --no-pager`, fixed argv, 5 s timeout, output capped at 8 KiB; hive-priv clamps `` to the last hour. hive-c0re appends the lines to the failed start's build log, which only the dashboard serves. | | `CreateContainer` / `UpdateContainer` | `nixos-container create --system-path `; for an update, `nix-env -p --set ` and a reload of the unit. `` must be the store path the last successful `RealiseClosure` returned for that agent (in memory, per agent), so hive-c0re can't name a path never realised for the agent; hive-priv builds nothing. The binding doesn't mean hive-c0re can't choose the closure: it can still ask hive-priv to download any swarm-signed path for any agent and then apply it. The swarm key and the cache bound that to a cross-assignment risk (one agent gets another's closure), not an arbitrary-path one | | `RealiseClosure` | `nix-store --realise --max-jobs 0` against the swarm cache, with the host's configured cache address, and the public key and netrc from root-owned `/run/hyperhive-priv/attic/`, as per-call settings that replace the host's substituters and trusted keys and require a signature. The path must be `/nix/store/<32 chars>-` and the agent name valid. It downloads and never builds | | `DestroyContainer` | `nixos-container destroy ` | diff --git a/hive-c0re/src/lifecycle/mod.rs b/hive-c0re/src/lifecycle/mod.rs index 47b4ff8a..1855ecbe 100644 --- a/hive-c0re/src/lifecycle/mod.rs +++ b/hive-c0re/src/lifecycle/mod.rs @@ -799,16 +799,23 @@ fn make_log_callback( /// Put a failed non-streaming op's error into its build-log row, which has no /// other output: `start` runs through `call`, not the streaming protocol. The -/// error carries `nixos-container`'s stderr. +/// error carries `nixos-container`'s stderr; `journal` is the container +/// unit's own log from hive-priv. An `Err` there (an older hive-priv does not +/// know the op) leaves the stderr alone. fn record_failure( logs: Option<&crate::build_logs::BuildLogs>, log_id: Option, err: &anyhow::Error, + journal: Result, ) { if let (Some(h), Some(id)) = (logs, log_id) { for line in format!("{err:#}").lines() { h.append_stderr(id, line); } + match journal { + Ok(text) => text.lines().for_each(|l| h.append_stderr(id, l)), + Err(e) => tracing::debug!(error = ?e, "start journal unavailable"), + } } } @@ -879,9 +886,13 @@ async fn priv_run_inner( None => Err(missing_toplevel(kind, name)), }, "start" => { + let attempt = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map_or(0, |d| d.as_secs()); let started = crate::priv_client::start_container(name).await; if let Err(e) = &started { - record_failure(logs.as_deref(), log_id, e); + let journal = crate::priv_client::start_failure_log(name, attempt).await; + record_failure(logs.as_deref(), log_id, e, journal); } started } diff --git a/hive-c0re/src/lifecycle/tests.rs b/hive-c0re/src/lifecycle/tests.rs index b4a5bb40..01954e3b 100644 --- a/hive-c0re/src/lifecycle/tests.rs +++ b/hive-c0re/src/lifecycle/tests.rs @@ -529,9 +529,33 @@ fn a_failed_start_puts_its_error_in_the_op_output() { .start("updo", "start", "nixos-container start h-updo", None) .expect("start"); let err = anyhow::anyhow!("nixos-container start h-updo failed (exit status: 1): Job failed"); - record_failure(Some(&logs), Some(id), &err); + let journal = Ok("Creating mount point failed: Read-only file system".to_owned()); + record_failure(Some(&logs), Some(id), &err, journal); let full = logs.get_full(id).expect("get").expect("row"); assert!(full.stderr.contains("Job failed"), "{}", full.stderr); - record_failure(Some(&logs), None, &err); - record_failure(None, Some(id), &err); + assert!( + full.stderr.contains("Read-only file system"), + "{}", + full.stderr + ); + record_failure(Some(&logs), None, &err, Ok(String::new())); + record_failure(None, Some(id), &err, Ok(String::new())); +} + +/// An older hive-priv rejects the op; the start's own error is still recorded. +#[test] +fn an_unknown_journal_op_keeps_the_start_error() { + let dir = tempfile::tempdir().expect("tempdir"); + let logs = crate::build_logs::BuildLogs::open(dir.path()).expect("open"); + let id = logs + .start("updo", "start", "nixos-container start h-updo", None) + .expect("start"); + let err = anyhow::anyhow!("Job failed"); + let unknown = Err(anyhow::anyhow!( + "parse request: unknown variant `start_failure_log`" + )); + record_failure(Some(&logs), Some(id), &err, unknown); + let full = logs.get_full(id).expect("get").expect("row"); + assert!(full.stderr.contains("Job failed"), "{}", full.stderr); + assert!(!full.stderr.contains("unknown variant"), "{}", full.stderr); } diff --git a/hive-c0re/src/priv_client.rs b/hive-c0re/src/priv_client.rs index 3b809eea..a67d9f23 100644 --- a/hive-c0re/src/priv_client.rs +++ b/hive-c0re/src/priv_client.rs @@ -216,6 +216,19 @@ pub async fn start_container(name: &str) -> Result<()> { .await?) } +/// The container unit's journal lines since `since_unix`. An older hive-priv +/// answers an error (it does not know the op). +pub async fn start_failure_log(name: &str, since_unix: u64) -> Result { + let (stdout, _) = check( + call(&PrivRequest::StartFailureLog { + name: name.to_owned(), + since_unix, + }) + .await?, + )?; + Ok(stdout) +} + pub async fn stop_container(name: &str) -> Result<()> { ok(call(&PrivRequest::StopContainer { name: name.to_owned(), diff --git a/hive-priv-sock/src/lib.rs b/hive-priv-sock/src/lib.rs index 0a4796bb..b50d8500 100644 --- a/hive-priv-sock/src/lib.rs +++ b/hive-priv-sock/src/lib.rs @@ -255,6 +255,11 @@ pub enum PrivRequest { /// `nixos-container start ` StartContainer { name: String }, + /// The last journal lines of `name`'s own `container@h-.service` + /// unit since `since_unix` (seconds), returned in `stdout`. hive-priv + /// builds the unit name and clamps `since_unix` to the last hour. + StartFailureLog { name: String, since_unix: u64 }, + /// `nixos-container stop ` StopContainer { name: String }, diff --git a/hive-priv/src/container.rs b/hive-priv/src/container.rs index 34e470d1..037e3823 100644 --- a/hive-priv/src/container.rs +++ b/hive-priv/src/container.rs @@ -49,6 +49,80 @@ pub(crate) async fn start_container(name: &str) -> Result<(String, String)> { container_run(&["start", &machine]).await } +/// Most bytes of journal text `StartFailureLog` returns. +const START_LOG_CAP: usize = 8 * 1024; +/// Longest `journalctl` run. +const START_LOG_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(5); +/// How far back `StartFailureLog` may look. +const START_LOG_MAX_LOOKBACK_SECS: u64 = 3600; + +/// The fixed `journalctl` argv for `machine`'s start log. The match is +/// `_SYSTEMD_UNIT`, so only lines written by the container unit's own +/// processes come back, not systemd's job messages about it. +fn start_log_argv(machine: &str, since: u64) -> Vec { + [ + &format!("_SYSTEMD_UNIT=container@{machine}.service"), + "--since", + &format!("@{since}"), + "-n", + "30", + "-o", + "cat", + "--no-pager", + ] + .map(str::to_owned) + .to_vec() +} + +/// The last `cap` bytes of `text`, cut at a char boundary. +fn tail_bytes(text: &str, cap: usize) -> &str { + let mut start = text.len().saturating_sub(cap); + while !text.is_char_boundary(start) { + start += 1; + } + &text[start..] +} + +/// `StartFailureLog`: the container unit's recent journal lines, capped. +/// `run` executes `journalctl` with the argv it is given. +async fn start_failure_log_with( + name: &str, + since_unix: u64, + now: u64, + run: F, +) -> Result<(String, String)> +where + F: FnOnce(Vec) -> Fut, + Fut: std::future::Future>, +{ + validate_agent_name(name)?; + let since = since_unix.clamp(now.saturating_sub(START_LOG_MAX_LOOKBACK_SECS), now); + let out = run(start_log_argv(&container_system_name(name), since)).await?; + Ok((tail_bytes(&out, START_LOG_CAP).to_owned(), String::new())) +} + +/// `StartFailureLog` against the real `journalctl`. +pub(crate) async fn start_failure_log(name: &str, since_unix: u64) -> Result<(String, String)> { + let now = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map_or(0, |d| d.as_secs()); + start_failure_log_with(name, since_unix, now, |argv| async move { + let child = Command::new("journalctl") + .args(&argv) + .kill_on_drop(true) + .output(); + let out = tokio::time::timeout(START_LOG_TIMEOUT, child) + .await + .context("journalctl timed out")? + .context("invoke journalctl")?; + if !out.status.success() { + bail!("journalctl failed ({})", out.status); + } + Ok(String::from_utf8_lossy(&out.stdout).into_owned()) + }) + .await +} + /// `StopContainer`. pub(crate) async fn stop_container(name: &str) -> Result<(String, String)> { validate_agent_name(name)?; @@ -635,3 +709,68 @@ mod tests { } } } + +#[cfg(test)] +mod start_log_tests { + use super::*; + + const NOW: u64 = 1_000_000; + + async fn argv_for(name: &str, since: u64) -> Vec { + let seen = std::sync::Mutex::new(Vec::new()); + start_failure_log_with(name, since, NOW, |argv| { + *seen.lock().unwrap() = argv; + async { Ok(String::new()) } + }) + .await + .unwrap(); + seen.into_inner().unwrap() + } + + #[tokio::test] + async fn odd_names_are_refused_before_journalctl_runs() { + for bad in ["", "../x", "a b", "A", "x.service", "x\n--vacuum-size=1"] { + let r = + start_failure_log_with(bad, NOW, NOW, |_| async { panic!("runner must not run") }) + .await; + assert!(r.is_err(), "{bad:?} accepted"); + } + } + + #[tokio::test] + async fn the_argv_is_fixed_and_the_unit_is_built_here() { + assert_eq!( + argv_for("bob", NOW - 5).await, + [ + "_SYSTEMD_UNIT=container@h-bob.service", + "--since", + "@999995", + "-n", + "30", + "-o", + "cat", + "--no-pager" + ] + ); + } + + #[tokio::test] + async fn since_is_clamped_to_the_last_hour_and_not_the_future() { + assert_eq!(argv_for("bob", 0).await[2], format!("@{}", NOW - 3600)); + assert_eq!(argv_for("bob", NOW + 99).await[2], format!("@{NOW}")); + } + + #[tokio::test] + async fn the_output_is_capped_keeping_the_newest_bytes() { + let big = format!("{}end\n", "é".repeat(START_LOG_CAP)); + let (out, _) = start_failure_log_with("bob", NOW, NOW, |_| async { Ok(big) }) + .await + .unwrap(); + assert!(out.len() <= START_LOG_CAP, "{}", out.len()); + assert!(out.ends_with("end\n")); + let (small, _) = start_failure_log_with("bob", NOW, NOW, |_| async { Ok("a\n".into()) }) + .await + .unwrap(); + assert_eq!(small, "a\n"); + } +} diff --git a/hive-priv/src/main.rs b/hive-priv/src/main.rs index 7dff824d..27f4f51f 100644 --- a/hive-priv/src/main.rs +++ b/hive-priv/src/main.rs @@ -360,6 +360,11 @@ async fn exec( match req { PrivRequest::StartContainer { ref name } => container::start_container(name).await, + PrivRequest::StartFailureLog { + ref name, + since_unix, + } => container::start_failure_log(name, since_unix).await, + PrivRequest::StopContainer { ref name } => container::stop_container(name).await, PrivRequest::KillContainer { ref name } => container::kill_container(name).await,