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 <noreply@anthropic.com>

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(),

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(())
 }

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(())
+}

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,
         }
     }
 }

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()?

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()?

crates/vmctl/src/commands/ssh.rs

@@ -15,13 +15,17 @@ pub struct SshArgs {
     /// VM name
     name: String,
 
-    /// SSH user
+    /// SSH user (overrides VMFile ssh block)
-    #[arg(long, default_value = "vm")]
+    #[arg(long)]
-    user: String,
+    user: Option<String>,
 
     /// Path to SSH private key
     #[arg(long)]
     key: Option<PathBuf>,
+
+    /// Path to VMFile.kdl (for reading ssh user)
+    #[arg(long)]
+    file: Option<PathBuf>,
 }
 
 /// Find the first existing SSH key in the user's .ssh directory.
@@ -38,6 +42,14 @@ fn find_ssh_key() -> Option<PathBuf> {
     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<String> {
+    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()?;
 

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()?