From e061b11974cfadbbbe30a33f2590ec9130494733 Mon Sep 17 00:00:00 2001 From: DuProcess <273172371+DuProcess@users.noreply.github.com> Date: Sun, 12 Jul 2026 21:18:19 -0400 Subject: [PATCH] Keep reconnect health breadcrumbs --- Cargo.lock | 2 +- Cargo.toml | 2 +- src/bin/dosh-client.rs | 195 +++++++++++++++++++++++++++++++++-------- src/trace.rs | 74 ++++++++++++++-- 4 files changed, 230 insertions(+), 43 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 65ac534..2e10890 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -436,7 +436,7 @@ dependencies = [ [[package]] name = "dosh" -version = "1.0.0-rc39" +version = "1.0.0-rc40" dependencies = [ "anyhow", "base64", diff --git a/Cargo.toml b/Cargo.toml index 7983d3f..4df473f 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "dosh" -version = "1.0.0-rc39" +version = "1.0.0-rc40" edition = "2024" license = "MIT" diff --git a/src/bin/dosh-client.rs b/src/bin/dosh-client.rs index a8e9722..f46a1da 100644 --- a/src/bin/dosh-client.rs +++ b/src/bin/dosh-client.rs @@ -251,6 +251,12 @@ async fn main() -> Result<()> { "client.start", &[("version", dosh::build_info::VERSION.to_string())], ); + if should_health_log_client_start(args.server.as_deref()) { + dosh::trace::health_event( + "client.start", + &[("version", dosh::build_info::VERSION.to_string())], + ); + } let config = load_client_config(None).unwrap_or_default(); if args.server.as_deref() == Some("cp") { return run_cp_command(&config, &args); @@ -1041,6 +1047,33 @@ fn sanitize_trace_name(value: &str) -> String { } } +fn should_health_log_client_start(command: Option<&str>) -> bool { + !matches!( + command, + Some( + "cp" | "exec" + | "ls" + | "mkdir" + | "rm" + | "cat" + | "update" + | "trace" + | "setup" + | "selftest" + | "proxy-stdio" + | "vscode" + | "recover" + | "repair" + | "status" + | "sessions" + | "restart" + | "import-ssh" + | "trust" + | "doctor" + ) + ) +} + fn run_trace_command(args: &Args) -> Result<()> { if args.command.first().is_some_and(|value| value == "report") { let config = load_client_config(None).unwrap_or_default(); @@ -1201,40 +1234,66 @@ fn trace_cache_dir() -> PathBuf { fn newest_client_trace_path() -> Result> { let root = trace_cache_dir(); - let Ok(entries) = fs::read_dir(&root) else { - return Ok(None); - }; + newest_client_trace_path_from(&root, default_health_trace_path()) +} + +fn newest_client_trace_path_from( + root: &Path, + health_path: Option, +) -> Result> { let mut newest: Option<(SystemTime, PathBuf)> = None; - for entry in entries { - let entry = entry?; - let path = entry.path(); - if !path.is_file() { - continue; + if let Ok(entries) = fs::read_dir(root) { + for entry in entries { + let entry = entry?; + let path = entry.path(); + if !path.is_file() { + continue; + } + let Some(name) = path.file_name().and_then(|value| value.to_str()) else { + continue; + }; + if !(name.starts_with("client-") + || name.starts_with("dosh-client-") + || name.starts_with("dosh-")) + || !name.ends_with(".log") + { + continue; + } + let modified = entry + .metadata() + .and_then(|metadata| metadata.modified()) + .unwrap_or(SystemTime::UNIX_EPOCH); + keep_newer_trace_path(&mut newest, modified, path); } - let Some(name) = path.file_name().and_then(|value| value.to_str()) else { - continue; - }; - if !(name.starts_with("client-") - || name.starts_with("dosh-client-") - || name.starts_with("dosh-")) - || !name.ends_with(".log") - { - continue; - } - let modified = entry + } + if let Some(path) = health_path.filter(|path| path.is_file()) { + let modified = path .metadata() .and_then(|metadata| metadata.modified()) .unwrap_or(SystemTime::UNIX_EPOCH); - if newest - .as_ref() - .is_none_or(|(old_modified, _)| modified > *old_modified) - { - newest = Some((modified, path)); - } + keep_newer_trace_path(&mut newest, modified, path); } Ok(newest.map(|(_, path)| path)) } +fn keep_newer_trace_path( + newest: &mut Option<(SystemTime, PathBuf)>, + modified: SystemTime, + path: PathBuf, +) { + if newest + .as_ref() + .is_none_or(|(old_modified, _)| modified > *old_modified) + { + *newest = Some((modified, path)); + } +} + +fn default_health_trace_path() -> Option { + let path = dosh::trace::default_health_log_path(); + path.is_file().then_some(path) +} + fn summarize_trace_file(path: &Path, tail: usize) -> Result { summarize_trace_file_with_mode(path, tail, true) } @@ -7127,6 +7186,14 @@ async fn reconnect( ("last_rendered_seq", cred.last_rendered_seq.to_string()), ], ); + dosh::trace::health_event( + "client.reconnect_start", + &[ + ("session", cred.session.clone()), + ("mode", cred.mode.clone()), + ("last_rendered_seq", cred.last_rendered_seq.to_string()), + ], + ); match try_live_resume(socket, cred, send_seq, size.0, size.1).await { Ok((frame, next)) => { *cred = next; @@ -7147,6 +7214,13 @@ async fn reconnect( ("bytes", frame.bytes.len().to_string()), ], ); + dosh::trace::health_event( + "client.reconnect_live_ok", + &[ + ("output_seq", frame.output_seq.to_string()), + ("bytes", frame.bytes.len().to_string()), + ], + ); return Ok(Some(frame)); } Err(err) => { @@ -7154,6 +7228,10 @@ async fn reconnect( "client.reconnect_live_fail", &[("reason", format!("{err:#}"))], ); + dosh::trace::health_event( + "client.reconnect_live_fail", + &[("reason", format!("{err:#}"))], + ); } } @@ -7164,7 +7242,12 @@ async fn reconnect( "client.reconnect_ticket_fail", &[("reason", format!("{err:#}"))], ); + dosh::trace::health_event( + "client.reconnect_ticket_fail", + &[("reason", format!("{err:#}"))], + ); dosh::trace::event("client.reconnect_none", &[]); + dosh::trace::health_event("client.reconnect_none", &[]); return Ok(None); } }; @@ -7187,6 +7270,13 @@ async fn reconnect( ("bytes", frame.bytes.len().to_string()), ], ); + dosh::trace::health_event( + "client.reconnect_ticket_ok", + &[ + ("output_seq", frame.output_seq.to_string()), + ("bytes", frame.bytes.len().to_string()), + ], + ); Ok(Some(frame)) } @@ -9325,16 +9415,17 @@ mod tests { ensure_tui_safe_status_overlay, expand_ssh_path_tokens, input_contains_focus_in, input_matches_escape, is_local_status_target, is_resume_response_for_client, latest_release_download_url, load_first_native_identity_with_prompt, - native_proxy_udp_warning, parse_dynamic_forward, parse_escape_key, parse_local_forward, - parse_remote_forward, parse_ssh_config, parse_trace_line, parse_trace_options, - parse_trace_report_options, parse_trace_summary, parse_update_options, - post_submit_hold_duration, queue_pending_user_input, queue_stale_pending_user_input, - raw_contains_host_table, recv_response_until, refresh_live_addr, release_tag_download_url, - release_tag_from_effective_url, release_version_from_tag, render_status_clear, - render_status_overlay, requested_env, resolved_startup_command, retire_stream_state, - retransmit_stream_opens, rewrite_forward_command, sanitize_trace_name, - selected_predict_mode, selected_udp_host, server_version_mismatch, - should_flush_terminal_input_after_contact, should_hold_during_startup_gate, + native_proxy_udp_warning, newest_client_trace_path_from, parse_dynamic_forward, + parse_escape_key, parse_local_forward, parse_remote_forward, parse_ssh_config, + parse_trace_line, parse_trace_options, parse_trace_report_options, parse_trace_summary, + parse_update_options, post_submit_hold_duration, queue_pending_user_input, + queue_stale_pending_user_input, raw_contains_host_table, recv_response_until, + refresh_live_addr, release_tag_download_url, release_tag_from_effective_url, + release_version_from_tag, render_status_clear, render_status_overlay, requested_env, + resolved_startup_command, retire_stream_state, retransmit_stream_opens, + rewrite_forward_command, sanitize_trace_name, selected_predict_mode, selected_udp_host, + server_version_mismatch, should_flush_terminal_input_after_contact, + should_health_log_client_start, should_hold_during_startup_gate, should_hold_post_submit_input, should_reconnect_before_input_for_local_sleep, should_repaint_idle_terminal, should_strip_unowned_terminal_reports, split_after_command_submit, split_trace_tokens, ssh_command_target, ssh_config_uses_proxy, @@ -10893,6 +10984,40 @@ mod tests { })); } + #[test] + fn trace_report_falls_back_to_health_log_when_no_client_trace_exists() { + let dir = tempfile::tempdir().unwrap(); + let root = dir.path().join("trace"); + let health = root.join("health.log"); + fs::create_dir_all(&root).unwrap(); + fs::write( + &health, + concat!( + "ts_ms=10 pid=1 event=client.start version=1.0.0\n", + "ts_ms=11 pid=1 event=client.reconnect_none\n", + ), + ) + .unwrap(); + + let selected = newest_client_trace_path_from(&root, Some(health.clone())) + .unwrap() + .expect("health log fallback"); + assert_eq!(selected, health); + let report = summarize_trace_file(&selected, 10).unwrap(); + assert_eq!(report.reconnect_none_events, 1); + } + + #[test] + fn health_log_start_markers_only_for_connect_runs() { + assert!(should_health_log_client_start(None)); + assert!(should_health_log_client_start(Some("palav"))); + assert!(should_health_log_client_start(Some("forward"))); + assert!(!should_health_log_client_start(Some("trace"))); + assert!(!should_health_log_client_start(Some("update"))); + assert!(!should_health_log_client_start(Some("doctor"))); + assert!(!should_health_log_client_start(Some("status"))); + } + #[test] fn update_installer_uses_platform_native_script() { assert_eq!( diff --git a/src/trace.rs b/src/trace.rs index eaffc5d..feeed5f 100644 --- a/src/trace.rs +++ b/src/trace.rs @@ -1,11 +1,13 @@ use std::fs::{File, OpenOptions}; use std::io::Write; -use std::path::PathBuf; +use std::path::{Path, PathBuf}; use std::sync::{Mutex, OnceLock}; use std::time::{SystemTime, UNIX_EPOCH}; static TRACE_FILE: OnceLock>> = OnceLock::new(); +static HEALTH_FILE: OnceLock>> = OnceLock::new(); static TRACE_BYTES: OnceLock = OnceLock::new(); +const HEALTH_LOG_MAX_BYTES: u64 = 1024 * 1024; pub fn enabled() -> bool { TRACE_FILE.get_or_init(open_trace_file).is_some() @@ -19,6 +21,21 @@ pub fn event(name: &str, fields: &[(&str, String)]) { let Some(file) = TRACE_FILE.get_or_init(open_trace_file) else { return; }; + write_event(file, name, fields); +} + +pub fn health_event(name: &str, fields: &[(&str, String)]) { + let Some(file) = HEALTH_FILE.get_or_init(open_health_file) else { + return; + }; + write_event(file, name, fields); +} + +pub fn default_health_log_path() -> PathBuf { + trace_root().join("health.log") +} + +fn write_event(file: &Mutex, name: &str, fields: &[(&str, String)]) { let now = SystemTime::now() .duration_since(UNIX_EPOCH) .map(|duration| duration.as_millis()) @@ -81,11 +98,49 @@ fn open_trace_file() -> Option> { .map(Mutex::new) } +fn open_health_file() -> Option> { + let path = health_log_path_from_env()?; + rotate_health_log_if_needed(&path); + if let Some(parent) = path.parent() { + let _ = std::fs::create_dir_all(parent); + } + OpenOptions::new() + .create(true) + .append(true) + .open(&path) + .ok() + .map(Mutex::new) +} + +fn health_log_path_from_env() -> Option { + match std::env::var_os("DOSH_HEALTH_LOG") { + Some(raw) => { + let normalized = raw.to_string_lossy().to_ascii_lowercase(); + if normalized.is_empty() || matches!(normalized.as_str(), "0" | "false" | "off") { + None + } else if matches!(normalized.as_str(), "1" | "true" | "on") { + Some(default_health_log_path()) + } else { + Some(PathBuf::from(raw)) + } + } + None => Some(default_health_log_path()), + } +} + +fn rotate_health_log_if_needed(path: &Path) { + let Ok(metadata) = std::fs::metadata(path) else { + return; + }; + if metadata.len() <= HEALTH_LOG_MAX_BYTES { + return; + } + let rotated = path.with_extension("log.1"); + let _ = std::fs::remove_file(&rotated); + let _ = std::fs::rename(path, rotated); +} + fn default_trace_path() -> PathBuf { - let root = dirs::cache_dir() - .unwrap_or_else(std::env::temp_dir) - .join("dosh") - .join("trace"); let exe = std::env::current_exe() .ok() .and_then(|path| { @@ -93,7 +148,14 @@ fn default_trace_path() -> PathBuf { .map(|stem| stem.to_string_lossy().to_string()) }) .unwrap_or_else(|| "dosh".to_string()); - root.join(format!("{}-{}.log", exe, std::process::id())) + trace_root().join(format!("{}-{}.log", exe, std::process::id())) +} + +fn trace_root() -> PathBuf { + dirs::cache_dir() + .unwrap_or_else(std::env::temp_dir) + .join("dosh") + .join("trace") } fn truthy_env(name: &str) -> bool {