perf: improve shim loading (#2828)

src/backend/mod.rs

@@ -110,7 +110,7 @@ fn load_tools() -> BackendMap {
         .map(|plugin| (plugin.id().to_string(), plugin))
         .collect();
     *TOOLS.lock().unwrap() = Some(tools.clone());
-    time!("load_tools", "done");
+    time!("load_tools done");
     tools
 }
 

src/cli/doctor.rs

@@ -189,7 +189,7 @@ impl Doctor {
                 ));
             }
         }
-        time!("doctor::analyze_shims: {:?}");
+        time!("doctor::analyze_shims");
     }
 
     fn analyze_plugins(&mut self) {

src/cli/mod.rs

@@ -206,7 +206,7 @@ impl Cli {
         time!("run init");
         shims::handle_shim()?;
         time!("run handle_shim");
-        ctrlc::init()?;
+        ctrlc::init();
         version::print_version_if_requested(args)?;
 
         let matches = CLI.clone().try_get_matches_from(args).unwrap_or_else(|_| {

src/config/mod.rs

@@ -262,12 +262,7 @@ impl Config {
             })
             .map(|t| (t.name.clone(), t))
             .collect();
-        time!(
-            "load_all_tasks",
-            "{count} {tasks}",
-            count = tasks.len(),
-            tasks = if tasks.len() == 1 { "task" } else { "tasks" },
-        );
+        time!("load_all_tasks {count}", count = tasks.len(),);
         Ok(tasks)
     }
 

src/logger.rs

@@ -74,7 +74,7 @@ impl Logger {
             LevelFilter::Trace => {
                 let meta = ui::style::edim(format!(
                     "{thread_id:>2} [{file}:{line}]",
-                    thread_id = self.thread_id(),
+                    thread_id = thread_id(),
                     file = record.file().unwrap_or("<unknown>"),
                     line = record.line().unwrap_or(0),
                 ));
@@ -108,12 +108,6 @@ impl Logger {
         }
     }
 
-    fn thread_id(&self) -> String {
-        let id = format!("{:?}", thread::current().id());
-        let id = id.replace("ThreadId(", "");
-        id.replace(")", "")
-    }
-
     fn styled_level(&self, level: Level) -> String {
         let level = match level {
             Level::Error => ui::style::ered("ERROR").to_string(),
@@ -126,6 +120,12 @@ impl Logger {
     }
 }
 
+pub fn thread_id() -> String {
+    let id = format!("{:?}", thread::current().id());
+    let id = id.replace("ThreadId(", "");
+    id.replace(")", "")
+}
+
 pub fn init() {
     static INIT: std::sync::Once = std::sync::Once::new();
     INIT.call_once(|| {

src/main.rs

@@ -62,7 +62,8 @@ mod versions_host;
 pub use crate::exit::exit;
 
 fn main() -> eyre::Result<()> {
-    output::get_time_diff("", ""); // throwaway call to initialize the timer
+    #[cfg(feature = "timings")]
+    output::get_time_diff(""); // throwaway call to initialize the timer
     eager::early_init();
     let args = env::args().collect_vec();
     color_eyre::install()?;

src/output.rs

@@ -96,7 +96,7 @@ macro_rules! info {
 }
 
 #[cfg(feature = "timings")]
-pub fn get_time_diff(module: &str, extra: &str) -> String {
+pub fn get_time_diff(module: &str) -> String {
     static PREV: std::sync::Mutex<Option<std::time::Instant>> = std::sync::Mutex::new(None);
     let now = std::time::Instant::now();
     if PREV.lock().unwrap().is_none() {
@@ -106,7 +106,8 @@ pub fn get_time_diff(module: &str, extra: &str) -> String {
     let diff = now.duration_since(prev.unwrap());
     *prev = Some(now);
     let diff_str = crate::ui::time::format_duration(diff);
-    let out = format!("[TIME] {module} {diff_str} {extra}")
+    let thread_id = crate::logger::thread_id();
+    let out = format!("[TIME] {thread_id} {module} {diff_str}")
         .trim()
         .to_string();
     if diff.as_micros() > 8000 {
@@ -118,39 +119,33 @@ pub fn get_time_diff(module: &str, extra: &str) -> String {
     } else if diff.as_micros() > 1000 {
         style::eyellow(out).bright()
     } else if diff.as_micros() > 500 {
-        style::eyellow(out)
+        style::eyellow(out).dim()
     } else if diff.as_micros() > 100 {
-        style::ecyan(out)
+        style::ecyan(out).dim()
     } else {
         style::edim(out)
     }
     .to_string()
 }
 
-#[cfg(not(feature = "timings"))]
-pub fn get_time_diff(_module: &str, _extra: &str) -> String {
-    "".to_string()
-}
-
 #[macro_export]
 #[cfg(feature = "timings")]
 macro_rules! time {
     () => {{
         if *$crate::env::MISE_TIMINGS {
-            eprintln!("{}", $crate::output::get_time_diff(module_path!(), ""));
+            eprintln!("{}", $crate::output::get_time_diff(module_path!()));
         }
     }};
     ($fn:expr) => {{
         if *$crate::env::MISE_TIMINGS {
-            let module = format!("{}::{}", module_path!(), $fn);
-            eprintln!("{}", $crate::output::get_time_diff(&module, ""));
+            let module = format!("{}::{}", module_path!(), format!($fn));
+            eprintln!("{}", $crate::output::get_time_diff(&module));
         }
     }};
     ($fn:expr, $($arg:tt)+) => {{
         if *$crate::env::MISE_TIMINGS {
-            let module = format!("{}::{}", module_path!(), $fn);
-            let extra = format!($($arg)+);
-            eprintln!("{}", $crate::output::get_time_diff(&module, &extra));
+            let module = format!("{}::{}", module_path!(), format!($fn, $($arg)+));
+            eprintln!("{}", $crate::output::get_time_diff(&module));
         }
     }};
 }

src/shims.rs

@@ -17,13 +17,12 @@ use eyre::WrapErr;
 use indoc::formatdoc;
 use itertools::Itertools;
 use rayon::prelude::*;
-use xx::regex;
 
 // executes as if it was a shim if the command is not "mise", e.g.: "node"
 pub fn handle_shim() -> Result<()> {
     // TODO: instead, check if bin is in shims dir
     let bin_name = *env::MISE_BIN_NAME;
-    if regex!(r"^(mise|rtx)(\-.*)?(\.exe)?$").is_match(bin_name) || cfg!(test) {
+    if bin_name.starts_with("mise") || cfg!(test) {
         return Ok(());
     }
     logger::init();
@@ -174,7 +173,7 @@ pub fn get_shim_diffs(
         desired_shims.difference(&actual_shims).cloned().collect(),
         actual_shims.difference(&desired_shims).cloned().collect(),
     );
-    time!("get_shim_diffs", "sizes: ({},{})", out.0.len(), out.1.len());
+    time!("get_shim_diffs sizes: ({},{})", out.0.len(), out.1.len());
     Ok(out)
 }
 

src/toolset/builder.rs

@@ -44,7 +44,7 @@ impl ToolsetBuilder {
             warn!("failed to resolve toolset: {err:#}");
         }
 
-        time!("toolset::builder::build", "{toolset}");
+        time!("toolset::builder::build");
         Ok(toolset)
     }
 

src/toolset/tool_request_set.rs

@@ -148,7 +148,7 @@ impl ToolRequestSetBuilder {
             }
         }
 
-        time!("tool_request_set::build", "{trs}");
+        time!("tool_request_set::build");
         Ok(trs)
     }
 

src/ui/ctrlc.rs

@@ -1,42 +1,36 @@
 use crate::exit;
-use once_cell::sync::OnceCell;
 use std::sync::atomic::{AtomicBool, Ordering};
 use std::thread;
 
 use crate::cmd::CmdLineRunner;
 use console::Term;
 use signal_hook::consts::SIGINT;
-use signal_hook::iterator::{Handle, Signals};
+use signal_hook::iterator::Signals;
 
 static EXIT: AtomicBool = AtomicBool::new(true);
 static SHOW_CURSOR: AtomicBool = AtomicBool::new(false);
 // static HANDLERS: OnceCell<Vec<Box<dyn Fn() + Send + Sync + 'static>>> = OnceCell::new();
 
-pub fn init() -> eyre::Result<()> {
-    static HANDLE: OnceCell<Handle> = OnceCell::new();
-    HANDLE.get_or_try_init(|| {
-        let mut signals = Signals::new([SIGINT])?;
-        let handle = signals.handle();
-        thread::spawn(move || {
-            if let Some(_signal) = signals.into_iter().next() {
-                if SHOW_CURSOR.load(Ordering::Relaxed) {
-                    let _ = Term::stderr().show_cursor();
-                }
-                // for handler in HANDLERS.get().unwrap_or(&Vec::new()) {
-                //     handler();
-                // }
-                CmdLineRunner::kill_all(nix::sys::signal::SIGINT);
-                if EXIT.swap(true, Ordering::Relaxed) {
-                    debug!("Ctrl-C pressed, exiting...");
-                    exit(1);
-                } else {
-                    warn!("Ctrl-C pressed, please wait for tasks to finish or press Ctrl-C again to force exit");
-                }
+pub fn init() {
+    thread::spawn(move || {
+        let mut signals = Signals::new([SIGINT]).unwrap();
+        let _handle = signals.handle();
+        if let Some(_signal) = signals.into_iter().next() {
+            if SHOW_CURSOR.load(Ordering::Relaxed) {
+                let _ = Term::stderr().show_cursor();
             }
-        });
-        Ok::<_, eyre::Error>(handle)
-    })?;
-    Ok(())
+            // for handler in HANDLERS.get().unwrap_or(&Vec::new()) {
+            //     handler();
+            // }
+            CmdLineRunner::kill_all(nix::sys::signal::SIGINT);
+            if EXIT.swap(true, Ordering::Relaxed) {
+                debug!("Ctrl-C pressed, exiting...");
+                exit(1);
+            } else {
+                warn!("Ctrl-C pressed, please wait for tasks to finish or press Ctrl-C again to force exit");
+            }
+        }
+    });
 }
 
 // pub fn add_handler(func: impl Fn() + Send + Sync + 'static) {

src/ui/ctrlc_stub.rs

@@ -1,6 +1,4 @@
-pub fn init() -> eyre::Result<()> {
-    Ok(())
-}
+pub fn init() {}
 
 // pub fn add_handler(_func: impl Fn() + Send + Sync + 'static) {}
 

src/ui/time.rs

@@ -1,7 +1,11 @@
-pub fn format_duration(dur: std::time::Duration) -> String {
-    if dur < std::time::Duration::from_secs(1) {
-        format!("{:.0?}", dur)
+use std::time::Duration;
+
+pub fn format_duration(dur: Duration) -> String {
+    if dur < Duration::from_millis(1) {
+        format!("{dur:.0?}")
+    } else if dur < Duration::from_secs(1) {
+        format!("{dur:.1?}")
     } else {
-        format!("{:.2?}", dur)
+        format!("{dur:.2?}")
     }
 }