Filter trace reports to latest run

Cargo.lock

@@ -436,7 +436,7 @@ dependencies = [
 
 [[package]]
 name = "dosh"
-version = "1.0.0-rc31"
+version = "1.0.0-rc36"
 dependencies = [
  "anyhow",
  "base64",

Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "dosh"
-version = "1.0.0-rc31"
+version = "1.0.0-rc36"
 edition = "2024"
 license = "MIT"
 

README.md

@@ -85,12 +85,14 @@ dosh trace --client-log /tmp/dosh-client.log HOST
 Summarize collected traces with:
 
 ```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
-events. Trace byte prefixes are enabled for `dosh trace`, so use it only for
-short reproductions.
+When `HOST` is given, Dosh fetches `/tmp/dosh-server.log` over SSH before
+building the report. Set `DOSH_TRACE=/tmp/dosh-server.log` on `dosh-server` for
+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
 

src/bin/dosh-client.rs

@@ -71,9 +71,10 @@ const MAX_PENDING_USER_INPUT_BYTES: usize = 1024 * 1024;
 const STARTUP_INPUT_HOLD: Duration = Duration::from_millis(750);
 const POST_SUBMIT_ALL_INPUT_HOLD: Duration = Duration::from_millis(120);
 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 ALT_SCREEN_IDLE_REPAINT_AFTER: Duration = Duration::from_secs(15);
+const LOCAL_SLEEP_REPAINT_AFTER: Duration = Duration::from_secs(5);
 
 /// Sentinel `target_host` the server uses on a server-initiated `StreamOpen` that
 /// represents an SSH-agent connection (rather than a TCP target). The client
@@ -245,6 +246,10 @@ enum StartupGateMode {
 #[tokio::main(flavor = "current_thread")]
 async fn main() -> Result<()> {
     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();
     if args.server.as_deref() == Some("cp") {
         return run_cp_command(&config, &args);
@@ -791,9 +796,11 @@ struct TraceOptions {
 
 #[derive(Debug, Clone, PartialEq, Eq)]
 struct TraceReportOptions {
+    host: Option<String>,
     client_log: Option<PathBuf>,
-    server_log: Option<PathBuf>,
+    server_log: Option<String>,
     tail: usize,
+    latest_run: bool,
 }
 
 #[derive(Debug, Default, Clone, PartialEq, Eq)]
@@ -801,6 +808,8 @@ struct TraceReport {
     path: PathBuf,
     total_lines: usize,
     parsed_lines: usize,
+    skipped_old_run_lines: usize,
+    latest_run_filtered: bool,
     first_ts_ms: Option<u128>,
     last_ts_ms: Option<u128>,
     events: BTreeMap<String, usize>,
@@ -809,11 +818,16 @@ struct TraceReport {
     escape_events: usize,
     hex_events: usize,
     stripped_mouse_events: usize,
+    client_mouseish_sent_events: usize,
+    server_mouseish_pty_write_events: usize,
+    server_rejected_input_events: usize,
+    replay_drop_events: usize,
     queued_input_events: usize,
     flushed_input_events: usize,
     sent_input_events: usize,
     pty_write_events: usize,
     reconnect_events: usize,
+    unknown_resume_events: usize,
     roam_events: usize,
     recent_events: VecDeque<String>,
 }
@@ -883,15 +897,17 @@ fn parse_trace_options(command: &[String]) -> Result<TraceOptions> {
 }
 
 fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions> {
+    let mut host: Option<String> = 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 latest_run = true;
     let mut index = 0usize;
     while index < command.len() {
         match command[index].as_str() {
             "--client-log" => {
                 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));
                 index += 2;
@@ -906,7 +922,7 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
             }
             "--server-log" => {
                 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);
                 index += 2;
@@ -922,9 +938,17 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
                 server_log = None;
                 index += 1;
             }
+            "--latest-run" => {
+                latest_run = true;
+                index += 1;
+            }
+            "--all-runs" => {
+                latest_run = false;
+                index += 1;
+            }
             "--tail" => {
                 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)?;
                 index += 2;
@@ -936,25 +960,36 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
                 tail = parse_trace_tail(value)?;
                 index += 1;
             }
-            value => {
+            value if value.starts_with('-') => {
                 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 {
+        host,
         client_log,
         server_log,
         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") {
         None
     } else {
-        Some(expand_tilde(value))
+        Some(value.to_string())
     }
 }
 
@@ -1001,7 +1036,8 @@ fn sanitize_trace_name(value: &str) -> String {
 
 fn run_trace_command(args: &Args) -> Result<()> {
     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)?;
     if let Some(parent) = options.client_log.parent() {
@@ -1037,7 +1073,11 @@ fn run_trace_command(args: &Args) -> Result<()> {
     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 client_log = match options.client_log {
         Some(path) => Some(path),
@@ -1045,7 +1085,7 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
     };
     println!("Dosh trace report");
     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),
             Err(err) => println!("[warn] client log {}: {err:#}", path.display()),
         }
@@ -1056,7 +1096,21 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
         );
     }
     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),
             Err(err)
                 if err
@@ -1071,6 +1125,66 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
     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 {
     dirs::cache_dir()
         .unwrap_or_else(|| expand_tilde("~/.cache"))
@@ -1115,17 +1229,56 @@ fn newest_client_trace_path() -> Result<Option<PathBuf>> {
 }
 
 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 mut report = TraceReport {
-        path: path.to_path_buf(),
-        ..TraceReport::default()
-    };
+    let mut parsed = Vec::new();
+    let mut file_lines = 0usize;
     for line in BufReader::new(file).lines() {
         let line = line?;
-        report.total_lines += 1;
-        let Some(fields) = parse_trace_line(&line) else {
-            continue;
+        file_lines += 1;
+        if let Some(fields) = parse_trace_line(&line) {
+            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;
         if let Some(ts) = fields
             .get("ts_ms")
@@ -1159,6 +1312,11 @@ fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
         if event.contains("mouse_stripped") || event == "client.stale_strip" {
             report.stripped_mouse_events += 1;
         }
+        if event == "client.input_send"
+            && summary.get("mouseish").is_some_and(|value| value == "true")
+        {
+            report.client_mouseish_sent_events += 1;
+        }
         if event.starts_with("client.queue_") {
             report.queued_input_events += 1;
         }
@@ -1170,10 +1328,22 @@ fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
         }
         if event == "server.pty_write" {
             report.pty_write_events += 1;
+            if summary.get("mouseish").is_some_and(|value| value == "true") {
+                report.server_mouseish_pty_write_events += 1;
+            }
+        }
+        if event == "server.input_rejected_mode" {
+            report.server_rejected_input_events += 1;
+        }
+        if event.contains("replay_drop") {
+            report.replay_drop_events += 1;
         }
         if event.contains("reconnect") || event.contains("resume") {
             report.reconnect_events += 1;
         }
+        if event == "server.resume_unknown_client" {
+            report.unknown_resume_events += 1;
+        }
         if event.contains("roam") {
             report.roam_events += 1;
         }
@@ -1185,12 +1355,21 @@ fn summarize_trace_file(path: &Path, tail: usize) -> Result<TraceReport> {
             report.recent_events.push_back(rendered);
         }
     }
+    if report.total_lines == 0 && parsed_len > 0 {
+        report.total_lines = parsed_len;
+    }
     Ok(report)
 }
 
 fn print_trace_report(label: &str, report: &TraceReport) {
     println!();
     println!("{label}: {}", report.path.display());
+    if report.latest_run_filtered {
+        println!(
+            "  latest_run=true skipped_old_lines={}",
+            report.skipped_old_run_lines
+        );
+    }
     println!(
         "  lines={} parsed={} span_ms={}",
         report.total_lines,
@@ -1202,24 +1381,31 @@ fn print_trace_report(label: &str, report: &TraceReport) {
             .unwrap_or_else(|| "unknown".to_string())
     );
     println!(
-        "  input: sent={} queued={} flushed={} pty_writes={}",
+        "  input: sent={} queued={} flushed={} pty_writes={} rejected={} replay_drops={}",
         report.sent_input_events,
         report.queued_input_events,
         report.flushed_input_events,
-        report.pty_write_events
+        report.pty_write_events,
+        report.server_rejected_input_events,
+        report.replay_drop_events
     );
     println!(
-        "  terminal: mouseish={} stripped={} focus={} esc={} hex={}",
+        "  terminal: mouseish={} client_mouse_sent={} server_mouse_pty={} stripped={} focus={} esc={} hex={}",
         report.mouseish_events,
+        report.client_mouseish_sent_events,
+        report.server_mouseish_pty_write_events,
         report.stripped_mouse_events,
         report.focus_events,
         report.escape_events,
         report.hex_events
     );
     println!(
-        "  reconnect: events={} roam={}",
-        report.reconnect_events, report.roam_events
+        "  reconnect: events={} unknown_resume={} roam={}",
+        report.reconnect_events, report.unknown_resume_events, report.roam_events
     );
+    for warning in trace_report_warnings(report) {
+        println!("  alert: {warning}");
+    }
     if !report.events.is_empty() {
         println!("  top events:");
         for (event, count) in top_trace_events(&report.events, 8) {
@@ -1234,6 +1420,48 @@ fn print_trace_report(label: &str, report: &TraceReport) {
     }
 }
 
+fn trace_report_warnings(report: &TraceReport) -> Vec<String> {
+    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 {
+        warnings.push(format!(
+            "{} mouse-like input event(s) reached the server PTY",
+            report.server_mouseish_pty_write_events
+        ));
+    }
+    if report.client_mouseish_sent_events > report.stripped_mouse_events
+        && report.server_mouseish_pty_write_events == 0
+    {
+        warnings.push(format!(
+            "{} mouse-like input event(s) left the client; check the matching server log",
+            report.client_mouseish_sent_events
+        ));
+    }
+    if report.replay_drop_events > 0 {
+        warnings.push(format!(
+            "{} replay/drop event(s) observed",
+            report.replay_drop_events
+        ));
+    }
+    if report.reconnect_events > 0
+        && report.flushed_input_events == 0
+        && report.queued_input_events > 0
+    {
+        warnings
+            .push("queued input was observed around reconnect without a later flush".to_string());
+    }
+    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)> {
     let mut entries: Vec<_> = events
         .iter()
@@ -5449,6 +5677,7 @@ async fn run_terminal(
     let mut last_terminal_frame_at = Instant::now();
     let mut last_focus_repaint_at = Instant::now() - FOCUS_REPAINT_COOLDOWN;
     let mut last_idle_repaint_attempt_at = Instant::now() - ALT_SCREEN_IDLE_REPAINT_AFTER;
+    let mut last_status_tick_at = Instant::now();
     if let Some(frame) = first_frame {
         if !forward_only {
             render_frame(&frame)?;
@@ -5516,8 +5745,62 @@ async fn run_terminal(
                             dosh::trace::event("client.escape", &[]);
                             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);
                         if !forward_only
+                            && !refreshed_before_input
                             && saw_focus_in
                             && last_focus_repaint_at.elapsed() >= FOCUS_REPAINT_COOLDOWN
                         {
@@ -5577,13 +5860,14 @@ async fn run_terminal(
                         if bytes.is_empty() {
                             continue;
                         }
-                        if should_strip_unowned_terminal_reports(
+                        let before_mouse_strip = bytes.len();
+                        let (stripped_bytes, stripped_unowned_mouse) = strip_unowned_terminal_reports(
+                            bytes,
                             predictor.alternate_screen,
                             predictor.mouse_tracking,
-                        ) {
-                            let before_mouse_strip = bytes.len();
-                            bytes = strip_stale_mouse_reports(&bytes);
-                            if before_mouse_strip != bytes.len() {
+                        );
+                        bytes = stripped_bytes;
+                        if stripped_unowned_mouse {
                             dosh::trace::event(
                                 "client.unowned_mouse_stripped",
                                 &[
@@ -5592,7 +5876,6 @@ async fn run_terminal(
                                     ("summary", dosh::trace::bytes_summary(&bytes)),
                                 ],
                             );
-                            }
                             if bytes.is_empty() {
                                 continue;
                             }
@@ -6431,6 +6714,10 @@ async fn run_terminal(
                 }
             }
             _ = status_tick.tick() => {
+                let status_tick_at = Instant::now();
+                let status_tick_gap = status_tick_at.duration_since(last_status_tick_at);
+                last_status_tick_at = status_tick_at;
+                let mut repainted_this_tick = false;
                 let stale = last_packet_at.elapsed();
                 if stale >= Duration::from_secs(reconnect_timeout_secs.max(1)) {
                     if let Some(frame) = reconnect(
@@ -6451,6 +6738,8 @@ async fn run_terminal(
                             render_frame(&frame)?;
                             predictor.observe_output(&frame.bytes);
                             last_terminal_frame_at = Instant::now();
+                            last_idle_repaint_attempt_at = Instant::now();
+                            repainted_this_tick = true;
                         }
                         last_packet_at = Instant::now();
                         flush_pending_user_input(
@@ -6493,13 +6782,22 @@ async fn run_terminal(
                     )
                     .await?;
                     let now = Instant::now();
-                    if should_repaint_idle_alternate_screen(
+                    if !repainted_this_tick && should_repaint_idle_terminal(
                         predictor.alternate_screen,
                         last_terminal_frame_at,
                         last_idle_repaint_attempt_at,
+                        status_tick_gap,
                         now,
                     ) {
                         last_idle_repaint_attempt_at = now;
+                        dosh::trace::event(
+                            "client.idle_repaint_start",
+                            &[
+                                ("alt", predictor.alternate_screen.to_string()),
+                                ("tick_gap_ms", status_tick_gap.as_millis().to_string()),
+                                ("silent_ms", stale.as_millis().to_string()),
+                            ],
+                        );
                         if let Some(frame) = reconnect(
                             &socket,
                             &mut cred,
@@ -6922,10 +7220,31 @@ fn should_strip_stale_terminal_reports(
         || 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 {
     !alternate_screen && !mouse_tracking
 }
 
+fn strip_unowned_terminal_reports(
+    bytes: Vec<u8>,
+    alternate_screen: bool,
+    mouse_tracking: bool,
+) -> (Vec<u8>, bool) {
+    if !should_strip_unowned_terminal_reports(alternate_screen, mouse_tracking) {
+        return (bytes, false);
+    }
+    let before = bytes.len();
+    let stripped = strip_stale_mouse_reports(&bytes);
+    let changed = stripped.len() != before;
+    (stripped, changed)
+}
+
 fn input_contains_focus_in(bytes: &[u8]) -> bool {
     contains_bytes(bytes, b"\x1b[I") || contains_bytes(bytes, b"\x9bI")
 }
@@ -6950,19 +7269,28 @@ fn strip_terminal_focus_reports(bytes: &[u8]) -> Vec<u8> {
     out
 }
 
-fn should_repaint_idle_alternate_screen(
+fn should_repaint_idle_terminal(
     alternate_screen: bool,
     last_terminal_frame_at: Instant,
     last_attempt_at: Instant,
+    status_tick_gap: Duration,
     now: Instant,
 ) -> bool {
-    alternate_screen
+    (alternate_screen
         && now.duration_since(last_terminal_frame_at) >= ALT_SCREEN_IDLE_REPAINT_AFTER
+        || status_tick_gap >= LOCAL_SLEEP_REPAINT_AFTER)
         && now.duration_since(last_attempt_at) >= ALT_SCREEN_IDLE_REPAINT_AFTER
 }
 
 fn arm_stale_terminal_input_suppression(suppress_until: &mut Option<Instant>) {
     *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(
@@ -8901,32 +9229,34 @@ const TERMINAL_CLEANUP: &[u8] = concat!(
 mod tests {
     use super::{
         ALT_SCREEN_IDLE_REPAINT_AFTER, CachedCredential, DisconnectStatus, DynamicForward,
-        FRAME_GAP_RESYNC_AFTER_MS, FrameBuffer, LocalForward, MAX_PENDING_USER_INPUT_BYTES,
-        NativeIdentityContext, POST_SUBMIT_ALL_INPUT_HOLD, PendingStreamOpen, PredictMode,
-        Predictor, RESTART_STATUS_SCRIPT, RemoteForward, STARTUP_INPUT_HOLD, SshConfig,
-        SshPathTokenContext, StartupGateMode, StatusAction, UpdateOptions, UpdateRole, auth_allows,
-        cache_key, cache_server_prefix, cleanup_stream_state, clear_cached_credentials,
+        FRAME_GAP_RESYNC_AFTER_MS, FrameBuffer, LOCAL_SLEEP_REPAINT_AFTER, LocalForward,
+        MAX_PENDING_USER_INPUT_BYTES, NativeIdentityContext, POST_RECONNECT_STALE_INPUT_GRACE,
+        POST_SUBMIT_ALL_INPUT_HOLD, PendingStreamOpen, PredictMode, Predictor,
+        RESTART_STATUS_SCRIPT, RemoteForward, STARTUP_INPUT_HOLD, SshConfig, SshPathTokenContext,
+        StartupGateMode, StatusAction, UpdateOptions, UpdateRole, auth_allows, cache_key,
+        cache_server_prefix, cleanup_stream_state, clear_cached_credentials,
         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, raw_contains_host_table,
-        recv_response_until, refresh_live_addr, release_tag_download_url,
+        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,
-        should_hold_post_submit_input, should_repaint_idle_alternate_screen,
-        should_strip_unowned_terminal_reports, 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, strip_stale_mouse_reports,
-        strip_terminal_focus_reports, summarize_trace_file, terminal_private_mode_transition,
-        toml_bare_key_or_quoted, top_trace_events, unix_update_script, update_installer_url,
-        update_version_status, upsert_managed_block, valid_forward_host, vscode_safe_alias,
-        windows_update_script,
+        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,
+        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,
+        summarize_trace_file, summarize_trace_file_with_mode, terminal_private_mode_transition,
+        toml_bare_key_or_quoted, top_trace_events, trace_report_warnings, unix_update_script,
+        update_installer_url, update_version_status, upsert_managed_block, valid_forward_host,
+        vscode_safe_alias, windows_update_script,
     };
     use dosh::config::{ClientConfig, CommandExtension, HostConfig};
     use dosh::native::EnvVar;
@@ -10233,27 +10563,38 @@ mod tests {
     #[test]
     fn trace_report_options_parse_defaults_and_overrides() {
         let parsed = parse_trace_report_options(&[]).unwrap();
+        assert_eq!(parsed.host, None);
         assert_eq!(parsed.client_log, None);
-        assert_eq!(
-            parsed.server_log,
-            Some(std::path::PathBuf::from("/tmp/dosh-server.log"))
-        );
+        assert_eq!(parsed.server_log, Some("/tmp/dosh-server.log".to_string()));
         assert_eq!(parsed.tail, 20);
+        assert!(parsed.latest_run);
 
         let parsed = parse_trace_report_options(&[
+            "palav".to_string(),
             "--client-log=/tmp/client.log".to_string(),
             "--server-log".to_string(),
-            "none".to_string(),
+            "/tmp/server.log".to_string(),
+            "--all-runs".to_string(),
             "--tail".to_string(),
             "3".to_string(),
         ])
         .unwrap();
+        assert_eq!(parsed.host.as_deref(), Some("palav"));
         assert_eq!(
             parsed.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!(!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]
@@ -10318,11 +10659,79 @@ mod tests {
         assert_eq!(report.queued_input_events, 1);
         assert_eq!(report.sent_input_events, 1);
         assert_eq!(report.reconnect_events, 1);
+        assert_eq!(report.client_mouseish_sent_events, 0);
+        assert_eq!(report.server_mouseish_pty_write_events, 0);
         assert_eq!(report.recent_events.len(), 2);
         assert_eq!(
             top_trace_events(&report.events, 1),
             vec![("client.input_send".to_string(), 1)]
         );
+        assert_eq!(
+            trace_report_warnings(&report),
+            vec!["queued input was observed around reconnect without a later flush".to_string()]
+        );
+    }
+
+    #[test]
+    fn trace_report_warns_when_mouse_input_reaches_server_pty() {
+        let dir = tempfile::tempdir().unwrap();
+        let path = dir.path().join("server.log");
+        fs::write(
+            &path,
+            concat!(
+                "ts_ms=30 pid=2 event=server.input_roam session=term from=1.1.1.1:1 to=2.2.2.2:2\n",
+                "ts_ms=31 pid=2 event=server.pty_write session=term seq=9 summary=len=12,esc=false,focus=false,mouseish=true,printable=12\n",
+                "ts_ms=32 pid=2 event=server.input_replay_drop session=term seq=8 summary=len=1,esc=false,focus=false,mouseish=false,printable=1\n",
+            ),
+        )
+        .unwrap();
+
+        let report = summarize_trace_file(&path, 10).unwrap();
+        let warnings = trace_report_warnings(&report);
+
+        assert_eq!(report.pty_write_events, 1);
+        assert_eq!(report.server_mouseish_pty_write_events, 1);
+        assert_eq!(report.replay_drop_events, 1);
+        assert_eq!(report.roam_events, 1);
+        assert!(
+            warnings
+                .iter()
+                .any(|warning| { warning == "1 mouse-like input event(s) reached the server PTY" })
+        );
+        assert!(
+            warnings
+                .iter()
+                .any(|warning| { warning == "1 replay/drop event(s) observed" })
+        );
+    }
+
+    #[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]
@@ -10721,6 +11130,47 @@ mod tests {
         assert_eq!(pending_bytes, MAX_PENDING_USER_INPUT_BYTES);
     }
 
+    #[test]
+    fn stale_pending_user_input_is_marked_for_mouse_stripping() {
+        let mut pending = VecDeque::new();
+        let mut pending_bytes = 0usize;
+
+        queue_pending_user_input(&mut pending, &mut pending_bytes, b"\x1b[<35;10;1M".to_vec())
+            .unwrap();
+        queue_stale_pending_user_input(
+            &mut pending,
+            &mut pending_bytes,
+            b"\x1b[<35;11;1M".to_vec(),
+        )
+        .unwrap();
+
+        let normal = pending.pop_front().unwrap();
+        assert!(!normal.strip_mouse_reports);
+        assert_eq!(strip_stale_mouse_reports(&normal.bytes), b"");
+
+        let stale = pending.pop_front().unwrap();
+        assert!(stale.strip_mouse_reports);
+        assert_eq!(strip_stale_mouse_reports(&stale.bytes), b"");
+    }
+
+    #[test]
+    fn unowned_terminal_mouse_reports_strip_only_without_mouse_owner() {
+        let input = b"\x1b[<35;10;1Mcmd\r".to_vec();
+
+        let (stripped, changed) = strip_unowned_terminal_reports(input.clone(), false, false);
+        assert!(changed);
+        assert_eq!(stripped, b"cmd\r");
+
+        let (preserved, changed) = strip_unowned_terminal_reports(input.clone(), false, true);
+        assert!(!changed);
+        assert_eq!(preserved, input);
+
+        let (preserved, changed) =
+            strip_unowned_terminal_reports(b"\x1b[<35;10;1M".to_vec(), true, false);
+        assert!(!changed);
+        assert_eq!(preserved, b"\x1b[<35;10;1M");
+    }
+
     #[test]
     fn transient_udp_send_errors_are_not_terminal_fatal() {
         #[cfg(unix)]
@@ -10828,22 +11278,74 @@ mod tests {
     }
 
     #[test]
-    fn idle_repaint_only_runs_for_stale_alternate_screen() {
+    fn idle_repaint_runs_for_stale_alternate_screen_or_sleep_gap() {
         let now = Instant::now();
         let stale = now - ALT_SCREEN_IDLE_REPAINT_AFTER - Duration::from_secs(1);
         let recent = now - Duration::from_secs(1);
-        assert!(should_repaint_idle_alternate_screen(
-            true, stale, stale, now
+        assert!(should_repaint_idle_terminal(
+            true,
+            stale,
+            stale,
+            Duration::from_secs(1),
+            now
         ));
-        assert!(!should_repaint_idle_alternate_screen(
-            false, stale, stale, now
+        assert!(should_repaint_idle_terminal(
+            false,
+            recent,
+            stale,
+            LOCAL_SLEEP_REPAINT_AFTER + Duration::from_secs(1),
+            now
         ));
-        assert!(!should_repaint_idle_alternate_screen(
-            true, recent, stale, now
+        assert!(!should_repaint_idle_terminal(
+            false,
+            stale,
+            stale,
+            Duration::from_secs(1),
+            now
         ));
-        assert!(!should_repaint_idle_alternate_screen(
-            true, stale, recent, now
+        assert!(!should_repaint_idle_terminal(
+            true,
+            recent,
+            stale,
+            Duration::from_secs(1),
+            now
         ));
+        assert!(!should_repaint_idle_terminal(
+            true,
+            stale,
+            recent,
+            LOCAL_SLEEP_REPAINT_AFTER + Duration::from_secs(1),
+            now
+        ));
+    }
+
+    #[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]

src/bin/dosh-server.rs

@@ -200,6 +200,13 @@ async fn serve(config_path: Option<std::path::PathBuf>) -> Result<()> {
             .with_context(|| format!("bind {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 state = Arc::new(Mutex::new(ServerState::new(