From 3dc6d82b980be9b974f8123190f8b8f1aaec8ed1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E4=B8=89=E5=92=B2=E9=9B=85=20=C2=B7=20Misaki=20Masa?= Date: Wed, 5 Mar 2025 14:43:20 +0800 Subject: [PATCH] feat: log `tmux` call execution time to logs (#2444) --- Cargo.lock | 20 ++++++++++---------- yazi-adapter/src/brand.rs | 12 ++++++------ yazi-adapter/src/emulator.rs | 15 +++++++++++---- yazi-adapter/src/mux.rs | 26 ++++++++++++++++++-------- yazi-fm/src/term.rs | 4 +++- yazi-macro/src/lib.rs | 1 + yazi-macro/src/log.rs | 19 +++++++++++++++++++ 7 files changed, 68 insertions(+), 29 deletions(-) create mode 100644 yazi-macro/src/log.rs diff --git a/Cargo.lock b/Cargo.lock index 35a68c7c..db0466ad 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -313,9 +313,9 @@ checksum = "8f1fe948ff07f4bd06c30984e69f5b4899c516a3ef74f34df92a2df2ab535495" [[package]] name = "bytes" -version = "1.10.0" +version = "1.10.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f61dac84819c6588b558454b194026eb1f09c293b9036ae9b159e74e73ab6cf9" +checksum = "d71b6127be86fdcfddb610f7182ac57211d4b18a3e9c82eb2d17662f2227ad6a" [[package]] name = "cassowary" @@ -708,9 +708,9 @@ dependencies = [ [[package]] name = "either" -version = "1.14.0" +version = "1.15.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b7914353092ddf589ad78f25c5c1c21b7f80b0ff8621e7c814c3485b5306da9d" +checksum = "48c757948c5ede0e46177b7add2e67155f70e33c07fea8284df6576da70b3719" [[package]] name = "encode_unicode" @@ -2595,9 +2595,9 @@ dependencies = [ [[package]] name = "time" -version = "0.3.37" +version = "0.3.38" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "35e7868883861bd0e56d9ac6efcaaca0d6d5d82a2a7ec8209ff492c07cf37b21" +checksum = "bb041120f25f8fbe8fd2dbe4671c7c2ed74d83be2e7a77529bf7e0790ae3f472" dependencies = [ "deranged", "itoa", @@ -2612,15 +2612,15 @@ dependencies = [ [[package]] name = "time-core" -version = "0.1.2" +version = "0.1.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ef927ca75afb808a4d64dd374f00a2adf8d0fcff8e7b184af886c3c87ec4a3f3" +checksum = "765c97a5b985b7c11d7bc27fa927dc4fe6af3a6dfb021d28deb60d3bf51e76ef" [[package]] name = "time-macros" -version = "0.2.19" +version = "0.2.20" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2834e6017e3e5e4b9834939793b282bc03b37a3336245fa820e35e233e2a85de" +checksum = "e8093bc3e81c3bc5f7879de09619d06c9a5a5e45ca44dfeeb7225bae38005c5c" dependencies = [ "num-conv", "time-core", diff --git a/yazi-adapter/src/brand.rs b/yazi-adapter/src/brand.rs index 72851994..f9f6bef6 100644 --- a/yazi-adapter/src/brand.rs +++ b/yazi-adapter/src/brand.rs @@ -1,4 +1,4 @@ -use tracing::warn; +use tracing::debug; use yazi_shared::env_exists; use crate::Mux; @@ -63,7 +63,7 @@ impl Brand { "xterm-ghostty" => return Some(B::Ghostty), "rio" => return Some(B::Rio), "rxvt-unicode-256color" => return Some(B::Urxvt), - _ => warn!("[Adapter] Unknown TERM: {term}"), + _ => {} } match program.as_str() { "iTerm.app" => return Some(B::Iterm2), @@ -76,11 +76,11 @@ impl Brand { "Hyper" => return Some(B::Hyper), "mintty" => return Some(B::Mintty), "Apple_Terminal" => return Some(B::Apple), - _ => warn!("[Adapter] Unknown TERM_PROGRAM: {program}"), + _ => {} } - match vars.into_iter().find(|&(s, _)| env_exists(s)) { - Some((_, brand)) => return Some(brand), - None => warn!("[Adapter] No special environment variables detected"), + if let Some((var, brand)) = vars.into_iter().find(|&(s, _)| env_exists(s)) { + debug!("Detected special environment variable: {var}"); + return Some(brand); } None diff --git a/yazi-adapter/src/emulator.rs b/yazi-adapter/src/emulator.rs index 9939eda9..6b258387 100644 --- a/yazi-adapter/src/emulator.rs +++ b/yazi-adapter/src/emulator.rs @@ -106,7 +106,9 @@ impl Emulator { } pub fn read_until_da1() -> String { + let now = std::time::Instant::now(); let h = tokio::spawn(Self::error_to_user()); + let (buf, result) = AsyncStdin::default().read_until(Duration::from_millis(500), |b, buf| { b == b'c' && buf.contains(&0x1b) @@ -115,21 +117,26 @@ impl Emulator { h.abort(); match result { - Ok(()) => debug!("read_until_da1: {buf:?}"), - Err(e) => error!("read_until_da1 failed: {buf:?}, error: {e:?}"), + Ok(()) => debug!("Terminal responded to DA1 in {:?}: {buf:?}", now.elapsed()), + Err(e) => { + error!("Terminal failed to respond to DA1 in {:?}: {buf:?}, error: {e:?}", now.elapsed()) + } } String::from_utf8_lossy(&buf).into_owned() } pub fn read_until_dsr() -> String { + let now = std::time::Instant::now(); let (buf, result) = AsyncStdin::default().read_until(Duration::from_millis(100), |b, buf| { b == b'n' && (buf.ends_with(b"\x1b[0n") || buf.ends_with(b"\x1b[3n")) }); match result { - Ok(()) => debug!("read_until_dsr: {buf:?}"), - Err(e) => error!("read_until_dsr failed: {buf:?}, error: {e:?}"), + Ok(()) => debug!("Terminal responded to DSR in {:?}: {buf:?}", now.elapsed()), + Err(e) => { + error!("Terminal failed to respond to DSR in {:?}: {buf:?}, error: {e:?}", now.elapsed()) + } } String::from_utf8_lossy(&buf).into_owned() } diff --git a/yazi-adapter/src/mux.rs b/yazi-adapter/src/mux.rs index 282b6497..2eb2c1ae 100644 --- a/yazi-adapter/src/mux.rs +++ b/yazi-adapter/src/mux.rs @@ -1,5 +1,6 @@ use anyhow::Result; use tracing::error; +use yazi_macro::time; use crate::{CLOSE, ESCAPE, Emulator, START, TMUX}; @@ -18,14 +19,18 @@ impl Mux { } pub fn tmux_passthrough() { - let child = std::process::Command::new("tmux") - .args(["set", "-p", "allow-passthrough", "on"]) - .stdin(std::process::Stdio::null()) - .stdout(std::process::Stdio::null()) - .stderr(std::process::Stdio::piped()) - .spawn(); + let output = time!( + "Running `tmux set -p allow-passthrough on`", + std::process::Command::new("tmux") + .args(["set", "-p", "allow-passthrough", "on"]) + .stdin(std::process::Stdio::null()) + .stdout(std::process::Stdio::null()) + .stderr(std::process::Stdio::piped()) + .spawn() + .and_then(|c| c.wait_with_output()) + ); - match child.and_then(|c| c.wait_with_output()) { + match output { Ok(o) if o.status.success() => {} Ok(o) => { error!( @@ -68,9 +73,14 @@ impl Mux { if !TMUX.get() { return (term, program); } - let Ok(output) = std::process::Command::new("tmux").arg("show-environment").output() else { + + let Ok(output) = time!( + "Running `tmux show-environment`", + std::process::Command::new("tmux").arg("show-environment").output() + ) else { return (term, program); }; + for line in String::from_utf8_lossy(&output.stdout).lines() { if let Some((k, v)) = line.trim().split_once('=') { match k { diff --git a/yazi-fm/src/term.rs b/yazi-fm/src/term.rs index ef5af731..c1539bdc 100644 --- a/yazi-fm/src/term.rs +++ b/yazi-fm/src/term.rs @@ -6,6 +6,7 @@ use cursor::RestoreCursor; use ratatui::{CompletedFrame, Frame, Terminal, backend::CrosstermBackend, buffer::Buffer, layout::Rect}; use yazi_adapter::{Emulator, Mux}; use yazi_config::{INPUT, MGR}; +use yazi_shared::SyncCell; static CSI_U: AtomicBool = AtomicBool::new(false); static BLINK: AtomicBool = AtomicBool::new(false); @@ -19,6 +20,7 @@ pub(super) struct Term { impl Term { pub(super) fn start() -> Result { + static SKIP: SyncCell = SyncCell::new(false); let mut term = Self { inner: Terminal::new(CrosstermBackend::new(BufWriter::new(stderr())))?, last_area: Default::default(), @@ -26,7 +28,7 @@ impl Term { }; enable_raw_mode()?; - if yazi_adapter::TMUX.get() { + if SKIP.replace(true) && yazi_adapter::TMUX.get() { yazi_adapter::Mux::tmux_passthrough(); } diff --git a/yazi-macro/src/lib.rs b/yazi-macro/src/lib.rs index 624c20f7..39658539 100644 --- a/yazi-macro/src/lib.rs +++ b/yazi-macro/src/lib.rs @@ -1,5 +1,6 @@ mod asset; mod event; +mod log; mod module; mod platform; mod stdio; diff --git a/yazi-macro/src/log.rs b/yazi-macro/src/log.rs new file mode 100644 index 00000000..3770bfeb --- /dev/null +++ b/yazi-macro/src/log.rs @@ -0,0 +1,19 @@ +#[macro_export] +macro_rules! time { + ($expr:expr) => { + $crate::time!(stringify!($expr), $expr) + }; + ($label:expr, $expr:expr) => { + $crate::time!($expr, "{}", $label) + }; + ($expr:expr, $fmt:expr, $($args:tt)*) => {{ + if tracing::enabled!(tracing::Level::DEBUG) { + let start = std::time::Instant::now(); + let result = $expr; + tracing::debug!("{} took {:?}", format_args!($fmt, $($args)*), start.elapsed()); + result + } else { + $expr + } + }}; +}