@@ -26,7 +26,7 @@ use crate::{
28const SSH_KEY_NAME: &str = "ssh_key";
28const SSH_KEY_NAME: &str = "ssh_key";
29−pub(crate) const SERIAL_LOG_NAME: &str = "serial.log";
29+pub(crate) const VM_ROOT_LOG_NAME: &str = "vm_root.log";
30pub(crate) const DEFAULT_SSH_USER: &str = "vibecoder";
30pub(crate) const DEFAULT_SSH_USER: &str = "vibecoder";
31const SSH_CONNECT_RETRIES: usize = 30;
31const SSH_CONNECT_RETRIES: usize = 30;
32const SSH_CONNECT_DELAY_MS: u64 = 500;
32const SSH_CONNECT_DELAY_MS: u64 = 500;
@@ -72,7 +72,6 @@ pub fn run_with_ssh(manager_conn: UnixStream) -> Result<(), Box<dyn std::error::
72 tracing::debug!(ssh_user = %ssh_user, "loaded instance config");
72 tracing::debug!(ssh_user = %ssh_user, "loaded instance config");
74 let _manager_conn = manager_conn;
74 let _manager_conn = manager_conn;
75− tracing::debug!("waiting for vm ipv4");
76 wait_for_vm_ipv4(&instance_dir, Duration::from_secs(120))?;
75 wait_for_vm_ipv4(&instance_dir, Duration::from_secs(120))?;
78 let ip = load_or_create_instance_config(&instance_dir)?
77 let ip = load_or_create_instance_config(&instance_dir)?
@@ -118,7 +117,7 @@ pub(crate) fn ensure_ssh_keypair(
118 "vibebox",
117 "vibebox",
120 .stdin(Stdio::null())
119 .stdin(Stdio::null())
121− .stdout(Stdio::null())
120+ .stdout(Stdio::inherit())
122 .stderr(Stdio::inherit())
121 .stderr(Stdio::inherit())
123 .status()?;
122 .status()?;
@@ -246,6 +245,9 @@ fn wait_for_vm_ipv4(
246 timeout: Duration,
245 timeout: Duration,
247) -> Result<(), Box<dyn std::error::Error>> {
246) -> Result<(), Box<dyn std::error::Error>> {
248 let start = Instant::now();
247 let start = Instant::now();
248+ let mut next_log_at = start + Duration::from_secs(10);
249+ tracing::info!("waiting for vm ipv4");
250+ let mut once_hint = false;
250 let config = load_or_create_instance_config(instance_dir)?;
252 let config = load_or_create_instance_config(instance_dir)?;
251 if config.vm_ipv4.is_some() {
253 if config.vm_ipv4.is_some() {
@@ -254,8 +256,16 @@ fn wait_for_vm_ipv4(
254 if start.elapsed() > timeout {
256 if start.elapsed() > timeout {
255 return Err("Timed out waiting for VM IPv4".into());
257 return Err("Timed out waiting for VM IPv4".into());
259+ if Instant::now() >= next_log_at {
257− if start.elapsed().as_secs() % 5 == 0 {
260+ let waited = start.elapsed();
261+ if waited.as_secs() > 15 && !once_hint {
263+ "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!"
258− tracing::debug!("still waiting for vm ipv4");
267+ tracing::info!("still waiting for vm ipv4, {}s elapsed", waited.as_secs(),);
268+ next_log_at += Duration::from_secs(10);
260 thread::sleep(Duration::from_millis(200));
270 thread::sleep(Duration::from_millis(200));
@@ -270,9 +280,13 @@ fn run_ssh_session(
271 attempts += 1;
281 attempts += 1;
272 if !ssh_port_open(&ip) {
282 if !ssh_port_open(&ip) {
273− tracing::debug!(attempts, "ssh port not open yet");
283+ tracing::debug!(attempts, "ssh port doesn't open yet");
274− eprintln!(
284+ tracing::info!(
287+ "waiting for ssh port ({}/{})",
275− "[vibebox] waiting for ssh port on {ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})"
289+ SSH_CONNECT_RETRIES
277 if attempts >= SSH_CONNECT_RETRIES {
291 if attempts >= SSH_CONNECT_RETRIES {
278 return Err(
292 return Err(
@@ -283,10 +297,14 @@ fn run_ssh_session(
283 continue;
297 continue;
286− eprintln!(
300+ tracing::info!(
304+ "starting ssh ({}/{})",
287− "[vibebox] starting ssh to {ssh_user}@{ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})"
306+ SSH_CONNECT_RETRIES
289− tracing::info!(attempts, user = %ssh_user, ip = %ip, "starting ssh");
290 let status = Command::new("ssh")
308 let status = Command::new("ssh")
@@ -319,21 +337,22 @@ fn run_ssh_session(
320 match status {
338 match status {
321 Ok(status) if status.success() => {
339 Ok(status) if status.success() => {
322− eprintln!("[vibebox] ssh exited with status: {status}");
340+ tracing::info!(status = %status, "ssh exited");
325 Ok(status) if status.code() == Some(255) => {
343 Ok(status) if status.code() == Some(255) => {
326− eprintln!("[vibebox] ssh connection failed: {status}");
344+ tracing::warn!(status = %status, "ssh connection failed");
327 if attempts >= SSH_CONNECT_RETRIES {
345 if attempts >= SSH_CONNECT_RETRIES {
328 return Err(format!("ssh failed after {SSH_CONNECT_RETRIES} attempts").into());
346 return Err(format!("ssh failed after {SSH_CONNECT_RETRIES} attempts").into());
330 thread::sleep(Duration::from_millis(500));
348 thread::sleep(Duration::from_millis(500));
332 Ok(status) => {
350 Ok(status) => {
333− eprintln!("[vibebox] ssh exited with status: {status}");
351+ tracing::info!(status = %status, "ssh exited");
336 Err(err) => {
354 Err(err) => {
355+ tracing::error!(error = %err, "failed to start ssh");
337 return Err(format!("failed to start ssh: {err}").into());
356 return Err(format!("failed to start ssh: {err}").into());
@@ -404,7 +423,7 @@ fn spawn_ssh_io(
404) -> vm::IoContext {
423) -> vm::IoContext {
405 let io_control = vm::IoControl::new();
424 let io_control = vm::IoControl::new();
407− let log_path = instance_dir.join(SERIAL_LOG_NAME);
426+ let log_path = instance_dir.join(VM_ROOT_LOG_NAME);
408 let log_file = fs::OpenOptions::new()
427 let log_file = fs::OpenOptions::new()
409 .create(true)
428 .create(true)
410 .write(true)
429 .write(true)
@@ -458,7 +477,7 @@ fn spawn_ssh_io(
458 if cfg.vm_ipv4.as_deref() != Some(ip.as_str()) {
477 if cfg.vm_ipv4.as_deref() != Some(ip.as_str()) {
459 cfg.vm_ipv4 = Some(ip.clone());
478 cfg.vm_ipv4 = Some(ip.clone());
460 let _ = write_instance_config(&instance_path, &cfg);
479 let _ = write_instance_config(&instance_path, &cfg);
461− eprintln!("[vibebox] detected vm IPv4: {ip}");
480+ tracing::info!(ip = %ip, "detected vm ipv4");
@@ -466,7 +485,7 @@ fn spawn_ssh_io(
467 if cleaned.contains("VIBEBOX_SSH_READY") {
486 if cleaned.contains("VIBEBOX_SSH_READY") {
468 ssh_ready_for_output.store(true, Ordering::SeqCst);
487 ssh_ready_for_output.store(true, Ordering::SeqCst);
469− eprintln!("[vibebox] sshd ready");
488+ tracing::info!("sshd ready");
@@ -517,7 +536,7 @@ fn spawn_ssh_io(
520− eprintln!("[vibebox] starting ssh to {ssh_user}@{ip}");
539+ tracing::info!(user = %ssh_user, ip = %ip, "starting ssh");
521 io_control_for_thread.request_terminal_restore();
540 io_control_for_thread.request_terminal_restore();
522 io_control_for_thread.set_forward_output(false);
541 io_control_for_thread.set_forward_output(false);
523 io_control_for_thread.set_forward_input(false);
542 io_control_for_thread.set_forward_input(false);
@@ -527,13 +546,19 @@ fn spawn_ssh_io(
528 attempts += 1;
547 attempts += 1;
529 if !ssh_port_open(&ip) {
548 if !ssh_port_open(&ip) {
530− eprintln!(
549+ tracing::info!(
552+ "waiting for ssh port ({}/{})",
531− "[vibebox] waiting for ssh port on {ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})"
554+ SSH_CONNECT_RETRIES
533 if attempts >= SSH_CONNECT_RETRIES {
556 if attempts >= SSH_CONNECT_RETRIES {
534 ssh_connected_for_thread.store(false, Ordering::SeqCst);
557 ssh_connected_for_thread.store(false, Ordering::SeqCst);
535− eprintln!(
558+ tracing::warn!(
536− "[vibebox] ssh port not ready after {SSH_CONNECT_RETRIES} attempts"
560+ "ssh port not ready after {} attempts",
@@ -541,8 +566,13 @@ fn spawn_ssh_io(
541 continue;
566 continue;
544− eprintln!(
569+ tracing::info!(
573+ "starting ssh ({}/{})",
545− "[vibebox] starting ssh to {ssh_user}@{ip} (attempt {attempts}/{SSH_CONNECT_RETRIES})"
575+ SSH_CONNECT_RETRIES
547 let status = Command::new("ssh")
577 let status = Command::new("ssh")
@@ -577,18 +607,20 @@ fn spawn_ssh_io(
577 match status {
607 match status {
578 Ok(status) if status.success() => {
608 Ok(status) if status.success() => {
579 ssh_connected_for_thread.store(false, Ordering::SeqCst);
609 ssh_connected_for_thread.store(false, Ordering::SeqCst);
580− eprintln!("[vibebox] ssh exited with status: {status}");
610+ tracing::info!(status = %status, "ssh exited");
581 if let Some(tx) = input_tx_holder_for_thread.lock().unwrap().clone() {
611 if let Some(tx) = input_tx_holder_for_thread.lock().unwrap().clone() {
582 let _ = tx.send(VmInput::Bytes(b"systemctl poweroff\n".to_vec()));
612 let _ = tx.send(VmInput::Bytes(b"systemctl poweroff\n".to_vec()));
586 Ok(status) if status.code() == Some(255) => {
616 Ok(status) if status.code() == Some(255) => {
587− eprintln!("[vibebox] ssh connection failed: {status}");
617+ tracing::warn!(status = %status, "ssh connection failed");
588 if attempts >= SSH_CONNECT_RETRIES {
618 if attempts >= SSH_CONNECT_RETRIES {
589 ssh_connected_for_thread.store(false, Ordering::SeqCst);
619 ssh_connected_for_thread.store(false, Ordering::SeqCst);
590− eprintln!(
620+ tracing::warn!(
591− "[vibebox] ssh failed after {SSH_CONNECT_RETRIES} attempts"
622+ "ssh failed after {} attempts",
@@ -597,7 +629,7 @@ fn spawn_ssh_io(
598 Ok(status) => {
630 Ok(status) => {
599 ssh_connected_for_thread.store(false, Ordering::SeqCst);
631 ssh_connected_for_thread.store(false, Ordering::SeqCst);
600− eprintln!("[vibebox] ssh exited with status: {status}");
632+ tracing::info!(status = %status, "ssh exited");
601 if let Some(tx) = input_tx_holder_for_thread.lock().unwrap().clone() {
633 if let Some(tx) = input_tx_holder_for_thread.lock().unwrap().clone() {
602 let _ = tx.send(VmInput::Bytes(b"systemctl poweroff\n".to_vec()));
634 let _ = tx.send(VmInput::Bytes(b"systemctl poweroff\n".to_vec()));
@@ -605,7 +637,7 @@ fn spawn_ssh_io(
606 Err(err) => {
638 Err(err) => {
607 ssh_connected_for_thread.store(false, Ordering::SeqCst);
639 ssh_connected_for_thread.store(false, Ordering::SeqCst);
608− eprintln!("[vibebox] failed to start ssh: {err}");
640+ tracing::error!(error = %err, "failed to start ssh");