Keep reconnect health breadcrumbs
ci / test (push) Waiting to run
ci / fuzz-smoke (push) Waiting to run
ci / windows-client (push) Waiting to run
ci / package-release (linux-x86_64, ubuntu-latest) (push) Waiting to run
ci / package-release (macos-aarch64, macos-14) (push) Waiting to run
ci / package-release (macos-x86_64, macos-13) (push) Waiting to run
ci / package-release (windows-x86_64, windows-latest) (push) Waiting to run
ci / publish-gitea-release (push) Blocked by required conditions
ci / remote-bench (push) Waiting to run

This commit is contained in:
DuProcess
2026-07-12 21:18:19 -04:00
parent 0f2cb82be6
commit e061b11974
4 changed files with 230 additions and 43 deletions
Generated
+1 -1
View File
@@ -436,7 +436,7 @@ dependencies = [
[[package]] [[package]]
name = "dosh" name = "dosh"
version = "1.0.0-rc39" version = "1.0.0-rc40"
dependencies = [ dependencies = [
"anyhow", "anyhow",
"base64", "base64",
+1 -1
View File
@@ -1,6 +1,6 @@
[package] [package]
name = "dosh" name = "dosh"
version = "1.0.0-rc39" version = "1.0.0-rc40"
edition = "2024" edition = "2024"
license = "MIT" license = "MIT"
+141 -16
View File
@@ -251,6 +251,12 @@ async fn main() -> Result<()> {
"client.start", "client.start",
&[("version", dosh::build_info::VERSION.to_string())], &[("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(); let config = load_client_config(None).unwrap_or_default();
if args.server.as_deref() == Some("cp") { if args.server.as_deref() == Some("cp") {
return run_cp_command(&config, &args); 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<()> { fn run_trace_command(args: &Args) -> Result<()> {
if args.command.first().is_some_and(|value| value == "report") { if args.command.first().is_some_and(|value| value == "report") {
let config = load_client_config(None).unwrap_or_default(); let config = load_client_config(None).unwrap_or_default();
@@ -1201,10 +1234,15 @@ fn trace_cache_dir() -> PathBuf {
fn newest_client_trace_path() -> Result<Option<PathBuf>> { fn newest_client_trace_path() -> Result<Option<PathBuf>> {
let root = trace_cache_dir(); let root = trace_cache_dir();
let Ok(entries) = fs::read_dir(&root) else { newest_client_trace_path_from(&root, default_health_trace_path())
return Ok(None); }
};
fn newest_client_trace_path_from(
root: &Path,
health_path: Option<PathBuf>,
) -> Result<Option<PathBuf>> {
let mut newest: Option<(SystemTime, PathBuf)> = None; let mut newest: Option<(SystemTime, PathBuf)> = None;
if let Ok(entries) = fs::read_dir(root) {
for entry in entries { for entry in entries {
let entry = entry?; let entry = entry?;
let path = entry.path(); let path = entry.path();
@@ -1225,14 +1263,35 @@ fn newest_client_trace_path() -> Result<Option<PathBuf>> {
.metadata() .metadata()
.and_then(|metadata| metadata.modified()) .and_then(|metadata| metadata.modified())
.unwrap_or(SystemTime::UNIX_EPOCH); .unwrap_or(SystemTime::UNIX_EPOCH);
keep_newer_trace_path(&mut newest, modified, path);
}
}
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);
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 if newest
.as_ref() .as_ref()
.is_none_or(|(old_modified, _)| modified > *old_modified) .is_none_or(|(old_modified, _)| modified > *old_modified)
{ {
newest = Some((modified, path)); *newest = Some((modified, path));
} }
} }
Ok(newest.map(|(_, path)| path))
fn default_health_trace_path() -> Option<PathBuf> {
let path = dosh::trace::default_health_log_path();
path.is_file().then_some(path)
} }
fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> { fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
@@ -7127,6 +7186,14 @@ async fn reconnect(
("last_rendered_seq", cred.last_rendered_seq.to_string()), ("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 { match try_live_resume(socket, cred, send_seq, size.0, size.1).await {
Ok((frame, next)) => { Ok((frame, next)) => {
*cred = next; *cred = next;
@@ -7147,6 +7214,13 @@ async fn reconnect(
("bytes", frame.bytes.len().to_string()), ("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)); return Ok(Some(frame));
} }
Err(err) => { Err(err) => {
@@ -7154,6 +7228,10 @@ async fn reconnect(
"client.reconnect_live_fail", "client.reconnect_live_fail",
&[("reason", format!("{err:#}"))], &[("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", "client.reconnect_ticket_fail",
&[("reason", format!("{err:#}"))], &[("reason", format!("{err:#}"))],
); );
dosh::trace::health_event(
"client.reconnect_ticket_fail",
&[("reason", format!("{err:#}"))],
);
dosh::trace::event("client.reconnect_none", &[]); dosh::trace::event("client.reconnect_none", &[]);
dosh::trace::health_event("client.reconnect_none", &[]);
return Ok(None); return Ok(None);
} }
}; };
@@ -7187,6 +7270,13 @@ async fn reconnect(
("bytes", frame.bytes.len().to_string()), ("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)) Ok(Some(frame))
} }
@@ -9325,16 +9415,17 @@ mod tests {
ensure_tui_safe_status_overlay, expand_ssh_path_tokens, input_contains_focus_in, 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, input_matches_escape, is_local_status_target, is_resume_response_for_client,
latest_release_download_url, load_first_native_identity_with_prompt, latest_release_download_url, load_first_native_identity_with_prompt,
native_proxy_udp_warning, parse_dynamic_forward, parse_escape_key, parse_local_forward, native_proxy_udp_warning, newest_client_trace_path_from, parse_dynamic_forward,
parse_remote_forward, parse_ssh_config, parse_trace_line, parse_trace_options, parse_escape_key, parse_local_forward, parse_remote_forward, parse_ssh_config,
parse_trace_report_options, parse_trace_summary, parse_update_options, parse_trace_line, parse_trace_options, parse_trace_report_options, parse_trace_summary,
post_submit_hold_duration, queue_pending_user_input, queue_stale_pending_user_input, parse_update_options, post_submit_hold_duration, queue_pending_user_input,
raw_contains_host_table, recv_response_until, refresh_live_addr, release_tag_download_url, queue_stale_pending_user_input, raw_contains_host_table, recv_response_until,
release_tag_from_effective_url, release_version_from_tag, render_status_clear, refresh_live_addr, release_tag_download_url, release_tag_from_effective_url,
render_status_overlay, requested_env, resolved_startup_command, retire_stream_state, release_version_from_tag, render_status_clear, render_status_overlay, requested_env,
retransmit_stream_opens, rewrite_forward_command, sanitize_trace_name, resolved_startup_command, retire_stream_state, retransmit_stream_opens,
selected_predict_mode, selected_udp_host, server_version_mismatch, rewrite_forward_command, sanitize_trace_name, selected_predict_mode, selected_udp_host,
should_flush_terminal_input_after_contact, should_hold_during_startup_gate, 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_hold_post_submit_input, should_reconnect_before_input_for_local_sleep,
should_repaint_idle_terminal, should_strip_unowned_terminal_reports, should_repaint_idle_terminal, should_strip_unowned_terminal_reports,
split_after_command_submit, split_trace_tokens, ssh_command_target, ssh_config_uses_proxy, 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] #[test]
fn update_installer_uses_platform_native_script() { fn update_installer_uses_platform_native_script() {
assert_eq!( assert_eq!(
+68 -6
View File
@@ -1,11 +1,13 @@
use std::fs::{File, OpenOptions}; use std::fs::{File, OpenOptions};
use std::io::Write; use std::io::Write;
use std::path::PathBuf; use std::path::{Path, PathBuf};
use std::sync::{Mutex, OnceLock}; use std::sync::{Mutex, OnceLock};
use std::time::{SystemTime, UNIX_EPOCH}; use std::time::{SystemTime, UNIX_EPOCH};
static TRACE_FILE: OnceLock<Option<Mutex<File>>> = OnceLock::new(); static TRACE_FILE: OnceLock<Option<Mutex<File>>> = OnceLock::new();
static HEALTH_FILE: OnceLock<Option<Mutex<File>>> = OnceLock::new();
static TRACE_BYTES: OnceLock<bool> = OnceLock::new(); static TRACE_BYTES: OnceLock<bool> = OnceLock::new();
const HEALTH_LOG_MAX_BYTES: u64 = 1024 * 1024;
pub fn enabled() -> bool { pub fn enabled() -> bool {
TRACE_FILE.get_or_init(open_trace_file).is_some() 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 { let Some(file) = TRACE_FILE.get_or_init(open_trace_file) else {
return; 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<File>, name: &str, fields: &[(&str, String)]) {
let now = SystemTime::now() let now = SystemTime::now()
.duration_since(UNIX_EPOCH) .duration_since(UNIX_EPOCH)
.map(|duration| duration.as_millis()) .map(|duration| duration.as_millis())
@@ -81,11 +98,49 @@ fn open_trace_file() -> Option<Mutex<File>> {
.map(Mutex::new) .map(Mutex::new)
} }
fn open_health_file() -> Option<Mutex<File>> {
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<PathBuf> {
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 { 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() let exe = std::env::current_exe()
.ok() .ok()
.and_then(|path| { .and_then(|path| {
@@ -93,7 +148,14 @@ fn default_trace_path() -> PathBuf {
.map(|stem| stem.to_string_lossy().to_string()) .map(|stem| stem.to_string_lossy().to_string())
}) })
.unwrap_or_else(|| "dosh".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 { fn truthy_env(name: &str) -> bool {