Compare commits

...

3 Commits

Author SHA1 Message Date
DuProcess fdbd58b628 Fetch remote server trace reports
ci / test (push) Waiting to run
ci / fuzz-smoke (push) Waiting to run
ci / windows-client (push) Waiting to run
ci / package-release (linux-x86_64, ubuntu-latest) (push) Waiting to run
ci / package-release (macos-aarch64, macos-14) (push) Waiting to run
ci / package-release (macos-x86_64, macos-13) (push) Waiting to run
ci / package-release (windows-x86_64, windows-latest) (push) Waiting to run
ci / remote-bench (push) Waiting to run
2026-07-12 11:55:23 -04:00
DuProcess c65aba9d7a Repaint terminal after local sleep
ci / test (push) Waiting to run
ci / fuzz-smoke (push) Waiting to run
ci / windows-client (push) Waiting to run
ci / package-release (linux-x86_64, ubuntu-latest) (push) Waiting to run
ci / package-release (macos-aarch64, macos-14) (push) Waiting to run
ci / package-release (macos-x86_64, macos-13) (push) Waiting to run
ci / package-release (windows-x86_64, windows-latest) (push) Waiting to run
ci / remote-bench (push) Waiting to run
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
4 changed files with 268 additions and 75 deletions
Generated
+1 -1
View File
@@ -436,7 +436,7 @@ dependencies = [
[[package]]
name = "dosh"
version = "1.0.0-rc32"
version = "1.0.0-rc34"
dependencies = [
"anyhow",
"base64",
+1 -1
View File
@@ -1,6 +1,6 @@
[package]
name = "dosh"
version = "1.0.0-rc32"
version = "1.0.0-rc34"
edition = "2024"
license = "MIT"
+5 -4
View File
@@ -85,12 +85,13 @@ 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. Trace byte prefixes are enabled for `dosh trace`, so use
it only for short reproductions.
## VS Code
+253 -61
View File
@@ -74,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 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
@@ -791,8 +792,9 @@ 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,
}
@@ -887,15 +889,16 @@ 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 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] [--tail N]")
})?;
client_log = Some(expand_tilde(path));
index += 2;
@@ -910,7 +913,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] [--tail N]")
})?;
server_log = parse_optional_trace_path(path);
index += 2;
@@ -928,7 +931,7 @@ fn parse_trace_report_options(command: &[String]) -> Result<TraceReportOptions>
}
"--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] [--tail N]")
})?;
tail = parse_trace_tail(value)?;
index += 2;
@@ -940,25 +943,35 @@ 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] [--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] [--tail N]"
));
}
host = Some(value.to_string());
index += 1;
}
}
}
Ok(TraceReportOptions {
host,
client_log,
server_log,
tail,
})
}
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())
}
}
@@ -1005,7 +1018,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() {
@@ -1041,7 +1055,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),
@@ -1060,6 +1078,20 @@ fn run_trace_report_command(command: &[String]) -> Result<()> {
);
}
if let Some(path) = options.server_log {
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(&path, options.tail) {
Ok(report) => print_trace_report("server", &report),
Err(err)
@@ -1075,6 +1107,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"))
@@ -5506,6 +5598,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)?;
@@ -5634,13 +5727,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",
&[
@@ -5649,7 +5743,6 @@ async fn run_terminal(
("summary", dosh::trace::bytes_summary(&bytes)),
],
);
}
if bytes.is_empty() {
continue;
}
@@ -6488,6 +6581,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(
@@ -6508,6 +6605,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(
@@ -6550,13 +6649,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,
@@ -6983,6 +7091,20 @@ fn should_strip_unowned_terminal_reports(alternate_screen: bool, 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 {
contains_bytes(bytes, b"\x1b[I") || contains_bytes(bytes, b"\x9bI")
}
@@ -7007,14 +7129,16 @@ 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
}
@@ -8958,32 +9082,33 @@ 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,
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,
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, trace_report_warnings, unix_update_script,
update_installer_url, update_version_status, upsert_managed_block, valid_forward_host,
vscode_safe_alias, windows_update_script,
FRAME_GAP_RESYNC_AFTER_MS, FrameBuffer, LOCAL_SLEEP_REPAINT_AFTER, 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, ensure_tui_safe_status_overlay,
expand_ssh_path_tokens, input_contains_focus_in, input_matches_escape,
is_local_status_target, is_resume_response_for_client, latest_release_download_url,
load_first_native_identity_with_prompt, native_proxy_udp_warning, parse_dynamic_forward,
parse_escape_key, parse_local_forward, parse_remote_forward, parse_ssh_config,
parse_trace_line, parse_trace_options, parse_trace_report_options, parse_trace_summary,
parse_update_options, post_submit_hold_duration, queue_pending_user_input,
queue_stale_pending_user_input, raw_contains_host_table, recv_response_until,
refresh_live_addr, release_tag_download_url, release_tag_from_effective_url,
release_version_from_tag, render_status_clear, render_status_overlay, requested_env,
resolved_startup_command, retire_stream_state, retransmit_stream_opens,
rewrite_forward_command, sanitize_trace_name, selected_predict_mode, selected_udp_host,
server_version_mismatch, should_flush_terminal_input_after_contact,
should_hold_during_startup_gate, should_hold_post_submit_input,
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, 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;
@@ -10290,27 +10415,30 @@ 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);
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(),
"--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);
let parsed = parse_trace_report_options(&["--server-log=none".to_string()]).unwrap();
assert_eq!(parsed.server_log, None);
}
#[test]
@@ -10817,6 +10945,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)]
@@ -10924,21 +11093,44 @@ 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
));
}