Gate client timing logs behind verbosity
ci / test (push) Has been cancelled
ci / remote-bench (push) Has been cancelled

This commit is contained in:
Codex
2026-06-11 09:45:55 -04:00
parent 0eca4f1cf4
commit da60b71984
2 changed files with 32 additions and 24 deletions
+30 -23
View File
@@ -1,7 +1,7 @@
use anyhow::{Context, Result, anyhow}; use anyhow::{Context, Result, anyhow};
use base64::Engine; use base64::Engine;
use base64::engine::general_purpose::URL_SAFE_NO_PAD; use base64::engine::general_purpose::URL_SAFE_NO_PAD;
use clap::Parser; use clap::{ArgAction, Parser};
use crossterm::terminal::{disable_raw_mode, enable_raw_mode, size}; use crossterm::terminal::{disable_raw_mode, enable_raw_mode, size};
use dosh::auth::{ use dosh::auth::{
BootstrapResponse, build_bootstrap, decode_bootstrap, load_or_create_server_secret, BootstrapResponse, build_bootstrap, decode_bootstrap, load_or_create_server_secret,
@@ -53,6 +53,8 @@ struct Args {
dosh_port: Option<u16>, dosh_port: Option<u16>,
#[arg(long)] #[arg(long)]
dosh_host: Option<String>, dosh_host: Option<String>,
#[arg(short, long, action = ArgAction::Count)]
verbose: u8,
} }
#[derive(Debug, Clone, Serialize, Deserialize)] #[derive(Debug, Clone, Serialize, Deserialize)]
@@ -116,16 +118,10 @@ async fn main() -> Result<()> {
if let Some(mut cached) = credential.clone() { if let Some(mut cached) = credential.clone() {
cached.udp_host = target_udp_host.clone(); cached.udp_host = target_udp_host.clone();
cached.udp_port = dosh_port; cached.udp_port = dosh_port;
eprintln!( log_timing(args.verbose, "credential_lookup_end", started.elapsed());
"dosh timing credential_lookup_end={}ms",
started.elapsed().as_millis()
);
match try_resume(&socket, &cached, cols, rows).await { match try_resume(&socket, &cached, cols, rows).await {
Ok((frame, cred)) => { Ok((frame, cred)) => {
eprintln!( log_timing(args.verbose, "udp_resume_ready", started.elapsed());
"dosh timing udp_resume_ready={}ms",
started.elapsed().as_millis()
);
if !args.no_cache { if !args.no_cache {
save_cache(&cache_path, &cred)?; save_cache(&cache_path, &cred)?;
} }
@@ -137,14 +133,15 @@ async fn main() -> Result<()> {
return run_terminal(socket, cred, Some(frame)).await; return run_terminal(socket, cred, Some(frame)).await;
} }
Err(err) => { Err(err) => {
eprintln!("dosh resume failed, trying ticket attach before SSH: {err:#}"); log_debug(
args.verbose,
2,
&format!("dosh resume failed, trying ticket attach before SSH: {err:#}"),
);
if config.cache_attach_tickets && !args.no_cache { if config.cache_attach_tickets && !args.no_cache {
match try_ticket_attach(&socket, &cached, cols, rows).await { match try_ticket_attach(&socket, &cached, cols, rows).await {
Ok((frame, cred)) => { Ok((frame, cred)) => {
eprintln!( log_timing(args.verbose, "udp_ticket_attach_ready", started.elapsed());
"dosh timing udp_ticket_attach_ready={}ms",
started.elapsed().as_millis()
);
save_cache(&cache_path, &cred)?; save_cache(&cache_path, &cred)?;
if args.attach_only { if args.attach_only {
render_frame(&frame)?; render_frame(&frame)?;
@@ -154,8 +151,12 @@ async fn main() -> Result<()> {
return run_terminal(socket, cred, Some(frame)).await; return run_terminal(socket, cred, Some(frame)).await;
} }
Err(err) => { Err(err) => {
eprintln!( log_debug(
args.verbose,
2,
&format!(
"dosh ticket attach failed, falling back to SSH bootstrap: {err:#}" "dosh ticket attach failed, falling back to SSH bootstrap: {err:#}"
),
); );
} }
} }
@@ -184,20 +185,14 @@ async fn main() -> Result<()> {
bootstrap.udp_port = dosh_port; bootstrap.udp_port = dosh_port;
bootstrap bootstrap
}; };
eprintln!( log_timing(args.verbose, "ssh_bootstrap", bootstrap_start.elapsed());
"dosh timing ssh_bootstrap={}ms",
bootstrap_start.elapsed().as_millis()
);
let (ok, mut cred) = bootstrap_attach(&socket, &server, &bootstrap, cols, rows).await?; let (ok, mut cred) = bootstrap_attach(&socket, &server, &bootstrap, cols, rows).await?;
cred.last_rendered_seq = ok.initial_seq; cred.last_rendered_seq = ok.initial_seq;
if !args.no_cache { if !args.no_cache {
save_cache(&cache_path, &cred)?; save_cache(&cache_path, &cred)?;
} }
eprintln!( log_timing(args.verbose, "terminal_ready", started.elapsed());
"dosh timing terminal_ready={}ms",
started.elapsed().as_millis()
);
let first = Frame { let first = Frame {
session: ok.session, session: ok.session,
output_seq: ok.initial_seq, output_seq: ok.initial_seq,
@@ -238,6 +233,18 @@ fn local_bootstrap(
) )
} }
fn log_timing(verbose: u8, name: &str, elapsed: Duration) {
if verbose >= 1 {
eprintln!("dosh timing {name}={}ms", elapsed.as_millis());
}
}
fn log_debug(verbose: u8, level: u8, message: &str) {
if verbose >= level {
eprintln!("{message}");
}
}
fn select_session(requested: Option<&str>, force_new: bool, configured_default: &str) -> String { fn select_session(requested: Option<&str>, force_new: bool, configured_default: &str) -> String {
if let Some(session) = requested { if let Some(session) = requested {
return session.to_string(); return session.to_string();
+1
View File
@@ -68,6 +68,7 @@ fn attach_once(dir: &tempfile::TempDir, port: u16, cache: bool) -> std::process:
let mut cmd = Command::new(client); let mut cmd = Command::new(client);
cmd.arg("--local-auth") cmd.arg("--local-auth")
.arg("--attach-only") .arg("--attach-only")
.arg("-v")
.arg("--session") .arg("--session")
.arg("default") .arg("default")
.arg("--dosh-port") .arg("--dosh-port")