feat(tasks): add --show-timings option for run command

jdx · Jan 26, 2024 · 9c17be8 · 9c17be8
1 parent 91b9fc1
commit 9c17be8
Show file tree

Hide file tree

Showing 12 changed files with 166 additions and 38 deletions.
diff --git a/completions/_mise b/completions/_mise
@@ -584,6 +584,7 @@ __mise_run_cmd() {
     '*'{-t,--tool}'=[Tool(s) to also add e.g.\: node@20 [email protected]]:tool:__mise_tool_versions' \
     '(-j --jobs)'{-j,--jobs}'=[Number of tasks to run in parallel]:jobs:' \
     '(-r --raw)'{-r,--raw}'[Read/write directly to stdin/stdout/stderr instead of by line]' \
+    '--show-timings[Shows elapsed time after each task]' \
     '(-q --quiet)'{-q,--quiet}'[Suppress non-error messages]' \
     '*'{-v,--verbose}'[Show extra output (use -vv for even more)]' \
     '(-y --yes)'{-y,--yes}'[Answer yes to all confirmation prompts]'
@@ -793,6 +794,7 @@ __mise_task_run_cmd() {
     '*'{-t,--tool}'=[Tool(s) to also add e.g.\: node@20 [email protected]]:tool:__mise_tool_versions' \
     '(-j --jobs)'{-j,--jobs}'=[Number of tasks to run in parallel]:jobs:' \
     '(-r --raw)'{-r,--raw}'[Read/write directly to stdin/stdout/stderr instead of by line]' \
+    '--show-timings[Shows elapsed time after each task]' \
     '(-q --quiet)'{-q,--quiet}'[Suppress non-error messages]' \
     '*'{-v,--verbose}'[Show extra output (use -vv for even more)]' \
     '(-y --yes)'{-y,--yes}'[Answer yes to all confirmation prompts]'

diff --git a/completions/mise.bash b/completions/mise.bash
@@ -3738,7 +3738,7 @@ _mise() {
             return 0
             ;;
         mise__run)
-            opts="-C -n -f -p -i -t -j -r -q -v -y -h --cd --dry-run --force --prefix --interleave --tool --jobs --raw --debug --log-level --quiet --trace --verbose --yes --help [TASK] [ARGS]..."
+            opts="-C -n -f -p -i -t -j -r -q -v -y -h --cd --dry-run --force --prefix --interleave --tool --jobs --raw --show-timings --debug --log-level --quiet --trace --verbose --yes --help [TASK] [ARGS]..."
             if [[ ${cur} == -* || ${COMP_CWORD} -eq 2 ]] ; then
                 COMPREPLY=( $(compgen -W "${opts}" -- "${cur}") )
                 return 0
@@ -4509,7 +4509,7 @@ _mise() {
             return 0
             ;;
         mise__task__run)
-            opts="-C -n -f -p -i -t -j -r -q -v -y -h --cd --dry-run --force --prefix --interleave --tool --jobs --raw --debug --log-level --quiet --trace --verbose --yes --help [TASK] [ARGS]..."
+            opts="-C -n -f -p -i -t -j -r -q -v -y -h --cd --dry-run --force --prefix --interleave --tool --jobs --raw --show-timings --debug --log-level --quiet --trace --verbose --yes --help [TASK] [ARGS]..."
             if [[ ${cur} == -* || ${COMP_CWORD} -eq 3 ]] ; then
                 COMPREPLY=( $(compgen -W "${opts}" -- "${cur}") )
                 return 0

diff --git a/docs/cli-reference.md b/docs/cli-reference.md
@@ -936,6 +936,9 @@ Options:
           Read/write directly to stdin/stdout/stderr instead of by line
           Configure with `raw` config or `MISE_RAW` env var
 
+      --show-timings
+          Shows elapsed time after each task
+
 Examples:
   $ mise run lint
   Runs the "lint" task. This needs to either be defined in .mise.toml
@@ -1324,6 +1327,9 @@ Options:
           Read/write directly to stdin/stdout/stderr instead of by line
           Configure with `raw` config or `MISE_RAW` env var
 
+      --show-timings
+          Shows elapsed time after each task
+
 Examples:
   $ mise run lint
   Runs the "lint" task. This needs to either be defined in .mise.toml

diff --git a/src/cli/run.rs b/src/cli/run.rs
@@ -107,6 +107,10 @@ pub struct Run {
     #[clap(long, short, verbatim_doc_comment)]
     pub raw: bool,
 
+    /// Shows elapsed time after each task
+    #[clap(long, verbatim_doc_comment)]
+    pub show_timings: bool,
+
     #[clap(skip)]
     pub is_linear: bool,
 }
@@ -299,18 +303,25 @@ impl Run {
         if self.dry_run {
             return Ok(());
         }
-        if let Err(err) = cmd.execute() {
-            if let Some(ScriptFailed(_, Some(status))) = err.downcast_ref::<Error>() {
-                if let Some(code) = status.code() {
-                    error!("{prefix} exited with code {code}");
-                    exit(code);
-                } else if let Some(signal) = status.signal() {
-                    error!("{prefix} killed by signal {signal}");
-                    exit(1);
+        match cmd.execute() {
+            Ok(stat) => {
+                if self.show_timings {
+                    miseprintln!("elapsed time: {:?}", stat.elapsed())
+                }
+            }
+            Err(err) => {
+                if let Some(ScriptFailed(_, Some(status))) = err.downcast_ref::<Error>() {
+                    if let Some(code) = status.code() {
+                        error!("{prefix} exited with code {code}");
+                        exit(code);
+                    } else if let Some(signal) = status.signal() {
+                        error!("{prefix} killed by signal {signal}");
+                        exit(1);
+                    }
                 }
+                error!("{err}");
+                exit(1);
             }
-            error!("{err}");
-            exit(1);
         }
         trace!("{prefix} exited successfully");
         Ok(())

diff --git a/src/cmd.rs b/src/cmd.rs
@@ -1,11 +1,14 @@
 use std::ffi::{OsStr, OsString};
 use std::fmt::{Display, Formatter};
+use std::io;
 use std::io::{BufRead, BufReader, Write};
+use std::ops::{Deref, DerefMut};
 use std::path::{Path, PathBuf};
-use std::process::{Command, ExitStatus, Stdio};
+use std::process::{Child, Command, ExitStatus, Stdio};
 use std::sync::mpsc::channel;
 use std::sync::{Mutex, RwLock};
 use std::thread;
+use std::time;
 
 use color_eyre::Result;
 use duct::{Expression, IntoExecutablePath};
@@ -223,7 +226,7 @@ impl<'a> CmdLineRunner<'a> {
         self
     }
 
-    pub fn execute(mut self) -> Result<()> {
+    pub fn execute(mut self) -> Result<ExecStatus> {
         static RAW_LOCK: RwLock<()> = RwLock::new(());
         let read_lock = RAW_LOCK.read().unwrap();
         let settings = &Settings::try_get()?;
@@ -233,9 +236,7 @@ impl<'a> CmdLineRunner<'a> {
             let _write_lock = RAW_LOCK.write().unwrap();
             return self.execute_raw();
         }
-        let mut cp = self
-            .cmd
-            .spawn()
+        let mut cp = TimedProcess::spawn(&mut self.cmd)
             .wrap_err_with(|| format!("failed to execute command: {self}"))?;
         let (tx, rx) = channel();
         if let Some(stdout) = cp.stdout.take() {
@@ -311,18 +312,19 @@ impl<'a> CmdLineRunner<'a> {
         let status = status.unwrap();
 
         if !status.success() {
-            self.on_error(combined_output.join("\n"), status)?;
+            self.on_error(combined_output.join("\n"), *status)?;
         }
 
-        Ok(())
+        Ok(status.into())
     }
 
-    fn execute_raw(mut self) -> Result<()> {
-        let status = self.cmd.spawn()?.wait()?;
-        match status.success() {
-            true => Ok(()),
-            false => self.on_error(String::new(), status),
+    fn execute_raw(mut self) -> Result<ExecStatus> {
+        let status = TimedProcess::spawn(&mut self.cmd)?.wait()?;
+        if !status.success() {
+            self.on_error(String::new(), *status)?;
         }
+
+        Ok(status.into())
     }
 
     fn on_stdout(&self, line: &str) {
@@ -394,10 +396,91 @@ impl Display for CmdLineRunner<'_> {
 enum ChildProcessOutput {
     Stdout(String),
     Stderr(String),
-    ExitStatus(ExitStatus),
+    ExitStatus(TimedProcessExitStatus),
     Signal(i32),
 }
 
+struct TimedProcess {
+    proc: Child,
+    instant: time::Instant,
+}
+
+impl TimedProcess {
+    fn spawn(cmd: &mut Command) -> io::Result<TimedProcess> {
+        Ok(Self {
+            proc: cmd.spawn()?,
+            instant: time::Instant::now(),
+        })
+    }
+
+    fn wait(&mut self) -> io::Result<TimedProcessExitStatus> {
+        let status = self.proc.wait()?;
+
+        Ok(TimedProcessExitStatus {
+            status,
+            elapsed: self.instant.elapsed(),
+        })
+    }
+}
+
+impl Deref for TimedProcess {
+    type Target = Child;
+
+    fn deref(&self) -> &Self::Target {
+        &self.proc
+    }
+}
+
+impl DerefMut for TimedProcess {
+    fn deref_mut(&mut self) -> &mut Self::Target {
+        &mut self.proc
+    }
+}
+
+struct TimedProcessExitStatus {
+    pub status: ExitStatus,
+    elapsed: time::Duration,
+}
+
+impl TimedProcessExitStatus {
+    pub fn elapsed(&self) -> time::Duration {
+        self.elapsed
+    }
+}
+
+impl Deref for TimedProcessExitStatus {
+    type Target = ExitStatus;
+
+    fn deref(&self) -> &Self::Target {
+        &self.status
+    }
+}
+
+impl DerefMut for TimedProcessExitStatus {
+    fn deref_mut(&mut self) -> &mut Self::Target {
+        &mut self.status
+    }
+}
+
+#[derive(Debug, Clone)]
+pub struct ExecStatus {
+    elapsed: time::Duration,
+}
+
+impl ExecStatus {
+    pub fn elapsed(&self) -> time::Duration {
+        self.elapsed
+    }
+}
+
+impl From<TimedProcessExitStatus> for ExecStatus {
+    fn from(status: TimedProcessExitStatus) -> Self {
+        Self {
+            elapsed: status.elapsed(),
+        }
+    }
+}
+
 #[cfg(test)]
 mod tests {
     use crate::cmd;

diff --git a/src/plugins/core/bun.rs b/src/plugins/core/bun.rs
@@ -54,7 +54,9 @@ impl BunPlugin {
         CmdLineRunner::new(self.bun_bin(&ctx.tv))
             .with_pr(ctx.pr.as_ref())
             .arg("-v")
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn download(&self, tv: &ToolVersion, pr: &dyn SingleReport) -> Result<PathBuf> {

diff --git a/src/plugins/core/deno.rs b/src/plugins/core/deno.rs
@@ -58,7 +58,9 @@ impl DenoPlugin {
         CmdLineRunner::new(self.deno_bin(tv))
             .with_pr(pr)
             .arg("-V")
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn download(&self, tv: &ToolVersion, pr: &dyn SingleReport) -> Result<PathBuf> {

diff --git a/src/plugins/core/go.rs b/src/plugins/core/go.rs
@@ -94,7 +94,9 @@ impl GoPlugin {
         CmdLineRunner::new(self.go_bin(tv))
             .with_pr(pr)
             .arg("version")
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn download(&self, tv: &ToolVersion, pr: &dyn SingleReport) -> Result<PathBuf> {

diff --git a/src/plugins/core/java.rs b/src/plugins/core/java.rs
@@ -121,7 +121,9 @@ impl JavaPlugin {
             .with_pr(pr)
             .env("JAVA_HOME", tv.install_path())
             .arg("-version")
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn download(

diff --git a/src/plugins/core/node.rs b/src/plugins/core/node.rs
@@ -134,13 +134,19 @@ impl NodePlugin {
     }
 
     fn exec_configure(&self, ctx: &InstallContext, opts: &BuildOpts) -> Result<()> {
-        self.sh(ctx, opts)?.arg(&opts.configure_cmd).execute()
+        self.sh(ctx, opts)?.arg(&opts.configure_cmd).execute()?;
+
+        Ok(())
     }
     fn exec_make(&self, ctx: &InstallContext, opts: &BuildOpts) -> Result<()> {
-        self.sh(ctx, opts)?.arg(&opts.make_cmd).execute()
+        self.sh(ctx, opts)?.arg(&opts.make_cmd).execute()?;
+
+        Ok(())
     }
     fn exec_make_install(&self, ctx: &InstallContext, opts: &BuildOpts) -> Result<()> {
-        self.sh(ctx, opts)?.arg(&opts.make_install_cmd).execute()
+        self.sh(ctx, opts)?.arg(&opts.make_install_cmd).execute()?;
+
+        Ok(())
     }
 
     fn verify(&self, tarball: &Path, version: &str) -> Result<()> {
@@ -214,7 +220,9 @@ impl NodePlugin {
             .with_pr(pr)
             .arg("-v")
             .envs(config.env()?)
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn test_npm(&self, config: &Config, tv: &ToolVersion, pr: &dyn SingleReport) -> Result<()> {
@@ -224,7 +232,9 @@ impl NodePlugin {
             .with_pr(pr)
             .arg("-v")
             .envs(config.env()?)
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn shasums_url(&self, v: &str) -> Result<Url> {

diff --git a/src/plugins/core/python.rs b/src/plugins/core/python.rs
@@ -214,7 +214,9 @@ impl PythonPlugin {
             .arg("-r")
             .arg(packages_file)
             .envs(config.env()?)
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn get_virtualenv(
@@ -289,7 +291,9 @@ impl PythonPlugin {
         CmdLineRunner::new(self.python_path(tv))
             .arg("--version")
             .envs(config.env()?)
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 }
 

diff --git a/src/plugins/core/ruby.rs b/src/plugins/core/ruby.rs
@@ -209,7 +209,9 @@ impl RubyPlugin {
             .with_pr(pr)
             .arg("-v")
             .envs(config.env()?)
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn test_gem(&self, config: &Config, tv: &ToolVersion, pr: &dyn SingleReport) -> Result<()> {
@@ -219,7 +221,9 @@ impl RubyPlugin {
             .arg("-v")
             .envs(config.env()?)
             .env("PATH", CorePlugin::path_env_with_tv_path(tv)?)
-            .execute()
+            .execute()?;
+
+        Ok(())
     }
 
     fn ruby_build_version(&self) -> Result<String> {