Compare commits

...
Author SHA1 Message Date
DuProcess c65aba9d7a Repaint terminal 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 11:48:18 -04:00
DuProcess 818b481154 Cover terminal mouse input filtering
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 01:08:38 -04:00
DuProcess 70650e221b Flag trace terminal input anomalies
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 01:04:37 -04:00
DuProcess 01e8870578 Add trace report summarizer
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 00:59:15 -04:00
4 changed files with 751 additions and 52 deletions
Generated
+1 -1
View File
@@ -436,7 +436,7 @@ dependencies = [
[[package]] [[package]]
name = "dosh" name = "dosh"
version = "1.0.0-rc30" version = "1.0.0-rc33"
dependencies = [ dependencies = [
"anyhow", "anyhow",
"base64", "base64",
+1 -1
View File
@@ -1,6 +1,6 @@
[package] [package]
name = "dosh" name = "dosh"
version = "1.0.0-rc30" version = "1.0.0-rc33"
edition = "2024" edition = "2024"
license = "MIT" license = "MIT"
+6
View File
@@ -82,6 +82,12 @@ The client log path is printed before the session starts. To choose it:
dosh trace --client-log /tmp/dosh-client.log HOST dosh trace --client-log /tmp/dosh-client.log HOST
``` ```
Summarize collected traces with:
```sh
dosh trace report --client-log /tmp/dosh-client.log
```
Set `DOSH_TRACE=/tmp/dosh-server.log` on `dosh-server` for matching server 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 events. Trace byte prefixes are enabled for `dosh trace`, so use it only for
short reproductions. short reproductions.
+743 -50
View File
@@ -47,6 +47,8 @@ use std::collections::HashMap;
use std::collections::HashSet; use std::collections::HashSet;
use std::collections::VecDeque; use std::collections::VecDeque;
use std::fs; use std::fs;
use std::fs::File;
use std::io::{BufRead, BufReader};
use std::io::{Read, Seek, Write}; use std::io::{Read, Seek, Write};
use std::net::{ use std::net::{
Ipv4Addr, Ipv6Addr, SocketAddr, TcpListener as StdTcpListener, TcpStream as StdTcpStream, Ipv4Addr, Ipv6Addr, SocketAddr, TcpListener as StdTcpListener, TcpStream as StdTcpStream,
@@ -72,6 +74,7 @@ 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(2);
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);
/// Sentinel `target_host` the server uses on a server-initiated `StreamOpen` that /// Sentinel `target_host` the server uses on a server-initiated `StreamOpen` that
/// represents an SSH-agent connection (rather than a TCP target). The client /// represents an SSH-agent connection (rather than a TCP target). The client
@@ -787,6 +790,39 @@ struct TraceOptions {
bytes: bool, bytes: bool,
} }
#[derive(Debug, Clone, PartialEq, Eq)]
struct TraceReportOptions {
client_log: Option<PathBuf>,
server_log: Option<PathBuf>,
tail: usize,
}
#[derive(Debug, Default, Clone, PartialEq, Eq)]
struct TraceReport {
path: PathBuf,
total_lines: usize,
parsed_lines: usize,
first_ts_ms: Option<u128>,
last_ts_ms: Option<u128>,
events: BTreeMap<String, usize>,
mouseish_events: usize,
focus_events: usize,
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,
roam_events: usize,
recent_events: VecDeque<String>,
}
fn parse_trace_options(command: &[String]) -> Result<TraceOptions> { fn parse_trace_options(command: &[String]) -> Result<TraceOptions> {
let mut client_log: Option<PathBuf> = None; let mut client_log: Option<PathBuf> = None;
let mut bytes = true; let mut bytes = true;
@@ -851,6 +887,90 @@ fn parse_trace_options(command: &[String]) -> Result<TraceOptions> {
}) })
} }
fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions> {
let mut client_log: Option<PathBuf> = None;
let mut server_log: Option<PathBuf> = Some(PathBuf::from("/tmp/dosh-server.log"));
let mut tail = 20usize;
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]")
})?;
client_log = Some(expand_tilde(path));
index += 2;
}
value if value.starts_with("--client-log=") => {
let path = value
.strip_prefix("--client-log=")
.filter(|value| !value.is_empty())
.ok_or_else(|| anyhow!("--client-log requires a path"))?;
client_log = Some(expand_tilde(path));
index += 1;
}
"--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]")
})?;
server_log = parse_optional_trace_path(path);
index += 2;
}
value if value.starts_with("--server-log=") => {
let path = value
.strip_prefix("--server-log=")
.ok_or_else(|| anyhow!("--server-log requires a path"))?;
server_log = parse_optional_trace_path(path);
index += 1;
}
"--no-server" => {
server_log = None;
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]")
})?;
tail = parse_trace_tail(value)?;
index += 2;
}
value if value.starts_with("--tail=") => {
let value = value
.strip_prefix("--tail=")
.ok_or_else(|| anyhow!("--tail requires a count"))?;
tail = parse_trace_tail(value)?;
index += 1;
}
value => {
return Err(anyhow!(
"usage: dosh trace report [--client-log PATH] [--server-log PATH|none] [--tail N] (unknown option {value})"
));
}
}
}
Ok(TraceReportOptions {
client_log,
server_log,
tail,
})
}
fn parse_optional_trace_path(value: &str) -> Option<PathBuf> {
if matches!(value, "" | "none" | "off" | "0") {
None
} else {
Some(expand_tilde(value))
}
}
fn parse_trace_tail(value: &str) -> Result<usize> {
let tail = value
.parse::<usize>()
.with_context(|| format!("parse trace tail count {value}"))?;
anyhow::ensure!(tail <= 500, "--tail must be 500 or less");
Ok(tail)
}
fn default_client_trace_path(host: &str) -> PathBuf { fn default_client_trace_path(host: &str) -> PathBuf {
let root = dirs::cache_dir() let root = dirs::cache_dir()
.unwrap_or_else(|| expand_tilde("~/.cache")) .unwrap_or_else(|| expand_tilde("~/.cache"))
@@ -885,6 +1005,9 @@ 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") {
return run_trace_report_command(&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() {
fs::create_dir_all(parent) fs::create_dir_all(parent)
@@ -919,6 +1042,350 @@ fn run_trace_command(args: &Args) -> Result<()> {
Ok(()) Ok(())
} }
fn run_trace_report_command(command: &[String]) -> Result<()> {
let options = parse_trace_report_options(command)?;
let client_log = match options.client_log {
Some(path) => Some(path),
None => newest_client_trace_path()?,
};
println!("Dosh trace report");
if let Some(path) = client_log {
match summarize_trace_file(&path, options.tail) {
Ok(report) => print_trace_report("client", &report),
Err(err) => println!("[warn] client log {}: {err:#}", path.display()),
}
} else {
println!(
"[warn] client log: none found under {}",
trace_cache_dir().display()
);
}
if let Some(path) = options.server_log {
match summarize_trace_file(&path, options.tail) {
Ok(report) => print_trace_report("server", &report),
Err(err)
if err
.downcast_ref::<std::io::Error>()
.is_some_and(|io| io.kind() == std::io::ErrorKind::NotFound) =>
{
println!("[warn] server log {}: not found", path.display());
}
Err(err) => println!("[warn] server log {}: {err:#}", path.display()),
}
}
Ok(())
}
fn trace_cache_dir() -> PathBuf {
dirs::cache_dir()
.unwrap_or_else(|| expand_tilde("~/.cache"))
.join("dosh")
.join("trace")
}
fn newest_client_trace_path() -> Result<Option<PathBuf>> {
let root = trace_cache_dir();
let Ok(entries) = fs::read_dir(&root) else {
return Ok(None);
};
let mut newest: Option<(SystemTime, PathBuf)> = None;
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);
if newest
.as_ref()
.is_none_or(|(old_modified, _)| modified > *old_modified)
{
newest = Some((modified, path));
}
}
Ok(newest.map(|(_, path)| path))
}
fn summarize_trace_file(path: &Path, tail: usize) -> 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()
};
for line in BufReader::new(file).lines() {
let line = line?;
report.total_lines += 1;
let Some(fields) = parse_trace_line(&line) else {
continue;
};
report.parsed_lines += 1;
if let Some(ts) = fields
.get("ts_ms")
.and_then(|value| value.parse::<u128>().ok())
{
report.first_ts_ms.get_or_insert(ts);
report.last_ts_ms = Some(ts);
}
let event = fields
.get("event")
.cloned()
.unwrap_or_else(|| "<missing>".to_string());
*report.events.entry(event.clone()).or_insert(0) += 1;
let summary = fields
.get("bytes")
.or_else(|| fields.get("summary"))
.map(|value| parse_trace_summary(value))
.unwrap_or_default();
if summary.get("mouseish").is_some_and(|value| value == "true") {
report.mouseish_events += 1;
}
if summary.get("focus").is_some_and(|value| value == "true") {
report.focus_events += 1;
}
if summary.get("esc").is_some_and(|value| value == "true") {
report.escape_events += 1;
}
if summary.contains_key("hex") {
report.hex_events += 1;
}
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;
}
if event.starts_with("client.pending_flush") {
report.flushed_input_events += 1;
}
if event == "client.input_send" {
report.sent_input_events += 1;
}
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.contains("roam") {
report.roam_events += 1;
}
if tail > 0 {
let rendered = render_trace_event(&fields);
if report.recent_events.len() == tail {
report.recent_events.pop_front();
}
report.recent_events.push_back(rendered);
}
}
Ok(report)
}
fn print_trace_report(label: &str, report: &TraceReport) {
println!();
println!("{label}: {}", report.path.display());
println!(
" lines={} parsed={} span_ms={}",
report.total_lines,
report.parsed_lines,
report
.first_ts_ms
.zip(report.last_ts_ms)
.map(|(first, last)| last.saturating_sub(first).to_string())
.unwrap_or_else(|| "unknown".to_string())
);
println!(
" 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.server_rejected_input_events,
report.replay_drop_events
);
println!(
" 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
);
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) {
println!(" {count:>5} {event}");
}
}
if !report.recent_events.is_empty() {
println!(" recent:");
for event in &report.recent_events {
println!(" {event}");
}
}
}
fn trace_report_warnings(report: &TraceReport) -> Vec<String> {
let mut warnings = Vec::new();
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 top_trace_events(events: &BTreeMap<String, usize>, limit: usize) -> Vec<(String, usize)> {
let mut entries: Vec<_> = events
.iter()
.map(|(event, count)| (event.clone(), *count))
.collect();
entries.sort_by(|left, right| right.1.cmp(&left.1).then_with(|| left.0.cmp(&right.0)));
entries.truncate(limit);
entries
}
fn render_trace_event(fields: &BTreeMap<String, String>) -> String {
let ts = fields.get("ts_ms").map(String::as_str).unwrap_or("?");
let event = fields
.get("event")
.map(String::as_str)
.unwrap_or("<missing>");
let mut parts = vec![format!("{ts} {event}")];
for key in [
"seq",
"ack",
"sent",
"before",
"after",
"summary",
"bytes",
"silent_ms",
] {
if let Some(value) = fields.get(key) {
parts.push(format!("{key}={value}"));
}
}
parts.join(" ")
}
fn parse_trace_line(line: &str) -> Option<BTreeMap<String, String>> {
let mut fields = BTreeMap::new();
for token in split_trace_tokens(line)? {
let (key, value) = token.split_once('=')?;
fields.insert(key.to_string(), value.to_string());
}
Some(fields)
}
fn split_trace_tokens(line: &str) -> Option<Vec<String>> {
let mut tokens = Vec::new();
let mut current = String::new();
let mut chars = line.chars().peekable();
let mut quoted = false;
while let Some(ch) = chars.next() {
if quoted {
if ch == '\'' {
if chars.peek() == Some(&'\\') {
chars.next();
if chars.next() != Some('\'') || chars.next() != Some('\'') {
return None;
}
current.push('\'');
} else {
quoted = false;
}
} else {
current.push(ch);
}
continue;
}
if ch == '\'' {
quoted = true;
} else if ch.is_ascii_whitespace() {
if !current.is_empty() {
tokens.push(std::mem::take(&mut current));
}
} else {
current.push(ch);
}
}
if quoted {
return None;
}
if !current.is_empty() {
tokens.push(current);
}
Some(tokens)
}
fn parse_trace_summary(summary: &str) -> BTreeMap<String, String> {
let mut fields = BTreeMap::new();
for part in summary.split(',') {
if let Some((key, value)) = part.split_once('=') {
fields.insert(key.to_string(), value.to_string());
}
}
fields
}
fn push_trace_passthrough_args(command: &mut Command, args: &Args) { fn push_trace_passthrough_args(command: &mut Command, args: &Args) {
if let Some(session) = &args.session { if let Some(session) = &args.session {
command.arg("--session").arg(session); command.arg("--session").arg(session);
@@ -5040,6 +5507,7 @@ async fn run_terminal(
let mut last_terminal_frame_at = Instant::now(); let mut last_terminal_frame_at = Instant::now();
let mut last_focus_repaint_at = Instant::now() - FOCUS_REPAINT_COOLDOWN; 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_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 let Some(frame) = first_frame {
if !forward_only { if !forward_only {
render_frame(&frame)?; render_frame(&frame)?;
@@ -5168,22 +5636,22 @@ async fn run_terminal(
if bytes.is_empty() { if bytes.is_empty() {
continue; 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.alternate_screen,
predictor.mouse_tracking, predictor.mouse_tracking,
) { );
let before_mouse_strip = bytes.len(); bytes = stripped_bytes;
bytes = strip_stale_mouse_reports(&bytes); if stripped_unowned_mouse {
if before_mouse_strip != bytes.len() { dosh::trace::event(
dosh::trace::event( "client.unowned_mouse_stripped",
"client.unowned_mouse_stripped", &[
&[ ("before", before_mouse_strip.to_string()),
("before", before_mouse_strip.to_string()), ("after", bytes.len().to_string()),
("after", bytes.len().to_string()), ("summary", dosh::trace::bytes_summary(&bytes)),
("summary", dosh::trace::bytes_summary(&bytes)), ],
], );
);
}
if bytes.is_empty() { if bytes.is_empty() {
continue; continue;
} }
@@ -6022,6 +6490,10 @@ async fn run_terminal(
} }
} }
_ = status_tick.tick() => { _ = 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(); let stale = last_packet_at.elapsed();
if stale >= Duration::from_secs(reconnect_timeout_secs.max(1)) { if stale >= Duration::from_secs(reconnect_timeout_secs.max(1)) {
if let Some(frame) = reconnect( if let Some(frame) = reconnect(
@@ -6042,6 +6514,8 @@ async fn run_terminal(
render_frame(&frame)?; render_frame(&frame)?;
predictor.observe_output(&frame.bytes); predictor.observe_output(&frame.bytes);
last_terminal_frame_at = Instant::now(); last_terminal_frame_at = Instant::now();
last_idle_repaint_attempt_at = Instant::now();
repainted_this_tick = true;
} }
last_packet_at = Instant::now(); last_packet_at = Instant::now();
flush_pending_user_input( flush_pending_user_input(
@@ -6084,13 +6558,22 @@ async fn run_terminal(
) )
.await?; .await?;
let now = Instant::now(); let now = Instant::now();
if should_repaint_idle_alternate_screen( if !repainted_this_tick && should_repaint_idle_terminal(
predictor.alternate_screen, predictor.alternate_screen,
last_terminal_frame_at, last_terminal_frame_at,
last_idle_repaint_attempt_at, last_idle_repaint_attempt_at,
status_tick_gap,
now, now,
) { ) {
last_idle_repaint_attempt_at = 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( if let Some(frame) = reconnect(
&socket, &socket,
&mut cred, &mut cred,
@@ -6517,6 +7000,20 @@ fn should_strip_unowned_terminal_reports(alternate_screen: bool, mouse_tracking:
!alternate_screen && !mouse_tracking !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 { fn input_contains_focus_in(bytes: &[u8]) -> bool {
contains_bytes(bytes, b"\x1b[I") || contains_bytes(bytes, b"\x9bI") contains_bytes(bytes, b"\x1b[I") || contains_bytes(bytes, b"\x9bI")
} }
@@ -6541,14 +7038,16 @@ fn strip_terminal_focus_reports(bytes: &[u8]) -> Vec<u8> {
out out
} }
fn should_repaint_idle_alternate_screen( fn should_repaint_idle_terminal(
alternate_screen: bool, alternate_screen: bool,
last_terminal_frame_at: Instant, last_terminal_frame_at: Instant,
last_attempt_at: Instant, last_attempt_at: Instant,
status_tick_gap: Duration,
now: Instant, now: Instant,
) -> bool { ) -> bool {
alternate_screen (alternate_screen
&& now.duration_since(last_terminal_frame_at) >= ALT_SCREEN_IDLE_REPAINT_AFTER && 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 && now.duration_since(last_attempt_at) >= ALT_SCREEN_IDLE_REPAINT_AFTER
} }
@@ -8492,30 +8991,33 @@ const TERMINAL_CLEANUP: &[u8] = concat!(
mod tests { 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, LocalForward, MAX_PENDING_USER_INPUT_BYTES, FRAME_GAP_RESYNC_AFTER_MS, FrameBuffer, LOCAL_SLEEP_REPAINT_AFTER, LocalForward,
NativeIdentityContext, POST_SUBMIT_ALL_INPUT_HOLD, PendingStreamOpen, PredictMode, MAX_PENDING_USER_INPUT_BYTES, NativeIdentityContext, POST_SUBMIT_ALL_INPUT_HOLD,
Predictor, RESTART_STATUS_SCRIPT, RemoteForward, STARTUP_INPUT_HOLD, SshConfig, PendingStreamOpen, PredictMode, Predictor, RESTART_STATUS_SCRIPT, RemoteForward,
SshPathTokenContext, StartupGateMode, StatusAction, UpdateOptions, UpdateRole, auth_allows, STARTUP_INPUT_HOLD, SshConfig, SshPathTokenContext, StartupGateMode, StatusAction,
cache_key, cache_server_prefix, cleanup_stream_state, clear_cached_credentials, UpdateOptions, UpdateRole, auth_allows, cache_key, cache_server_prefix,
ensure_tui_safe_status_overlay, expand_ssh_path_tokens, input_contains_focus_in, cleanup_stream_state, clear_cached_credentials, ensure_tui_safe_status_overlay,
input_matches_escape, is_local_status_target, is_resume_response_for_client, expand_ssh_path_tokens, input_contains_focus_in, input_matches_escape,
latest_release_download_url, load_first_native_identity_with_prompt, is_local_status_target, is_resume_response_for_client, latest_release_download_url,
native_proxy_udp_warning, parse_dynamic_forward, parse_escape_key, parse_local_forward, load_first_native_identity_with_prompt, native_proxy_udp_warning, parse_dynamic_forward,
parse_remote_forward, parse_ssh_config, parse_trace_options, parse_update_options, parse_escape_key, parse_local_forward, parse_remote_forward, parse_ssh_config,
post_submit_hold_duration, queue_pending_user_input, raw_contains_host_table, parse_trace_line, parse_trace_options, parse_trace_report_options, parse_trace_summary,
recv_response_until, refresh_live_addr, release_tag_download_url, parse_update_options, post_submit_hold_duration, queue_pending_user_input,
release_tag_from_effective_url, release_version_from_tag, render_status_clear, queue_stale_pending_user_input, raw_contains_host_table, recv_response_until,
render_status_overlay, requested_env, resolved_startup_command, retire_stream_state, refresh_live_addr, release_tag_download_url, release_tag_from_effective_url,
retransmit_stream_opens, rewrite_forward_command, sanitize_trace_name, release_version_from_tag, render_status_clear, render_status_overlay, requested_env,
selected_predict_mode, selected_udp_host, server_version_mismatch, resolved_startup_command, retire_stream_state, retransmit_stream_opens,
should_flush_terminal_input_after_contact, should_hold_during_startup_gate, rewrite_forward_command, sanitize_trace_name, selected_predict_mode, selected_udp_host,
should_hold_post_submit_input, should_repaint_idle_alternate_screen, server_version_mismatch, should_flush_terminal_input_after_contact,
should_strip_unowned_terminal_reports, split_after_command_submit, ssh_command_target, should_hold_during_startup_gate, should_hold_post_submit_input,
ssh_config_uses_proxy, ssh_destination_host, ssh_username, ssh_with_user, startup_command, should_repaint_idle_terminal, should_strip_unowned_terminal_reports,
status_ssh_target, strip_stale_mouse_reports, strip_terminal_focus_reports, split_after_command_submit, split_trace_tokens, ssh_command_target, ssh_config_uses_proxy,
terminal_private_mode_transition, toml_bare_key_or_quoted, unix_update_script, ssh_destination_host, ssh_username, ssh_with_user, startup_command, status_ssh_target,
update_installer_url, update_version_status, upsert_managed_block, valid_forward_host, strip_stale_mouse_reports, strip_terminal_focus_reports, strip_unowned_terminal_reports,
vscode_safe_alias, windows_update_script, summarize_trace_file, 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::config::{ClientConfig, CommandExtension, HostConfig};
use dosh::native::EnvVar; use dosh::native::EnvVar;
@@ -9819,6 +10321,32 @@ mod tests {
assert!(parse_trace_options(&[]).is_err()); assert!(parse_trace_options(&[]).is_err());
} }
#[test]
fn trace_report_options_parse_defaults_and_overrides() {
let parsed = parse_trace_report_options(&[]).unwrap();
assert_eq!(parsed.client_log, None);
assert_eq!(
parsed.server_log,
Some(std::path::PathBuf::from("/tmp/dosh-server.log"))
);
assert_eq!(parsed.tail, 20);
let parsed = parse_trace_report_options(&[
"--client-log=/tmp/client.log".to_string(),
"--server-log".to_string(),
"none".to_string(),
"--tail".to_string(),
"3".to_string(),
])
.unwrap();
assert_eq!(
parsed.client_log,
Some(std::path::PathBuf::from("/tmp/client.log"))
);
assert_eq!(parsed.server_log, None);
assert_eq!(parsed.tail, 3);
}
#[test] #[test]
fn trace_log_name_is_shell_and_path_safe() { fn trace_log_name_is_shell_and_path_safe() {
assert_eq!(sanitize_trace_name("palav"), "palav"); assert_eq!(sanitize_trace_name("palav"), "palav");
@@ -9826,6 +10354,107 @@ mod tests {
assert_eq!(sanitize_trace_name(""), "host"); assert_eq!(sanitize_trace_name(""), "host");
} }
#[test]
fn trace_line_parser_handles_shell_quoted_values() {
let tokens =
split_trace_tokens("ts_ms=1 event='client stdin' bytes='len=1,hex=27'").unwrap();
assert_eq!(
tokens,
vec![
"ts_ms=1".to_string(),
"event=client stdin".to_string(),
"bytes=len=1,hex=27".to_string()
]
);
let parsed =
parse_trace_line("ts_ms=1 event=client.stdin bytes=len=3,esc=true,mouseish=false")
.unwrap();
assert_eq!(parsed["event"], "client.stdin");
assert_eq!(parsed["bytes"], "len=3,esc=true,mouseish=false");
}
#[test]
fn trace_summary_parser_counts_properties() {
let parsed = parse_trace_summary("len=3,esc=true,focus=false,mouseish=true,hex=1b5b41");
assert_eq!(parsed["len"], "3");
assert_eq!(parsed["esc"], "true");
assert_eq!(parsed["mouseish"], "true");
assert_eq!(parsed["hex"], "1b5b41");
}
#[test]
fn trace_report_summarizes_terminal_and_reconnect_events() {
let dir = tempfile::tempdir().unwrap();
let path = dir.path().join("client.log");
fs::write(
&path,
concat!(
"ts_ms=10 pid=1 event=client.stdin bytes=len=9,esc=true,focus=false,mouseish=true,printable=7,hex=313b324d\n",
"ts_ms=12 pid=1 event=client.unowned_mouse_stripped before=9 after=0 summary=len=0,esc=false,focus=false,mouseish=false,printable=0\n",
"ts_ms=15 pid=1 event=client.queue_disconnected bytes=len=1,esc=false,focus=false,mouseish=false,printable=1 silent_ms=2000\n",
"ts_ms=20 pid=1 event=client.reconnect_live_ok output_seq=3 bytes=12\n",
"ts_ms=25 pid=1 event=client.input_send seq=4 ack=3 sent=true summary=len=1,esc=false,focus=false,mouseish=false,printable=1\n",
),
)
.unwrap();
let report = summarize_trace_file(&path, 2).unwrap();
assert_eq!(report.total_lines, 5);
assert_eq!(report.parsed_lines, 5);
assert_eq!(report.mouseish_events, 1);
assert_eq!(report.escape_events, 1);
assert_eq!(report.hex_events, 1);
assert_eq!(report.stripped_mouse_events, 1);
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] #[test]
fn update_installer_uses_platform_native_script() { fn update_installer_uses_platform_native_script() {
assert_eq!( assert_eq!(
@@ -10222,6 +10851,47 @@ mod tests {
assert_eq!(pending_bytes, MAX_PENDING_USER_INPUT_BYTES); 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] #[test]
fn transient_udp_send_errors_are_not_terminal_fatal() { fn transient_udp_send_errors_are_not_terminal_fatal() {
#[cfg(unix)] #[cfg(unix)]
@@ -10329,21 +10999,44 @@ mod tests {
} }
#[test] #[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 now = Instant::now();
let stale = now - ALT_SCREEN_IDLE_REPAINT_AFTER - Duration::from_secs(1); let stale = now - ALT_SCREEN_IDLE_REPAINT_AFTER - Duration::from_secs(1);
let recent = now - Duration::from_secs(1); let recent = now - Duration::from_secs(1);
assert!(should_repaint_idle_alternate_screen( assert!(should_repaint_idle_terminal(
true, stale, stale, now true,
stale,
stale,
Duration::from_secs(1),
now
)); ));
assert!(!should_repaint_idle_alternate_screen( assert!(should_repaint_idle_terminal(
false, stale, stale, now false,
recent,
stale,
LOCAL_SLEEP_REPAINT_AFTER + Duration::from_secs(1),
now
)); ));
assert!(!should_repaint_idle_alternate_screen( assert!(!should_repaint_idle_terminal(
true, recent, stale, now false,
stale,
stale,
Duration::from_secs(1),
now
)); ));
assert!(!should_repaint_idle_alternate_screen( assert!(!should_repaint_idle_terminal(
true, stale, recent, now 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
)); ));
} }