Compare commits

...
Author SHA1 Message Date
DuProcess 37632a96b7 Filter trace reports to latest run
ci / test (push) Has been cancelled
ci / fuzz-smoke (push) Has been cancelled
ci / windows-client (push) Has been cancelled
ci / package-release (linux-x86_64, ubuntu-latest) (push) Has been cancelled
ci / package-release (macos-aarch64, macos-14) (push) Has been cancelled
ci / package-release (macos-x86_64, macos-13) (push) Has been cancelled
ci / package-release (windows-x86_64, windows-latest) (push) Has been cancelled
ci / remote-bench (push) Has been cancelled
2026-07-12 12:09:37 -04:00
DuProcess e69be4fdf0 Reconnect before input after local sleep
ci / test (push) Has been cancelled
ci / fuzz-smoke (push) Has been cancelled
ci / windows-client (push) Has been cancelled
ci / package-release (linux-x86_64, ubuntu-latest) (push) Has been cancelled
ci / package-release (macos-aarch64, macos-14) (push) Has been cancelled
ci / package-release (macos-x86_64, macos-13) (push) Has been cancelled
ci / package-release (windows-x86_64, windows-latest) (push) Has been cancelled
ci / remote-bench (push) Has been cancelled
2026-07-12 12:01:46 -04:00
DuProcess fdbd58b628 Fetch remote server trace reports
ci / test (push) Has been cancelled
ci / fuzz-smoke (push) Has been cancelled
ci / windows-client (push) Has been cancelled
ci / package-release (linux-x86_64, ubuntu-latest) (push) Has been cancelled
ci / package-release (macos-aarch64, macos-14) (push) Has been cancelled
ci / package-release (macos-x86_64, macos-13) (push) Has been cancelled
ci / package-release (windows-x86_64, windows-latest) (push) Has been cancelled
ci / remote-bench (push) Has been cancelled
2026-07-12 11:55:23 -04:00
5 changed files with 375 additions and 58 deletions
Generated
+1 -1
View File
@@ -436,7 +436,7 @@ dependencies = [
[[package]] [[package]]
name = "dosh" name = "dosh"
version = "1.0.0-rc33" version = "1.0.0-rc36"
dependencies = [ dependencies = [
"anyhow", "anyhow",
"base64", "base64",
+1 -1
View File
@@ -1,6 +1,6 @@
[package] [package]
name = "dosh" name = "dosh"
version = "1.0.0-rc33" version = "1.0.0-rc36"
edition = "2024" edition = "2024"
license = "MIT" license = "MIT"
+6 -4
View File
@@ -85,12 +85,14 @@ dosh trace --client-log /tmp/dosh-client.log HOST
Summarize collected traces with: Summarize collected traces with:
```sh ```sh
dosh trace report --client-log /tmp/dosh-client.log dosh trace report HOST --client-log /tmp/dosh-client.log
``` ```
Set `DOSH_TRACE=/tmp/dosh-server.log` on `dosh-server` for matching server When `HOST` is given, Dosh fetches `/tmp/dosh-server.log` over SSH before
events. Trace byte prefixes are enabled for `dosh trace`, so use it only for building the report. Set `DOSH_TRACE=/tmp/dosh-server.log` on `dosh-server` for
short reproductions. matching server events. Reports default to the latest traced client/server
process run; add `--all-runs` to include older appended log entries. Trace byte
prefixes are enabled for `dosh trace`, so use it only for short reproductions.
## VS Code ## VS Code
+360 -52
View File
@@ -71,7 +71,7 @@ const MAX_PENDING_USER_INPUT_BYTES: usize = 1024 * 1024;
const STARTUP_INPUT_HOLD: Duration = Duration::from_millis(750); const STARTUP_INPUT_HOLD: Duration = Duration::from_millis(750);
const POST_SUBMIT_ALL_INPUT_HOLD: Duration = Duration::from_millis(120); const POST_SUBMIT_ALL_INPUT_HOLD: Duration = Duration::from_millis(120);
const STALE_TERMINAL_INPUT_AFTER: Duration = Duration::from_secs(2); const STALE_TERMINAL_INPUT_AFTER: Duration = Duration::from_secs(2);
const POST_RECONNECT_STALE_INPUT_GRACE: Duration = Duration::from_secs(2); const POST_RECONNECT_STALE_INPUT_GRACE: Duration = Duration::from_secs(5);
const FOCUS_REPAINT_COOLDOWN: Duration = Duration::from_secs(1); const FOCUS_REPAINT_COOLDOWN: Duration = Duration::from_secs(1);
const ALT_SCREEN_IDLE_REPAINT_AFTER: Duration = Duration::from_secs(15); const ALT_SCREEN_IDLE_REPAINT_AFTER: Duration = Duration::from_secs(15);
const LOCAL_SLEEP_REPAINT_AFTER: Duration = Duration::from_secs(5); const LOCAL_SLEEP_REPAINT_AFTER: Duration = Duration::from_secs(5);
@@ -246,6 +246,10 @@ enum StartupGateMode {
#[tokio::main(flavor = "current_thread")] #[tokio::main(flavor = "current_thread")]
async fn main() -> Result<()> { async fn main() -> Result<()> {
let mut args = Args::parse(); let mut args = Args::parse();
dosh::trace::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);
@@ -792,9 +796,11 @@ struct TraceOptions {
#[derive(Debug, Clone, PartialEq, Eq)] #[derive(Debug, Clone, PartialEq, Eq)]
struct TraceReportOptions { struct TraceReportOptions {
host: Option<String>,
client_log: Option<PathBuf>, client_log: Option<PathBuf>,
server_log: Option<PathBuf>, server_log: Option<String>,
tail: usize, tail: usize,
latest_run: bool,
} }
#[derive(Debug, Default, Clone, PartialEq, Eq)] #[derive(Debug, Default, Clone, PartialEq, Eq)]
@@ -802,6 +808,8 @@ struct TraceReport {
path: PathBuf, path: PathBuf,
total_lines: usize, total_lines: usize,
parsed_lines: usize, parsed_lines: usize,
skipped_old_run_lines: usize,
latest_run_filtered: bool,
first_ts_ms: Option<u128>, first_ts_ms: Option<u128>,
last_ts_ms: Option<u128>, last_ts_ms: Option<u128>,
events: BTreeMap<String, usize>, events: BTreeMap<String, usize>,
@@ -819,6 +827,7 @@ struct TraceReport {
sent_input_events: usize, sent_input_events: usize,
pty_write_events: usize, pty_write_events: usize,
reconnect_events: usize, reconnect_events: usize,
unknown_resume_events: usize,
roam_events: usize, roam_events: usize,
recent_events: VecDeque<String>, recent_events: VecDeque<String>,
} }
@@ -888,15 +897,17 @@ fn parse_trace_options(command: &[String]) -> Result<TraceOptions> {
} }
fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions> { fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions> {
let mut host: Option<String> = None;
let mut client_log: Option<PathBuf> = None; let mut client_log: Option<PathBuf> = None;
let mut server_log: Option<PathBuf> = Some(PathBuf::from("/tmp/dosh-server.log")); let mut server_log: Option<String> = Some("/tmp/dosh-server.log".to_string());
let mut tail = 20usize; let mut tail = 20usize;
let mut latest_run = true;
let mut index = 0usize; let mut index = 0usize;
while index < command.len() { while index < command.len() {
match command[index].as_str() { match command[index].as_str() {
"--client-log" => { "--client-log" => {
let path = command.get(index + 1).ok_or_else(|| { let path = command.get(index + 1).ok_or_else(|| {
anyhow!("usage: dosh trace report [--client-log PATH] [--server-log PATH|none] [--tail N]") anyhow!("usage: dosh trace report [HOST] [--client-log PATH] [--server-log PATH|none] [--latest-run|--all-runs] [--tail N]")
})?; })?;
client_log = Some(expand_tilde(path)); client_log = Some(expand_tilde(path));
index += 2; index += 2;
@@ -911,7 +922,7 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
} }
"--server-log" => { "--server-log" => {
let path = command.get(index + 1).ok_or_else(|| { let path = command.get(index + 1).ok_or_else(|| {
anyhow!("usage: dosh trace report [--client-log PATH] [--server-log PATH|none] [--tail N]") anyhow!("usage: dosh trace report [HOST] [--client-log PATH] [--server-log PATH|none] [--latest-run|--all-runs] [--tail N]")
})?; })?;
server_log = parse_optional_trace_path(path); server_log = parse_optional_trace_path(path);
index += 2; index += 2;
@@ -927,9 +938,17 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
server_log = None; server_log = None;
index += 1; index += 1;
} }
"--latest-run" => {
latest_run = true;
index += 1;
}
"--all-runs" => {
latest_run = false;
index += 1;
}
"--tail" => { "--tail" => {
let value = command.get(index + 1).ok_or_else(|| { let value = command.get(index + 1).ok_or_else(|| {
anyhow!("usage: dosh trace report [--client-log PATH] [--server-log PATH|none] [--tail N]") anyhow!("usage: dosh trace report [HOST] [--client-log PATH] [--server-log PATH|none] [--latest-run|--all-runs] [--tail N]")
})?; })?;
tail = parse_trace_tail(value)?; tail = parse_trace_tail(value)?;
index += 2; index += 2;
@@ -941,25 +960,36 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
tail = parse_trace_tail(value)?; tail = parse_trace_tail(value)?;
index += 1; index += 1;
} }
value => { value if value.starts_with('-') => {
return Err(anyhow!( return Err(anyhow!(
"usage: dosh trace report [--client-log PATH] [--server-log PATH|none] [--tail N] (unknown option {value})" "usage: dosh trace report [HOST] [--client-log PATH] [--server-log PATH|none] [--latest-run|--all-runs] [--tail N] (unknown option {value})"
)); ));
} }
value => {
if host.is_some() {
return Err(anyhow!(
"usage: dosh trace report [HOST] [--client-log PATH] [--server-log PATH|none] [--latest-run|--all-runs] [--tail N]"
));
}
host = Some(value.to_string());
index += 1;
}
} }
} }
Ok(TraceReportOptions { Ok(TraceReportOptions {
host,
client_log, client_log,
server_log, server_log,
tail, tail,
latest_run,
}) })
} }
fn parse_optional_trace_path(value: &str) -> Option<PathBuf> { fn parse_optional_trace_path(value: &str) -> Option<String> {
if matches!(value, "" | "none" | "off" | "0") { if matches!(value, "" | "none" | "off" | "0") {
None None
} else { } else {
Some(expand_tilde(value)) Some(value.to_string())
} }
} }
@@ -1006,7 +1036,8 @@ fn sanitize_trace_name(value: &str) -> String {
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") {
return run_trace_report_command(&args.command[1..]); let config = load_client_config(None).unwrap_or_default();
return run_trace_report_command(&config, args, &args.command[1..]);
} }
let options = parse_trace_options(&args.command)?; let options = parse_trace_options(&args.command)?;
if let Some(parent) = options.client_log.parent() { if let Some(parent) = options.client_log.parent() {
@@ -1042,7 +1073,11 @@ fn run_trace_command(args: &Args) -> Result<()> {
Ok(()) Ok(())
} }
fn run_trace_report_command(command: &[String]) -> Result<()> { fn run_trace_report_command(
config: &dosh::config::ClientConfig,
args: &Args,
command: &[String],
) -> Result<()> {
let options = parse_trace_report_options(command)?; let options = parse_trace_report_options(command)?;
let client_log = match options.client_log { let client_log = match options.client_log {
Some(path) => Some(path), Some(path) => Some(path),
@@ -1050,7 +1085,7 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
}; };
println!("Dosh trace report"); println!("Dosh trace report");
if let Some(path) = client_log { if let Some(path) = client_log {
match summarize_trace_file(&path, options.tail) { match summarize_trace_file_for_report(&path, options.tail, options.latest_run) {
Ok(report) => print_trace_report("client", &report), Ok(report) => print_trace_report("client", &report),
Err(err) => println!("[warn] client log {}: {err:#}", path.display()), Err(err) => println!("[warn] client log {}: {err:#}", path.display()),
} }
@@ -1061,7 +1096,21 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
); );
} }
if let Some(path) = options.server_log { if let Some(path) = options.server_log {
match summarize_trace_file(&path, options.tail) { let server_log = if let Some(host) = options.host.as_deref() {
match fetch_trace_server_log(config, args, host, &path) {
Ok(path) => Some(path),
Err(err) => {
println!("[warn] server log {host}:{path}: {err:#}");
None
}
}
} else {
Some(expand_tilde(&path))
};
let Some(path) = server_log else {
return Ok(());
};
match summarize_trace_file_for_report(&path, options.tail, options.latest_run) {
Ok(report) => print_trace_report("server", &report), Ok(report) => print_trace_report("server", &report),
Err(err) Err(err)
if err if err
@@ -1076,6 +1125,66 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
Ok(()) Ok(())
} }
fn fetch_trace_server_log(
config: &dosh::config::ClientConfig,
args: &Args,
requested: &str,
remote_log: &str,
) -> Result<PathBuf> {
let hosts = load_hosts_config(None).unwrap_or_default();
let host_config = hosts.hosts.get(requested).cloned().unwrap_or_default();
let server = status_ssh_target(requested, &host_config);
let ssh_port = args.ssh_port.or(host_config.ssh_port).or(config.ssh_port);
if is_local_status_target(&server) {
return Ok(expand_tilde(remote_log));
}
let local_path = fetched_trace_server_log_path(requested);
if let Some(parent) = local_path.parent() {
fs::create_dir_all(parent)
.with_context(|| format!("create trace log directory {}", parent.to_string_lossy()))?;
}
let mut command = Command::new("ssh");
if let Some(ssh_port) = ssh_port {
command.arg("-p").arg(ssh_port.to_string());
}
command.arg("-T");
if let Some(key) = args.ssh_key.as_deref() {
command.arg("-i").arg(key);
}
if let Some(known_hosts) = args.ssh_known_hosts.as_deref() {
command
.arg("-o")
.arg(format!("UserKnownHostsFile={}", known_hosts.display()));
}
let script = format!("test -r {0} && cat {0}", shell_word(remote_log));
let output = command
.arg(&server)
.arg(format!("sh -c {}", shell_word(&script)))
.output()
.with_context(|| format!("fetch server trace log from {server}"))?;
anyhow::ensure!(
output.status.success(),
"{}",
String::from_utf8_lossy(&output.stderr)
);
fs::write(&local_path, &output.stdout)
.with_context(|| format!("write fetched server trace {}", local_path.display()))?;
Ok(local_path)
}
fn fetched_trace_server_log_path(host: &str) -> PathBuf {
let now = SystemTime::now()
.duration_since(UNIX_EPOCH)
.map(|duration| duration.as_secs())
.unwrap_or(0);
trace_cache_dir().join(format!(
"server-{}-{}-{}.log",
sanitize_trace_name(host),
now,
std::process::id()
))
}
fn trace_cache_dir() -> PathBuf { fn trace_cache_dir() -> PathBuf {
dirs::cache_dir() dirs::cache_dir()
.unwrap_or_else(|| expand_tilde("~/.cache")) .unwrap_or_else(|| expand_tilde("~/.cache"))
@@ -1120,17 +1229,56 @@ fn newest_client_trace_path() -> Result<Option<PathBuf>> {
} }
fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> { fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
summarize_trace_file_with_mode(path, tail, true)
}
fn summarize_trace_file_for_report(
path: &Path,
tail: usize,
latest_run: bool,
) -> Result<TraceReport> {
if latest_run {
summarize_trace_file(path, tail)
} else {
summarize_trace_file_with_mode(path, tail, false)
}
}
fn summarize_trace_file_with_mode(
path: &Path,
tail: usize,
latest_run: bool,
) -> Result<TraceReport> {
let file = File::open(path).with_context(|| format!("open trace log {}", path.display()))?; let file = File::open(path).with_context(|| format!("open trace log {}", path.display()))?;
let mut report = TraceReport { let mut parsed = Vec::new();
path: path.to_path_buf(), let mut file_lines = 0usize;
..TraceReport::default()
};
for line in BufReader::new(file).lines() { for line in BufReader::new(file).lines() {
let line = line?; let line = line?;
report.total_lines += 1; file_lines += 1;
let Some(fields) = parse_trace_line(&line) else { if let Some(fields) = parse_trace_line(&line) {
continue; parsed.push(fields);
}; }
}
let latest_run_start = if latest_run {
parsed.iter().rposition(|fields| {
fields
.get("event")
.is_some_and(|event| trace_run_marker(event))
})
} else {
None
};
let parsed_len = parsed.len();
let skipped_old_run_lines = latest_run_start.unwrap_or(0);
let latest_run_filtered = latest_run_start.is_some_and(|index| index > 0);
let mut report = TraceReport {
path: path.to_path_buf(),
total_lines: file_lines.saturating_sub(skipped_old_run_lines),
skipped_old_run_lines,
latest_run_filtered,
..TraceReport::default()
};
for fields in parsed.into_iter().skip(skipped_old_run_lines) {
report.parsed_lines += 1; report.parsed_lines += 1;
if let Some(ts) = fields if let Some(ts) = fields
.get("ts_ms") .get("ts_ms")
@@ -1193,6 +1341,9 @@ fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
if event.contains("reconnect") || event.contains("resume") { if event.contains("reconnect") || event.contains("resume") {
report.reconnect_events += 1; report.reconnect_events += 1;
} }
if event == "server.resume_unknown_client" {
report.unknown_resume_events += 1;
}
if event.contains("roam") { if event.contains("roam") {
report.roam_events += 1; report.roam_events += 1;
} }
@@ -1204,12 +1355,21 @@ fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
report.recent_events.push_back(rendered); report.recent_events.push_back(rendered);
} }
} }
if report.total_lines == 0 && parsed_len > 0 {
report.total_lines = parsed_len;
}
Ok(report) Ok(report)
} }
fn print_trace_report(label: &str, report: &TraceReport) { fn print_trace_report(label: &str, report: &TraceReport) {
println!(); println!();
println!("{label}: {}", report.path.display()); println!("{label}: {}", report.path.display());
if report.latest_run_filtered {
println!(
" latest_run=true skipped_old_lines={}",
report.skipped_old_run_lines
);
}
println!( println!(
" lines={} parsed={} span_ms={}", " lines={} parsed={} span_ms={}",
report.total_lines, report.total_lines,
@@ -1240,8 +1400,8 @@ fn print_trace_report(label: &str, report: &TraceReport) {
report.hex_events report.hex_events
); );
println!( println!(
" reconnect: events={} roam={}", " reconnect: events={} unknown_resume={} roam={}",
report.reconnect_events, report.roam_events report.reconnect_events, report.unknown_resume_events, report.roam_events
); );
for warning in trace_report_warnings(report) { for warning in trace_report_warnings(report) {
println!(" alert: {warning}"); println!(" alert: {warning}");
@@ -1262,6 +1422,12 @@ fn print_trace_report(label: &str, report: &TraceReport) {
fn trace_report_warnings(report: &TraceReport) -> Vec<String> { fn trace_report_warnings(report: &TraceReport) -> Vec<String> {
let mut warnings = Vec::new(); let mut warnings = Vec::new();
if report.unknown_resume_events > 0 {
warnings.push(format!(
"{} unknown live resume event(s); ticket reattach should follow after server restart",
report.unknown_resume_events
));
}
if report.server_mouseish_pty_write_events > 0 { if report.server_mouseish_pty_write_events > 0 {
warnings.push(format!( warnings.push(format!(
"{} mouse-like input event(s) reached the server PTY", "{} mouse-like input event(s) reached the server PTY",
@@ -1292,6 +1458,10 @@ fn trace_report_warnings(report: &TraceReport) -> Vec<String> {
warnings warnings
} }
fn trace_run_marker(event: &str) -> bool {
matches!(event, "client.start" | "server.start")
}
fn top_trace_events(events: &BTreeMap<String, usize>, limit: usize) -> Vec<(String, usize)> { fn top_trace_events(events: &BTreeMap<String, usize>, limit: usize) -> Vec<(String, usize)> {
let mut entries: Vec<_> = events let mut entries: Vec<_> = events
.iter() .iter()
@@ -5575,8 +5745,62 @@ async fn run_terminal(
dosh::trace::event("client.escape", &[]); dosh::trace::event("client.escape", &[]);
break; break;
} }
let input_status_tick_gap = last_status_tick_at.elapsed();
let mut refreshed_before_input = false;
if should_reconnect_before_input_for_local_sleep(
forward_only,
input_status_tick_gap,
) {
dosh::trace::event(
"client.local_sleep_input_reconnect_start",
&[(
"tick_gap_ms",
input_status_tick_gap.as_millis().to_string(),
)],
);
last_status_tick_at = Instant::now();
arm_stale_terminal_input_suppression(
&mut stale_terminal_input_suppress_until,
);
if let Some(frame) = reconnect(
&socket,
&mut cred,
&mut send_seq,
last_size,
&mut frame_buffer,
&mut predictor,
)
.await?
{
dosh::trace::event(
"client.local_sleep_input_reconnect_ok",
&[
("output_seq", frame.output_seq.to_string()),
("bytes", frame.bytes.len().to_string()),
],
);
refresh_live_addr(&mut addr, &cred)?;
render_frame(&frame)?;
predictor.observe_output(&frame.bytes);
last_terminal_frame_at = Instant::now();
last_packet_at = Instant::now();
last_focus_repaint_at = Instant::now();
refreshed_before_input = true;
flush_pending_user_input(
&socket,
addr,
&cred,
&mut send_seq,
&mut predictor,
&mut pending_user_input,
&mut pending_user_input_bytes,
)
.await?;
}
}
let saw_focus_in = input_contains_focus_in(&bytes); let saw_focus_in = input_contains_focus_in(&bytes);
if !forward_only if !forward_only
&& !refreshed_before_input
&& saw_focus_in && saw_focus_in
&& last_focus_repaint_at.elapsed() >= FOCUS_REPAINT_COOLDOWN && last_focus_repaint_at.elapsed() >= FOCUS_REPAINT_COOLDOWN
{ {
@@ -6996,6 +7220,13 @@ fn should_strip_stale_terminal_reports(
|| suppress_until.is_some_and(|deadline| Instant::now() < deadline) || suppress_until.is_some_and(|deadline| Instant::now() < deadline)
} }
fn should_reconnect_before_input_for_local_sleep(
forward_only: bool,
status_tick_gap: Duration,
) -> bool {
!forward_only && status_tick_gap >= LOCAL_SLEEP_REPAINT_AFTER
}
fn should_strip_unowned_terminal_reports(alternate_screen: bool, mouse_tracking: bool) -> bool { fn should_strip_unowned_terminal_reports(alternate_screen: bool, mouse_tracking: bool) -> bool {
!alternate_screen && !mouse_tracking !alternate_screen && !mouse_tracking
} }
@@ -7053,6 +7284,13 @@ fn should_repaint_idle_terminal(
fn arm_stale_terminal_input_suppression(suppress_until: &mut Option<Instant>) { fn arm_stale_terminal_input_suppression(suppress_until: &mut Option<Instant>) {
*suppress_until = Some(Instant::now() + POST_RECONNECT_STALE_INPUT_GRACE); *suppress_until = Some(Instant::now() + POST_RECONNECT_STALE_INPUT_GRACE);
dosh::trace::event(
"client.stale_terminal_quarantine_arm",
&[(
"grace_ms",
POST_RECONNECT_STALE_INPUT_GRACE.as_millis().to_string(),
)],
);
} }
async fn flush_pending_user_input( async fn flush_pending_user_input(
@@ -8992,32 +9230,33 @@ mod tests {
use super::{ use super::{
ALT_SCREEN_IDLE_REPAINT_AFTER, CachedCredential, DisconnectStatus, DynamicForward, ALT_SCREEN_IDLE_REPAINT_AFTER, CachedCredential, DisconnectStatus, DynamicForward,
FRAME_GAP_RESYNC_AFTER_MS, FrameBuffer, LOCAL_SLEEP_REPAINT_AFTER, LocalForward, FRAME_GAP_RESYNC_AFTER_MS, FrameBuffer, LOCAL_SLEEP_REPAINT_AFTER, LocalForward,
MAX_PENDING_USER_INPUT_BYTES, NativeIdentityContext, POST_SUBMIT_ALL_INPUT_HOLD, MAX_PENDING_USER_INPUT_BYTES, NativeIdentityContext, POST_RECONNECT_STALE_INPUT_GRACE,
PendingStreamOpen, PredictMode, Predictor, RESTART_STATUS_SCRIPT, RemoteForward, POST_SUBMIT_ALL_INPUT_HOLD, PendingStreamOpen, PredictMode, Predictor,
STARTUP_INPUT_HOLD, SshConfig, SshPathTokenContext, StartupGateMode, StatusAction, RESTART_STATUS_SCRIPT, RemoteForward, STARTUP_INPUT_HOLD, SshConfig, SshPathTokenContext,
UpdateOptions, UpdateRole, auth_allows, cache_key, cache_server_prefix, StartupGateMode, StatusAction, UpdateOptions, UpdateRole, auth_allows, cache_key,
cleanup_stream_state, clear_cached_credentials, ensure_tui_safe_status_overlay, cache_server_prefix, cleanup_stream_state, clear_cached_credentials,
expand_ssh_path_tokens, input_contains_focus_in, input_matches_escape, ensure_tui_safe_status_overlay, expand_ssh_path_tokens, input_contains_focus_in,
is_local_status_target, is_resume_response_for_client, latest_release_download_url, input_matches_escape, is_local_status_target, is_resume_response_for_client,
load_first_native_identity_with_prompt, native_proxy_udp_warning, parse_dynamic_forward, latest_release_download_url, load_first_native_identity_with_prompt,
parse_escape_key, parse_local_forward, parse_remote_forward, parse_ssh_config, native_proxy_udp_warning, parse_dynamic_forward, parse_escape_key, parse_local_forward,
parse_trace_line, parse_trace_options, parse_trace_report_options, parse_trace_summary, parse_remote_forward, parse_ssh_config, parse_trace_line, parse_trace_options,
parse_update_options, post_submit_hold_duration, queue_pending_user_input, parse_trace_report_options, parse_trace_summary, parse_update_options,
queue_stale_pending_user_input, raw_contains_host_table, recv_response_until, post_submit_hold_duration, queue_pending_user_input, queue_stale_pending_user_input,
refresh_live_addr, release_tag_download_url, release_tag_from_effective_url, raw_contains_host_table, recv_response_until, refresh_live_addr, release_tag_download_url,
release_version_from_tag, render_status_clear, render_status_overlay, requested_env, release_tag_from_effective_url, release_version_from_tag, render_status_clear,
resolved_startup_command, retire_stream_state, retransmit_stream_opens, render_status_overlay, requested_env, resolved_startup_command, retire_stream_state,
rewrite_forward_command, sanitize_trace_name, selected_predict_mode, selected_udp_host, retransmit_stream_opens, rewrite_forward_command, sanitize_trace_name,
server_version_mismatch, should_flush_terminal_input_after_contact, selected_predict_mode, selected_udp_host, server_version_mismatch,
should_hold_during_startup_gate, should_hold_post_submit_input, should_flush_terminal_input_after_contact, 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, 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,
ssh_destination_host, ssh_username, ssh_with_user, startup_command, status_ssh_target, ssh_destination_host, ssh_username, ssh_with_user, startup_command, status_ssh_target,
strip_stale_mouse_reports, strip_terminal_focus_reports, strip_unowned_terminal_reports, strip_stale_mouse_reports, strip_terminal_focus_reports, strip_unowned_terminal_reports,
summarize_trace_file, terminal_private_mode_transition, toml_bare_key_or_quoted, summarize_trace_file, summarize_trace_file_with_mode, terminal_private_mode_transition,
top_trace_events, trace_report_warnings, unix_update_script, update_installer_url, toml_bare_key_or_quoted, top_trace_events, trace_report_warnings, unix_update_script,
update_version_status, upsert_managed_block, valid_forward_host, vscode_safe_alias, update_installer_url, update_version_status, upsert_managed_block, valid_forward_host,
windows_update_script, vscode_safe_alias, windows_update_script,
}; };
use dosh::config::{ClientConfig, CommandExtension, HostConfig}; use dosh::config::{ClientConfig, CommandExtension, HostConfig};
use dosh::native::EnvVar; use dosh::native::EnvVar;
@@ -10324,27 +10563,38 @@ mod tests {
#[test] #[test]
fn trace_report_options_parse_defaults_and_overrides() { fn trace_report_options_parse_defaults_and_overrides() {
let parsed = parse_trace_report_options(&[]).unwrap(); let parsed = parse_trace_report_options(&[]).unwrap();
assert_eq!(parsed.host, None);
assert_eq!(parsed.client_log, None); assert_eq!(parsed.client_log, None);
assert_eq!( assert_eq!(parsed.server_log, Some("/tmp/dosh-server.log".to_string()));
parsed.server_log,
Some(std::path::PathBuf::from("/tmp/dosh-server.log"))
);
assert_eq!(parsed.tail, 20); assert_eq!(parsed.tail, 20);
assert!(parsed.latest_run);
let parsed = parse_trace_report_options(&[ let parsed = parse_trace_report_options(&[
"palav".to_string(),
"--client-log=/tmp/client.log".to_string(), "--client-log=/tmp/client.log".to_string(),
"--server-log".to_string(), "--server-log".to_string(),
"none".to_string(), "/tmp/server.log".to_string(),
"--all-runs".to_string(),
"--tail".to_string(), "--tail".to_string(),
"3".to_string(), "3".to_string(),
]) ])
.unwrap(); .unwrap();
assert_eq!(parsed.host.as_deref(), Some("palav"));
assert_eq!( assert_eq!(
parsed.client_log, parsed.client_log,
Some(std::path::PathBuf::from("/tmp/client.log")) Some(std::path::PathBuf::from("/tmp/client.log"))
); );
assert_eq!(parsed.server_log, None); assert_eq!(parsed.server_log.as_deref(), Some("/tmp/server.log"));
assert_eq!(parsed.tail, 3); assert_eq!(parsed.tail, 3);
assert!(!parsed.latest_run);
let parsed = parse_trace_report_options(&[
"--server-log=none".to_string(),
"--latest-run".to_string(),
])
.unwrap();
assert_eq!(parsed.server_log, None);
assert!(parsed.latest_run);
} }
#[test] #[test]
@@ -10455,6 +10705,35 @@ mod tests {
); );
} }
#[test]
fn trace_report_defaults_to_latest_process_run_when_marker_exists() {
let dir = tempfile::tempdir().unwrap();
let path = dir.path().join("server.log");
fs::write(
&path,
concat!(
"ts_ms=10 pid=1 event=server.pty_write session=term seq=1 summary=len=12,esc=false,focus=false,mouseish=true,printable=12\n",
"ts_ms=20 pid=2 event=server.start version=1.0.0 bind=0.0.0.0:50000\n",
"ts_ms=21 pid=2 event=server.resume_start seq=2 ack=1\n",
"ts_ms=22 pid=2 event=server.resume_ok bytes=20\n",
),
)
.unwrap();
let latest = summarize_trace_file(&path, 10).unwrap();
assert!(latest.latest_run_filtered);
assert_eq!(latest.skipped_old_run_lines, 1);
assert_eq!(latest.total_lines, 3);
assert_eq!(latest.server_mouseish_pty_write_events, 0);
assert_eq!(latest.reconnect_events, 2);
let all = summarize_trace_file_with_mode(&path, 10, false).unwrap();
assert!(!all.latest_run_filtered);
assert_eq!(all.skipped_old_run_lines, 0);
assert_eq!(all.total_lines, 4);
assert_eq!(all.server_mouseish_pty_write_events, 1);
}
#[test] #[test]
fn update_installer_uses_platform_native_script() { fn update_installer_uses_platform_native_script() {
assert_eq!( assert_eq!(
@@ -11040,6 +11319,35 @@ mod tests {
)); ));
} }
#[test]
fn local_sleep_gap_reconnects_before_forwarding_input() {
assert!(should_reconnect_before_input_for_local_sleep(
false,
LOCAL_SLEEP_REPAINT_AFTER
));
assert!(should_reconnect_before_input_for_local_sleep(
false,
LOCAL_SLEEP_REPAINT_AFTER + Duration::from_secs(10)
));
assert!(!should_reconnect_before_input_for_local_sleep(
false,
LOCAL_SLEEP_REPAINT_AFTER - Duration::from_millis(1)
));
assert!(!should_reconnect_before_input_for_local_sleep(
true,
LOCAL_SLEEP_REPAINT_AFTER + Duration::from_secs(10)
));
}
#[test]
fn reconnect_mouse_quarantine_is_long_enough_for_sleep_wake_noise() {
assert!(POST_RECONNECT_STALE_INPUT_GRACE >= LOCAL_SLEEP_REPAINT_AFTER);
assert_eq!(
strip_stale_mouse_reports(b"35;152;1M\x1b[A35;149;1M"),
b"\x1b[A"
);
}
#[test] #[test]
fn non_mouse_escape_input_survives_stale_filter() { fn non_mouse_escape_input_survives_stale_filter() {
assert_eq!(strip_stale_mouse_reports(b"\x1b[A"), b"\x1b[A"); assert_eq!(strip_stale_mouse_reports(b"\x1b[A"), b"\x1b[A");
+7
View File
@@ -200,6 +200,13 @@ async fn serve(config_path: Option<std::path::PathBuf>) -> Result<()> {
.with_context(|| format!("bind {bind}"))?, .with_context(|| format!("bind {bind}"))?,
); );
eprintln!("dosh-server listening on {bind}"); eprintln!("dosh-server listening on {bind}");
dosh::trace::event(
"server.start",
&[
("version", dosh::build_info::VERSION.to_string()),
("bind", bind.clone()),
],
);
let (pty_tx, mut pty_rx) = mpsc::unbounded_channel(); let (pty_tx, mut pty_rx) = mpsc::unbounded_channel();
let state = Arc::new(Mutex::new(ServerState::new( let state = Arc::new(Mutex::new(ServerState::new(