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

[Ajpantuso]

Summary

Closed #1265

Adds a --show-timings option to the mise run command to display elapsed time after each task.

Open Questions

• Should timings be shown even after failure?
• Should total time also be displayed after all tasks have run?
• What style/format would look best for the new output?

[jdx]

let's just call it --timings—with a hidden alias --timing

[roele]

Since tasks might run in parallel the task prefix should probably be added to be able to tell which timing belongs to what task.
The current output does not make that clear.

[Ajpantuso]

@roele yeah I figured that would happen since we are streaming stdout/stderr; was just getting lucky on my test runs.

How would you feel about just adding a summary report of timings after all parallel execution?
I already added a metrics recorder for this purpose so there could eventually be structured output options. I guess prefixed output would be okay as well just think it may be hard to read with many tasks or lots of output.

[roele]

Yes prefixed will help a little but with many tasks could still be hard to read. An overall summary at the end might be better. Maybe we can find some good examples from other tools.

[Ajpantuso]

@roele cool, added prefixes for now just so folks can review what it would look like. In parallel I'll play around with summary formats.

[Ajpantuso]

@roele I have a quick summary table implementation here if you wanted to review/refine it.

After looking at it I feel like hacking a table on to the default output doesn't look right. I think a --summarize or --summary option in the future would feel more natural. The default summary could just be a user-consumable table with no stdout/stderr from tasks while additional output options like ---output={json,yaml,...} could dump stdout/stderr from tasks into a structured format for processing by CI runners.

[jdx]

after looking at this I am considering if maybe we just want to always display the timings. Not sure though.

[roele]

i feel in either case it should interfere less with the actual command output by maybe showing the entire line (after prefix) dimmed?

[jdx]

I'm still undecided on this. I think I'm leaning towards always displaying though curious if you all have any thoughts.

[jdx]

hmm maybe not. Let's keep it optional for now, I think we should err on the side of less noise.

[Ajpantuso]

Yeah, the other choice is optional, but default to enabled. Seems reasonable however to just take user feedback and make a final decision before tasks are a GA feature.

[jdx]

I might be not understanding this so much but I think this could be simplified by doing something like this:

fn run_all() {
  let start = time::Instant::now()
  for task in tasks {
    task.run();
  }
  println!("elapsed all: ...")
}

fn run_task() {
  let start = time::Instant::now()
  run()
  println!("elapsed: ...")
}

then we wouldn't need to modify anything outside of the cli command or use any mutexes or anything

[Ajpantuso]

then we wouldn't need to modify anything outside of the cli command or use any mutexes or anything

Correct, the only reason to have Mutexes or Channels would be to capture summaries. If there is no appetite for having some kind of summary report I can drop this to the simplest implementation. Really just playing around with possibilities to scope this out.

[roele]

After looking at it I feel like hacking a table on to the default output doesn't look right.

@Ajpantuso you're right it looks a bit odd. So i guess we should start small by refining the current inline approach.

[Ajpantuso]

@jdx @roele I've reset this back to barebones incorporating some suggestions.

Making it so timings are always displayed would have some implications for testing so leaving the flag in for now.

[jdx]

let's wrap this in style::edim() also we should only display it if there are >1 tasks. Lastly, let's put it on stderr. I could make a case for stderr or stdout but we're already using stderr for the task start message so I think stderr makes sense for this to match.

info_unprefix_trunc is what you'll want to use for this since that will respect the log level and hide the output under --quiet EDIT: we probably only want to do that if we make it non-optional

[Ajpantuso]

Done, used info! so the dim mise prefix is added, but I think that makes sense.