From acdf43ae5a11ff8424cd0b875452252692dfead7 Mon Sep 17 00:00:00 2001 From: Till Wegmueller Date: Sun, 15 Feb 2026 12:01:25 +0100 Subject: [PATCH] Add console and provision logging, vmctl log command, fix ssh user - QEMU serial console now logs to console.log in the VM's work directory via chardev logfile, so boot and cloud-init output can be reviewed after the fact. - Provision steps stream stdout/stderr through tracing and append to provision.log in the work directory. - vmctl ssh now reads the VMFile ssh block to resolve the user (e.g. "smithy") instead of always defaulting to "vm". - New vmctl log command shows console and/or provision logs with optional --tail support. Co-Authored-By: Claude Opus 4.6 --- crates/vm-manager/src/backends/qemu.rs | 10 ++- crates/vm-manager/src/provision.rs | 60 +++++++++++++++++- crates/vmctl/src/commands/log.rs | 71 ++++++++++++++++++++++ crates/vmctl/src/commands/mod.rs | 4 ++ crates/vmctl/src/commands/provision_cmd.rs | 9 ++- crates/vmctl/src/commands/reload.rs | 9 ++- crates/vmctl/src/commands/ssh.rs | 30 +++++++-- crates/vmctl/src/commands/up.rs | 9 ++- 8 files changed, 189 insertions(+), 13 deletions(-) create mode 100644 crates/vmctl/src/commands/log.rs diff --git a/crates/vm-manager/src/backends/qemu.rs b/crates/vm-manager/src/backends/qemu.rs index 8f3b288..2b741d5 100644 --- a/crates/vm-manager/src/backends/qemu.rs +++ b/crates/vm-manager/src/backends/qemu.rs @@ -216,9 +216,15 @@ impl Hypervisor for QemuBackend { // QMP socket "-qmp".into(), format!("unix:{},server,nowait", qmp_sock.display()), - // Serial console socket + // Serial console: Unix socket (interactive) + log file for post-mortem review + "-chardev".into(), + format!( + "socket,id=serial0,path={},server=on,wait=off,logfile={}", + console_sock.display(), + vm.work_dir.join("console.log").display(), + ), "-serial".into(), - format!("unix:{},server,nowait", console_sock.display()), + "chardev:serial0".into(), // VNC on localhost with auto-port "-vnc".into(), "127.0.0.1:0".into(), diff --git a/crates/vm-manager/src/provision.rs b/crates/vm-manager/src/provision.rs index c71915f..a16b09e 100644 --- a/crates/vm-manager/src/provision.rs +++ b/crates/vm-manager/src/provision.rs @@ -1,3 +1,5 @@ +use std::fs::OpenOptions; +use std::io::Write; use std::path::Path; use ssh2::Session; @@ -8,32 +10,70 @@ use crate::ssh; use crate::vmfile::{FileProvision, ProvisionDef, ShellProvision, resolve_path}; /// Run all provision steps on an established SSH session. +/// +/// If `log_dir` is provided, all stdout/stderr from provision steps is appended to +/// `provision.log` in that directory. pub fn run_provisions( sess: &Session, provisions: &[ProvisionDef], base_dir: &Path, vm_name: &str, + log_dir: Option<&Path>, ) -> Result<()> { for (i, prov) in provisions.iter().enumerate() { let step = i + 1; match prov { ProvisionDef::Shell(shell) => { - run_shell(sess, shell, base_dir, vm_name, step)?; + run_shell(sess, shell, base_dir, vm_name, step, log_dir)?; } ProvisionDef::File(file) => { - run_file(sess, file, base_dir, vm_name, step)?; + run_file(sess, file, base_dir, vm_name, step, log_dir)?; } } } Ok(()) } +/// Log provision output to tracing and optionally to a file. +fn log_output(vm_name: &str, step: usize, label: &str, stdout: &str, stderr: &str) { + for line in stdout.lines() { + info!(vm = %vm_name, step, "[{label}:stdout] {line}"); + } + for line in stderr.lines() { + info!(vm = %vm_name, step, "[{label}:stderr] {line}"); + } +} + +/// Append provision output to a log file in the given directory. +pub fn append_provision_log(log_dir: &Path, step: usize, label: &str, stdout: &str, stderr: &str) { + let log_path = log_dir.join("provision.log"); + if let Ok(mut f) = OpenOptions::new().create(true).append(true).open(&log_path) { + let _ = writeln!(f, "=== Step {step}: {label} ==="); + if !stdout.is_empty() { + let _ = writeln!(f, "--- stdout ---"); + let _ = write!(f, "{stdout}"); + if !stdout.ends_with('\n') { + let _ = writeln!(f); + } + } + if !stderr.is_empty() { + let _ = writeln!(f, "--- stderr ---"); + let _ = write!(f, "{stderr}"); + if !stderr.ends_with('\n') { + let _ = writeln!(f); + } + } + let _ = writeln!(f); + } +} + fn run_shell( sess: &Session, shell: &ShellProvision, base_dir: &Path, vm_name: &str, step: usize, + log_dir: Option<&Path>, ) -> Result<()> { if let Some(ref cmd) = shell.inline { info!(vm = %vm_name, step, cmd = %cmd, "running inline shell provision"); @@ -44,6 +84,11 @@ fn run_shell( detail: format!("shell exec: {e}"), })?; + log_output(vm_name, step, cmd, &stdout, &stderr); + if let Some(dir) = log_dir { + append_provision_log(dir, step, cmd, &stdout, &stderr); + } + if exit_code != 0 { return Err(VmError::ProvisionFailed { vm: vm_name.into(), @@ -77,6 +122,11 @@ fn run_shell( detail: format!("script exec: {e}"), })?; + log_output(vm_name, step, script_raw, &stdout, &stderr); + if let Some(dir) = log_dir { + append_provision_log(dir, step, script_raw, &stdout, &stderr); + } + if exit_code != 0 { return Err(VmError::ProvisionFailed { vm: vm_name.into(), @@ -97,6 +147,7 @@ fn run_file( base_dir: &Path, vm_name: &str, step: usize, + log_dir: Option<&Path>, ) -> Result<()> { let local_path = resolve_path(&file.source, base_dir); let remote_path = Path::new(&file.destination); @@ -115,6 +166,11 @@ fn run_file( detail: format!("file upload: {e}"), })?; + let msg = format!("{} -> {}", local_path.display(), file.destination); + if let Some(dir) = log_dir { + append_provision_log(dir, step, "file-upload", &msg, ""); + } + info!(vm = %vm_name, step, "file provision completed"); Ok(()) } diff --git a/crates/vmctl/src/commands/log.rs b/crates/vmctl/src/commands/log.rs new file mode 100644 index 0000000..beb2305 --- /dev/null +++ b/crates/vmctl/src/commands/log.rs @@ -0,0 +1,71 @@ +use clap::Args; +use miette::{IntoDiagnostic, Result}; + +use super::state; + +#[derive(Args)] +pub struct LogArgs { + /// VM name + name: String, + + /// Show only console log (boot / cloud-init) + #[arg(long)] + console: bool, + + /// Show only provision log + #[arg(long)] + provision: bool, + + /// Show the last N lines (0 = all) + #[arg(long, short = 'n', default_value = "0")] + tail: usize, +} + +pub async fn run(args: LogArgs) -> Result<()> { + let store = state::load_store().await?; + let handle = store + .get(&args.name) + .ok_or_else(|| miette::miette!("VM '{}' not found", args.name))?; + + // If neither flag is set, show both + let show_console = args.console || !args.provision; + let show_provision = args.provision || !args.console; + + if show_console { + let path = handle.work_dir.join("console.log"); + print_log("console", &path, args.tail).await?; + } + + if show_provision { + let path = handle.work_dir.join("provision.log"); + print_log("provision", &path, args.tail).await?; + } + + Ok(()) +} + +async fn print_log(label: &str, path: &std::path::Path, tail: usize) -> Result<()> { + match tokio::fs::read_to_string(path).await { + Ok(content) => { + println!("=== {label} log ({}) ===", path.display()); + if tail > 0 { + let lines: Vec<&str> = content.lines().collect(); + let start = lines.len().saturating_sub(tail); + for line in &lines[start..] { + println!("{line}"); + } + } else { + print!("{content}"); + } + println!(); + } + Err(e) if e.kind() == std::io::ErrorKind::NotFound => { + println!("=== {label} log: not found (VM may not have been started yet) ==="); + println!(); + } + Err(e) => { + return Err(e).into_diagnostic(); + } + } + Ok(()) +} diff --git a/crates/vmctl/src/commands/mod.rs b/crates/vmctl/src/commands/mod.rs index 132e505..de9abd3 100644 --- a/crates/vmctl/src/commands/mod.rs +++ b/crates/vmctl/src/commands/mod.rs @@ -4,6 +4,7 @@ pub mod destroy; pub mod down; pub mod image; pub mod list; +pub mod log; pub mod provision_cmd; pub mod reload; pub mod ssh; @@ -56,6 +57,8 @@ enum Command { Reload(reload::ReloadArgs), /// Re-run provisioners on running VMs from VMFile.kdl Provision(provision_cmd::ProvisionArgs), + /// Show VM console and provision logs + Log(log::LogArgs), } impl Cli { @@ -76,6 +79,7 @@ impl Cli { Command::Down(args) => down::run(args).await, Command::Reload(args) => reload::run(args).await, Command::Provision(args) => provision_cmd::run(args).await, + Command::Log(args) => log::run(args).await, } } } diff --git a/crates/vmctl/src/commands/provision_cmd.rs b/crates/vmctl/src/commands/provision_cmd.rs index c5a0ced..64d9645 100644 --- a/crates/vmctl/src/commands/provision_cmd.rs +++ b/crates/vmctl/src/commands/provision_cmd.rs @@ -73,8 +73,15 @@ pub async fn run(args: ProvisionArgs) -> Result<()> { let provisions = def.provisions.clone(); let base_dir = vmfile.base_dir.clone(); let name = def.name.clone(); + let log_dir = handle.work_dir.clone(); tokio::task::spawn_blocking(move || { - vm_manager::provision::run_provisions(&sess, &provisions, &base_dir, &name) + vm_manager::provision::run_provisions( + &sess, + &provisions, + &base_dir, + &name, + Some(&log_dir), + ) }) .await .into_diagnostic()? diff --git a/crates/vmctl/src/commands/reload.rs b/crates/vmctl/src/commands/reload.rs index 1467f09..de3d22b 100644 --- a/crates/vmctl/src/commands/reload.rs +++ b/crates/vmctl/src/commands/reload.rs @@ -109,8 +109,15 @@ async fn run_provision_for_vm( let provisions = provisions.to_vec(); let base_dir = base_dir.to_path_buf(); let name = vm_name.to_string(); + let log_dir = handle.work_dir.clone(); tokio::task::spawn_blocking(move || { - vm_manager::provision::run_provisions(&sess, &provisions, &base_dir, &name) + vm_manager::provision::run_provisions( + &sess, + &provisions, + &base_dir, + &name, + Some(&log_dir), + ) }) .await .into_diagnostic()? diff --git a/crates/vmctl/src/commands/ssh.rs b/crates/vmctl/src/commands/ssh.rs index 599db65..07b8fd8 100644 --- a/crates/vmctl/src/commands/ssh.rs +++ b/crates/vmctl/src/commands/ssh.rs @@ -15,13 +15,17 @@ pub struct SshArgs { /// VM name name: String, - /// SSH user - #[arg(long, default_value = "vm")] - user: String, + /// SSH user (overrides VMFile ssh block) + #[arg(long)] + user: Option, /// Path to SSH private key #[arg(long)] key: Option, + + /// Path to VMFile.kdl (for reading ssh user) + #[arg(long)] + file: Option, } /// Find the first existing SSH key in the user's .ssh directory. @@ -38,6 +42,14 @@ fn find_ssh_key() -> Option { None } +/// Try to read the ssh user from the VMFile for the given VM name. +fn ssh_user_from_vmfile(vm_name: &str, explicit_file: Option<&std::path::Path>) -> Option { + let path = vm_manager::vmfile::discover(explicit_file).ok()?; + let vmfile = vm_manager::vmfile::parse(&path).ok()?; + let def = vmfile.vms.iter().find(|d| d.name == vm_name)?; + Some(def.ssh.as_ref()?.user.clone()) +} + pub async fn run(args: SshArgs) -> Result<()> { let store = state::load_store().await?; let handle = store @@ -53,6 +65,12 @@ pub async fn run(args: SshArgs) -> Result<()> { _ => 22, }; + // Resolve user: CLI flag → VMFile → default "vm" + let user = args + .user + .or_else(|| ssh_user_from_vmfile(&args.name, args.file.as_deref())) + .unwrap_or_else(|| "vm".to_string()); + // Check for a generated key in the VM's work directory first, then user keys let generated_key = handle.work_dir.join(super::GENERATED_KEY_FILE); let key_path = args @@ -67,13 +85,13 @@ pub async fn run(args: SshArgs) -> Result<()> { })?; let config = SshConfig { - user: args.user.clone(), + user: user.clone(), public_key: None, private_key_path: Some(key_path), private_key_pem: None, }; - println!("Connecting to {}@{}:{}...", args.user, ip, port); + println!("Connecting to {user}@{ip}:{port}..."); let sess = vm_manager::ssh::connect_with_retry(&ip, port, &config, Duration::from_secs(30)) .await @@ -99,7 +117,7 @@ pub async fn run(args: SshArgs) -> Result<()> { cmd.arg("-i").arg(key); } - cmd.arg(format!("{}@{}", args.user, ip)); + cmd.arg(format!("{user}@{ip}")); let status = cmd.status().await.into_diagnostic()?; diff --git a/crates/vmctl/src/commands/up.rs b/crates/vmctl/src/commands/up.rs index ff52383..bc9ff9e 100644 --- a/crates/vmctl/src/commands/up.rs +++ b/crates/vmctl/src/commands/up.rs @@ -130,8 +130,15 @@ async fn run_provision_for_vm( let provisions = provisions.to_vec(); let base_dir = base_dir.to_path_buf(); let name = vm_name.to_string(); + let log_dir = handle.work_dir.clone(); tokio::task::spawn_blocking(move || { - vm_manager::provision::run_provisions(&sess, &provisions, &base_dir, &name) + vm_manager::provision::run_provisions( + &sess, + &provisions, + &base_dir, + &name, + Some(&log_dir), + ) }) .await .into_diagnostic()?