diff --git a/docs/tasks.md b/docs/tasks.md index 544d4c0..3c47be0 100644 --- a/docs/tasks.md +++ b/docs/tasks.md @@ -47,8 +47,9 @@ 2. [x] Remove old cli. 3. [x] add an actual config file. 4. [x] set up the cli. -9. [ ] fix ui overlap, and consistency issue. -10. [ ] intensive integration test. +9. [x] fix ui overlap, and consistency issue. +10. [ ] `clean_cache` to cleanup the cache. +11. [ ] intensive integration test. ## Publish diff --git a/src/bin/vibebox-cli.rs b/src/bin/vibebox-cli.rs index 9dff02d..d49d00f 100644 --- a/src/bin/vibebox-cli.rs +++ b/src/bin/vibebox-cli.rs @@ -11,7 +11,9 @@ use color_eyre::Result; use dialoguer::Confirm; use time::OffsetDateTime; use time::format_description::well_known::Rfc3339; -use tracing_subscriber::EnvFilter; +use tracing_subscriber::filter::LevelFilter; +use tracing_subscriber::registry::Registry; +use tracing_subscriber::{EnvFilter, fmt, prelude::*, reload}; use vibebox::tui::{AppState, VmInfo}; use vibebox::{ @@ -39,11 +41,11 @@ enum Command { } fn main() -> Result<()> { - init_tracing(); color_eyre::install()?; + let cwd = env::current_dir().map_err(|err| color_eyre::eyre::eyre!(err.to_string()))?; + let stderr_handle = init_tracing(&cwd); let cli = Cli::parse(); - let cwd = env::current_dir().map_err(|err| color_eyre::eyre::eyre!(err.to_string()))?; tracing::info!(cwd = %cwd.display(), "starting vibebox cli"); if let Some(command) = cli.command { return handle_command(command, &cwd, cli.config.as_deref()); @@ -79,12 +81,13 @@ fn main() -> Result<()> { mounts: config.box_cfg.mounts.clone(), }; + let auto_shutdown_ms = config.supervisor.auto_shutdown_ms; let vm_info = VmInfo { - version: env!("CARGO_PKG_VERSION").to_string(), max_memory_mb: vm_args.ram_bytes / (1024 * 1024), cpu_cores: vm_args.cpu_count, + system_name: "Debian".to_string(), // TODO: read system name from the VM. + auto_shutdown_ms, }; - let auto_shutdown_ms = config.supervisor.auto_shutdown_ms; if let Ok(manager) = SessionManager::new() { if let Err(err) = manager.update_global_sessions(&cwd) { tracing::warn!(error = %err, "failed to update a global session list"); @@ -104,6 +107,9 @@ fn main() -> Result<()> { writeln!(stdout)?; stdout.flush()?; } + if let Some(handle) = stderr_handle { + let _ = handle.modify(|filter| *filter = LevelFilter::INFO); + } tracing::info!(auto_shutdown_ms, "auto shutdown config"); let manager_conn = @@ -248,13 +254,62 @@ fn format_last_active(value: Option<&str>) -> String { format!("{} day{} ago", days, if days == 1 { "" } else { "s" }) } -fn init_tracing() { +type StderrHandle = reload::Handle; + +fn init_tracing(cwd: &Path) -> Option { let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info")); - let ansi = std::io::stderr().is_terminal() && env::var("VIBEBOX_LOG_NO_COLOR").is_err(); - let _ = tracing_subscriber::fmt() - .with_env_filter(filter) - .with_target(false) - .with_ansi(ansi) - .with_writer(std::io::stderr) - .try_init(); + let file_filter = filter.clone(); + let stderr_is_tty = std::io::stderr().is_terminal(); + let ansi = stderr_is_tty && env::var("VIBEBOX_LOG_NO_COLOR").is_err(); + let file = instance::ensure_instance_dir(cwd) + .ok() + .and_then(|instance_dir| { + let log_path = instance_dir.join("cli.log"); + std::fs::OpenOptions::new() + .create(true) + .write(true) + .truncate(true) + .open(log_path) + .ok() + }); + + if stderr_is_tty { + let (stderr_filter, handle) = reload::Layer::new(LevelFilter::OFF); + let stderr_layer = fmt::layer() + .with_target(false) + .with_ansi(ansi) + .without_time() + .with_writer(std::io::stderr) + .with_filter(stderr_filter); + let subscriber = tracing_subscriber::registry().with(stderr_layer); + if let Some(file) = file { + let file_layer = fmt::layer() + .with_target(false) + .with_ansi(false) + .with_writer(file) + .with_filter(file_filter); + let _ = subscriber.with(file_layer).try_init(); + } else { + let _ = subscriber.try_init(); + } + Some(handle) + } else { + let stderr_layer = fmt::layer() + .with_target(false) + .with_ansi(ansi) + .with_writer(std::io::stderr) + .with_filter(filter); + let subscriber = tracing_subscriber::registry().with(stderr_layer); + if let Some(file) = file { + let file_layer = fmt::layer() + .with_target(false) + .with_ansi(false) + .with_writer(file) + .with_filter(file_filter); + let _ = subscriber.with(file_layer).try_init(); + } else { + let _ = subscriber.try_init(); + } + None + } } diff --git a/src/bin/vibebox-supervisor.rs b/src/bin/vibebox-supervisor.rs index 25464c1..396c0ce 100644 --- a/src/bin/vibebox-supervisor.rs +++ b/src/bin/vibebox-supervisor.rs @@ -5,6 +5,9 @@ use std::{ use color_eyre::Result; use tracing_subscriber::EnvFilter; +use tracing_subscriber::filter::LevelFilter; +use tracing_subscriber::fmt; +use tracing_subscriber::prelude::*; use vibebox::{config, instance, vm, vm_manager}; @@ -40,11 +43,22 @@ fn main() -> Result<()> { fn init_tracing() { let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info")); - let ansi = std::io::stderr().is_terminal() && env::var("VIBEBOX_LOG_NO_COLOR").is_err(); - let _ = tracing_subscriber::fmt() - .with_env_filter(filter) - .with_target(false) - .with_ansi(ansi) - .with_writer(io::stderr) - .try_init(); + let stderr_is_tty = std::io::stderr().is_terminal(); + let ansi = stderr_is_tty && env::var("VIBEBOX_LOG_NO_COLOR").is_err(); + if stderr_is_tty { + let stderr_layer = fmt::layer() + .with_target(false) + .with_ansi(ansi) + .without_time() + .with_writer(io::stderr) + .with_filter(LevelFilter::INFO); + let _ = tracing_subscriber::registry().with(stderr_layer).try_init(); + } else { + let stderr_layer = fmt::layer() + .with_target(false) + .with_ansi(ansi) + .with_writer(io::stderr) + .with_filter(filter); + let _ = tracing_subscriber::registry().with(stderr_layer).try_init(); + } } diff --git a/src/config.rs b/src/config.rs index 1c00d9b..0688c92 100644 --- a/src/config.rs +++ b/src/config.rs @@ -279,6 +279,6 @@ fn validate_or_exit(config: &Config) { } fn die(message: &str) -> ! { - eprintln!("[vibebox] {message}"); + tracing::error!("{message}"); std::process::exit(1); } diff --git a/src/instance.rs b/src/instance.rs index a652a86..3d91b3a 100644 --- a/src/instance.rs +++ b/src/instance.rs @@ -26,7 +26,7 @@ use crate::{ }; const SSH_KEY_NAME: &str = "ssh_key"; -pub(crate) const SERIAL_LOG_NAME: &str = "serial.log"; +pub(crate) const VM_ROOT_LOG_NAME: &str = "vm_root.log"; pub(crate) const DEFAULT_SSH_USER: &str = "vibecoder"; const SSH_CONNECT_RETRIES: usize = 30; const SSH_CONNECT_DELAY_MS: u64 = 500; @@ -72,7 +72,6 @@ pub fn run_with_ssh(manager_conn: UnixStream) -> Result<(), Box Result<(), Box> { let start = Instant::now(); + let mut next_log_at = start + Duration::from_secs(10); + tracing::info!("waiting for vm ipv4"); + let mut once_hint = false; loop { let config = load_or_create_instance_config(instance_dir)?; if config.vm_ipv4.is_some() { @@ -254,8 +256,16 @@ fn wait_for_vm_ipv4( if start.elapsed() > timeout { return Err("Timed out waiting for VM IPv4".into()); } - if start.elapsed().as_secs() % 5 == 0 { - tracing::debug!("still waiting for vm ipv4"); + if Instant::now() >= next_log_at { + let waited = start.elapsed(); + if waited.as_secs() > 15 && !once_hint { + tracing::info!( + "if vibebox is just initialized in this directory, it might take up to 1 minutes depending on your machine, and then you can enjoy the speed vibecoding! go pack!" + ); + once_hint = true; + } + tracing::info!("still waiting for vm ipv4, {}s elapsed", waited.as_secs(),); + next_log_at += Duration::from_secs(10); } thread::sleep(Duration::from_millis(200)); } @@ -270,9 +280,13 @@ fn run_ssh_session( loop { attempts += 1; if !ssh_port_open(&ip) { - tracing::debug!(attempts, "ssh port not open yet"); - eprintln!( - "[vibebox] waiting for ssh port on {ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})" + tracing::debug!(attempts, "ssh port doesn't open yet"); + tracing::info!( + attempts, + ip = %ip, + "waiting for ssh port ({}/{})", + attempts, + SSH_CONNECT_RETRIES ); if attempts >= SSH_CONNECT_RETRIES { return Err( @@ -283,10 +297,14 @@ fn run_ssh_session( continue; } - eprintln!( - "[vibebox] starting ssh to {ssh_user}@{ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})" + tracing::info!( + attempts, + user = %ssh_user, + ip = %ip, + "starting ssh ({}/{})", + attempts, + SSH_CONNECT_RETRIES ); - tracing::info!(attempts, user = %ssh_user, ip = %ip, "starting ssh"); let status = Command::new("ssh") .args([ "-i", @@ -319,21 +337,22 @@ fn run_ssh_session( match status { Ok(status) if status.success() => { - eprintln!("[vibebox] ssh exited with status: {status}"); + tracing::info!(status = %status, "ssh exited"); break; } Ok(status) if status.code() == Some(255) => { - eprintln!("[vibebox] ssh connection failed: {status}"); + tracing::warn!(status = %status, "ssh connection failed"); if attempts >= SSH_CONNECT_RETRIES { return Err(format!("ssh failed after {SSH_CONNECT_RETRIES} attempts").into()); } thread::sleep(Duration::from_millis(500)); } Ok(status) => { - eprintln!("[vibebox] ssh exited with status: {status}"); + tracing::info!(status = %status, "ssh exited"); break; } Err(err) => { + tracing::error!(error = %err, "failed to start ssh"); return Err(format!("failed to start ssh: {err}").into()); } } @@ -404,7 +423,7 @@ fn spawn_ssh_io( ) -> vm::IoContext { let io_control = vm::IoControl::new(); - let log_path = instance_dir.join(SERIAL_LOG_NAME); + let log_path = instance_dir.join(VM_ROOT_LOG_NAME); let log_file = fs::OpenOptions::new() .create(true) .write(true) @@ -458,7 +477,7 @@ fn spawn_ssh_io( if cfg.vm_ipv4.as_deref() != Some(ip.as_str()) { cfg.vm_ipv4 = Some(ip.clone()); let _ = write_instance_config(&instance_path, &cfg); - eprintln!("[vibebox] detected vm IPv4: {ip}"); + tracing::info!(ip = %ip, "detected vm ipv4"); } } } @@ -466,7 +485,7 @@ fn spawn_ssh_io( if cleaned.contains("VIBEBOX_SSH_READY") { ssh_ready_for_output.store(true, Ordering::SeqCst); - eprintln!("[vibebox] sshd ready"); + tracing::info!("sshd ready"); } } }; @@ -517,7 +536,7 @@ fn spawn_ssh_io( break; } - eprintln!("[vibebox] starting ssh to {ssh_user}@{ip}"); + tracing::info!(user = %ssh_user, ip = %ip, "starting ssh"); io_control_for_thread.request_terminal_restore(); io_control_for_thread.set_forward_output(false); io_control_for_thread.set_forward_input(false); @@ -527,13 +546,19 @@ fn spawn_ssh_io( loop { attempts += 1; if !ssh_port_open(&ip) { - eprintln!( - "[vibebox] waiting for ssh port on {ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})" + tracing::info!( + attempts, + ip = %ip, + "waiting for ssh port ({}/{})", + attempts, + SSH_CONNECT_RETRIES ); if attempts >= SSH_CONNECT_RETRIES { ssh_connected_for_thread.store(false, Ordering::SeqCst); - eprintln!( - "[vibebox] ssh port not ready after {SSH_CONNECT_RETRIES} attempts" + tracing::warn!( + attempts, + "ssh port not ready after {} attempts", + SSH_CONNECT_RETRIES ); break; } @@ -541,8 +566,13 @@ fn spawn_ssh_io( continue; } - eprintln!( - "[vibebox] starting ssh to {ssh_user}@{ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})" + tracing::info!( + attempts, + user = %ssh_user, + ip = %ip, + "starting ssh ({}/{})", + attempts, + SSH_CONNECT_RETRIES ); let status = Command::new("ssh") .args([ @@ -577,18 +607,20 @@ fn spawn_ssh_io( match status { Ok(status) if status.success() => { ssh_connected_for_thread.store(false, Ordering::SeqCst); - eprintln!("[vibebox] ssh exited with status: {status}"); + tracing::info!(status = %status, "ssh exited"); if let Some(tx) = input_tx_holder_for_thread.lock().unwrap().clone() { let _ = tx.send(VmInput::Bytes(b"systemctl poweroff\n".to_vec())); } break; } Ok(status) if status.code() == Some(255) => { - eprintln!("[vibebox] ssh connection failed: {status}"); + tracing::warn!(status = %status, "ssh connection failed"); if attempts >= SSH_CONNECT_RETRIES { ssh_connected_for_thread.store(false, Ordering::SeqCst); - eprintln!( - "[vibebox] ssh failed after {SSH_CONNECT_RETRIES} attempts" + tracing::warn!( + attempts, + "ssh failed after {} attempts", + SSH_CONNECT_RETRIES ); break; } @@ -597,7 +629,7 @@ fn spawn_ssh_io( } Ok(status) => { ssh_connected_for_thread.store(false, Ordering::SeqCst); - eprintln!("[vibebox] ssh exited with status: {status}"); + tracing::info!(status = %status, "ssh exited"); if let Some(tx) = input_tx_holder_for_thread.lock().unwrap().clone() { let _ = tx.send(VmInput::Bytes(b"systemctl poweroff\n".to_vec())); } @@ -605,7 +637,7 @@ fn spawn_ssh_io( } Err(err) => { ssh_connected_for_thread.store(false, Ordering::SeqCst); - eprintln!("[vibebox] failed to start ssh: {err}"); + tracing::error!(error = %err, "failed to start ssh"); break; } } diff --git a/src/tui.rs b/src/tui.rs index 1a4371c..fcd231e 100644 --- a/src/tui.rs +++ b/src/tui.rs @@ -34,12 +34,14 @@ const ASCII_BANNER: [&str; 7] = [ " ╚═══╝ ╚═╝╚═════╝ ╚══════╝╚═════╝ ╚═════╝ ╚═╝ ╚═╝", "", ]; +const INFO_LINE_COUNT: u16 = 5; #[derive(Debug, Clone)] pub struct VmInfo { - pub version: String, pub max_memory_mb: u64, pub cpu_cores: usize, + pub system_name: String, + pub auto_shutdown_ms: u64, } #[derive(Debug)] @@ -155,10 +157,14 @@ fn compute_page_layout(app: &AppState, width: u16) -> PageLayout { fn header_height() -> u16 { let banner_height = ASCII_BANNER.len() as u16; let welcome_height = 1; - let info_height = 4; + let info_height = info_block_height(); welcome_height + banner_height + info_height } +fn info_block_height() -> u16 { + INFO_LINE_COUNT.saturating_add(1) +} + pub fn render_tui_once(app: &mut AppState) -> Result<()> { let (width, _) = crossterm::terminal::size()?; if width == 0 { @@ -532,13 +538,15 @@ fn render_header(buffer: &mut Buffer, area: Rect, app: &AppState) { .constraints([ Constraint::Length(1), Constraint::Length(ASCII_BANNER.len() as u16), - Constraint::Length(4), + Constraint::Length(info_block_height()), ]) .split(area); + let version = env!("CARGO_PKG_VERSION"); + let welcome = Line::from(vec![ Span::raw("Welcome to Vibebox v"), - Span::styled(&app.vm_info.version, Style::default().fg(Color::Yellow)), + Span::styled(version, Style::default().fg(Color::Yellow)), ]); Paragraph::new(welcome).render(header_chunks[0], buffer); @@ -557,8 +565,8 @@ fn render_header(buffer: &mut Buffer, area: Rect, app: &AppState) { Span::styled(app.cwd.to_string_lossy(), Style::default().fg(Color::Cyan)), ]), Line::from(vec![ - Span::raw("VM Version: "), - Span::styled(&app.vm_info.version, Style::default().fg(Color::Green)), + Span::raw("System: "), + Span::styled(&app.vm_info.system_name, Style::default().fg(Color::Green)), ]), Line::from(vec![ Span::raw("CPU / Memory: "), @@ -570,6 +578,13 @@ fn render_header(buffer: &mut Buffer, area: Rect, app: &AppState) { Style::default().fg(Color::Green), ), ]), + Line::from(vec![ + Span::raw("Auto Shutdown: "), + Span::styled( + format!("{} ms", app.vm_info.auto_shutdown_ms), + Style::default().fg(Color::Green), + ), + ]), ]; Paragraph::new(info_lines) diff --git a/src/vm.rs b/src/vm.rs index 43207d3..3dce637 100644 --- a/src/vm.rs +++ b/src/vm.rs @@ -429,7 +429,7 @@ fn ensure_base_image( if !base_compressed.exists() || std::fs::metadata(base_compressed).map(|m| m.len())? < DEBIAN_COMPRESSED_SIZE_BYTES { - println!("Downloading base image..."); + tracing::info!("downloading base image"); let status = Command::new("curl") .args([ "--continue-at", @@ -470,7 +470,7 @@ fn ensure_base_image( } } - println!("Decompressing base image..."); + tracing::info!("decompressing base image"); let status = Command::new("tar") .args([ "-xOf", @@ -499,7 +499,7 @@ fn ensure_default_image( ensure_base_image(base_raw, base_compressed)?; - println!("Configuring base image..."); + tracing::info!("configuring base image"); fs::copy(base_raw, default_raw)?; let provision_command = script_command_from_content(PROVISION_SCRIPT_NAME, PROVISION_SCRIPT)?; @@ -522,7 +522,7 @@ fn ensure_instance_disk( return Ok(()); } - println!("Creating instance disk from {}...", template_raw.display()); + tracing::info!(path = %template_raw.display(), "creating instance disk"); std::fs::create_dir_all(instance_raw.parent().unwrap())?; fs::copy(template_raw, instance_raw)?; Ok(()) @@ -961,7 +961,7 @@ fn spawn_login_actions_thread( let command = match script_command_from_path(&path, index) { Ok(command) => command, Err(err) => { - eprintln!("{err}"); + tracing::error!(error = %err, "failed to build login script command"); return; } }; @@ -1042,7 +1042,7 @@ where return Err("Timed out waiting for VM to start".into()); } - println!("VM booting..."); + tracing::info!("vm booting"); let output_monitor = Arc::new(OutputMonitor::default()); let io_ctx = io_handler(output_monitor.clone(), we_read_from, we_write_to); @@ -1111,7 +1111,7 @@ where unsafe { if vm.canRequestStop() { if let Err(err) = vm.requestStopWithError() { - eprintln!("Failed to request VM stop: {:?}", err); + tracing::error!(error = ?err, "failed to request VM stop"); } } else if vm.canStop() { let handler = RcBlock::new(|_error: *mut NSError| {}); @@ -1249,15 +1249,15 @@ pub fn ensure_signed() { match status { Ok(s) if s.success() => { let err = Command::new(&exe).args(std::env::args_os().skip(1)).exec(); - eprintln!("failed to re-exec after signing: {err}"); + tracing::error!(error = %err, "failed to re-exec after signing"); std::process::exit(1); } Ok(s) => { - eprintln!("codesign failed with status: {s}"); + tracing::error!(status = %s, "codesign failed"); std::process::exit(1); } Err(e) => { - eprintln!("failed to run codesign: {e}"); + tracing::error!(error = %e, "failed to run codesign"); std::process::exit(1); } } diff --git a/src/vm_manager.rs b/src/vm_manager.rs index 079adb0..1d0f479 100644 --- a/src/vm_manager.rs +++ b/src/vm_manager.rs @@ -17,7 +17,7 @@ use std::{ use crate::{ config::CONFIG_PATH_ENV, - instance::SERIAL_LOG_NAME, + instance::VM_ROOT_LOG_NAME, instance::{ DEFAULT_SSH_USER, InstanceConfig, build_ssh_login_actions, ensure_instance_dir, ensure_ssh_keypair, extract_ipv4, load_or_create_instance_config, write_instance_config, @@ -451,7 +451,7 @@ fn spawn_manager_io( vm_output_fd: std::os::unix::io::OwnedFd, vm_input_fd: std::os::unix::io::OwnedFd, ) -> vm::IoContext { - let log_path = instance_dir.join(SERIAL_LOG_NAME); + let log_path = instance_dir.join(VM_ROOT_LOG_NAME); let log_file = fs::OpenOptions::new() .create(true) .write(true)