Add command execution time segment

[dritter]

This PR solves #330 . It is not complete by now, just wanted early feedback.

Still missing:

• Documentation
• Icon
• Add tests (more or less)

[rjorgenson]

I was just looking into how to do this because I also think this is a great thing to have! Pulled the code and am testing.

I couldn't find any icons that seemed terribly appropriate but for me the use case for this will be no icon and merged with the status segment. Could we make the "Dur" string a user setting? Something like POWERLEVEL9K_COMMAND_EXECUTION_TIME_STRING so it can be empty?

One thing I did notice is that the segment position seems to affect the time. Here I have it on the left prompt and the right prompt and the right prompt segment execution seems to have a taken a little longer than the left prompt segment. In bullettrain they do the calculation in the precmd function which I assume gets around this.

edit - it's the "2" joined to the status segment on the left prompt and the "3" on the very right of the right prompt.

[rjorgenson]

After further looking this is the best icon I could find for the segment - uE89C for patched mode - but it's got a lot too it and doesn't look to great at smaller font points.

Normal font size for me(11pt) -

a more reasonable for most 14pt -

[V1rgul]

If you use fontawesome, there's these ones

[rjorgenson]

The hourglass-end seems awfully appropriate =]

[dritter]

Thanks for the excellent feedback @rjorgenson
I'll fix these issues later today.

And thanks @V1rgul for the icons. Btw. You use awesome-fontconfig mode, right? Could you post the codepoint of that icon? That would be helpful.

[V1rgul]

@dritter that would be '\u'$CODEPOINT_OF_AWESOME_HOURGLASS_END (or $'\uF253' without #385)

[dritter]

Thanks @V1rgul !

@rjorgenson I updated this PR according to your suggestions. "Dur" is now the visual identifier for the default icon set. For awesome-patched mode I used indeed the hourglass. I agree that it is quite ugly on smaller font sizes, but it's the best we have. 🙄
Also, the calculation is now done in powerlevel9k_prepare_prompts, so that the duration is independent from the segment.

Btw. I skipped the tests, because we can't recreate interactive commands well enough in the tests.

[rjorgenson]

Been using this for the last day, and have noticed a lot of very very high second counts from things like ssh sessions and editing files etc. What do you think about something like this for a more readable output? Alternatively we could set a max threshold, but that information might be useful to people running hours long executions and having a readable output would be nice.

  local dur=$_P9K_DURATION_TIME

  [[ $_P9K_COMMAND_DURATION -gt 60 ]] && dur=$(strftime '%M:%S' $_P9K_COMMAND_DURATION)
  [[ $_P9K_COMMAND_DURATION -gt 3600 ]] && dur=$(strftime '%H:%M:%S' $_P9K_COMMAND_DURATION)

  if [ $_P9K_COMMAND_DURATION -ge $POWERLEVEL9K_COMMAND_EXECUTION_TIME_THRESHOLD ]; then
    "$1_prompt_segment" "$0" "$2" "red" "226" "${dur}" 'EXECUTION_TIME_ICON'
  fi

edit - forgot to account for sub 60 second times lol - fixed

[dritter]

In 04e75a6#diff-ea5a405f0331722fc10a832209ffe20bR1185 I fixed a problem that the segment was not wiped, if you just press enter. That might be the problem in your case (or did you enter a command?)..
So could you retest it? That would be cool.

[rjorgenson]

No it wasn't a problem, I would just have a command executing for a significant period of time, in the case of SSH sessions, sometimes hours. This was giving me output in seconds that were almost meaningless to my maths challenged brain because it was more than a minute or two lol - The above would just output it in the form of MM:SS or HH:MM:SS if applicable.

[dritter]

Ah. Now I see where you are getting at (sorry, too tired). Yes, great idea! 👍

[rjorgenson]

Just noticed I left the 's' off the second output in my example above if you wanted to keep that.

[dritter]

Thanks for the hint, but I'll leave it like this. If all outputs don't have units, then seconds should have none too.

Btw. I noticed something strange, when I wrote tests for this: strftime '%H:%M:%S' 7200 says 3 hours on my mac.. Could you execute test/segments/command_execution_time.spec on your machine? At least the tests run on travis..

[rjorgenson]

It actually returns 19:00:00 on my mac for some reason lol

./test/segments/command_execution_time.spec
testCommandExecutionTimeIsNotShownIfTimeIsBelowThreshold
testCommandExecutionTimesThresholdCouldBeChanged
testCommandExecutionTimeIsFormattedHumandReadbleForMinuteLongCommand
testCommandExecutionTimeIsFormattedHumandReadbleForHourLongCommand
ASSERT:expected:<%K{red} %F{226%}Dur%f %F{226}02:00:00 %k%F{red}%f > but was:<%K{red} %F{226%}Dur%f %F{226}19:00:00 %k%F{red}%f >

Ran 4 tests.

FAILED (failures=1)

I also get the exact same output on my Ubuntu test machine. It seems to be applying an offset to the hour for some reason rather than converting the epoch seconds to a time string. If I pass it 60 with the H:M:S date string it returns 17:01. It does appear to be calculating it correctly as 2 hours, but adding 17 hours to it somewhere, in your case it's probably just adding 1 hour. And for some reason on travis it's adding 0 hours. My TZ is GMT-7 so I don't think that's it, it is 17:XX PM right now where I am, so that may have something to do with it. I'll check it again at 18:XX PM and see if it changes.

[rjorgenson]

At 18:01 the strftime still returns the time plus 17 hours. Bizarre.

[rjorgenson]

Hmm, it does appear to be timezone related, if I run TZ=GMT strftime '%H:%M:%S' 7200 I get the expected output of 02:00:00 - Any chance you are GMT+1?

[dritter]

Yep. I am GMT+1.
Interestingly I get for 01:XX AM the same output as for 02:XX AM - both times 03:00:00

[dritter]

Anyway. Need to sleep now. Thanks for the help. Much appreciated! 👍

[rjorgenson]

Awesome, looks like we can normalize TZ like so

[[ $_P9K_COMMAND_DURATION -gt 60 ]] && duration=$(TZ=GMT strftime '%M:%S' $_P9K_COMMAND_DURATION)
[[ $_P9K_COMMAND_DURATION -gt 3600 ]] && duration=$(TZ=GMT strftime '%H:%M:%S' $_P9K_COMMAND_DURATION)

And the tests pass as expected.

testCommandExecutionTimeIsNotShownIfTimeIsBelowThreshold
testCommandExecutionTimesThresholdCouldBeChanged
testCommandExecutionTimeIsFormattedHumandReadbleForMinuteLongCommand
testCommandExecutionTimeIsFormattedHumandReadbleForHourLongCommand

Ran 4 tests.

OK

Enjoy your sleep! =]

[bhilburn]

@rjorgenson @dritter - I'm testing this out, now, and for whatever reason the segment isn't rendering at all for me. I'm not really sure how to explain it, yet. Going to keep digging.

[rjorgenson]

@bhilburn by default if the command execution is less than 3 it will not display anything. Also for me it doesn't display anything if the execution time is less than 1 second even if threshold is set to 0. I've been testing by just opening up a file in vim for a number of seconds.

[bhilburn]

@rjorgenson @dritter - Yeah, sorry, I should have been more specific. What I couldn't make it do was "always render". Like @rjorgenson said, setting the threshold to zero for some reason doesn't seem to work (neither do negative numbers).

I think lots of people are going to be really excited by this segment, and want it to always be on. It would be great if there was a way to not only turn it perma-on, but display fractional seconds. Is there something similar to $EPOCHSECONDS that is more granular that we could use as easily?

[rjorgenson]

@bhilburn @dritter Hmmm, we could use date +%s%N in place of $EPOCHSECONDS and compare that to date +%s%N in the precmd function to get a nanosecond difference. We would need to account for OS X not supporting %N unless coreutils is installed via homebrew which provides gdate which does support %N. I tested this and it appears to work best with thousandths of a second, or %3N - the full %N output was just not useful for humans =] We would also have to find a way to normalize this I think, for those commands that run for more than a few seconds. We could just cut off the thousandths for anything over 60 seconds, and then process them as we originally we were going to.

I also had a thought on that and am not sure strftime is the best approach, since that's not actually what we want. I came up with this

prompt_command_execution_time() {
  set_default POWERLEVEL9K_COMMAND_EXECUTION_TIME_THRESHOLD 3

  local duration=$(echo $_P9K_COMMAND_DURATION | sed 's/...$/.&/;s/^..$/.0&/;s/^.$/.00&/')s
  local nduration=$(echo $duration | sed 's/\..*//')

  if [[ $nduration -gt 60 ]]; then
    local hours=$(( nduration / 60 / 60 % 24 ))
    local minutes=$(( nduration / 60 % 60 ))
    local seconds=$(( nduration % 60 ))
    if [[ ! $hours = 0 ]]; then
      duration="${hours}h ${minutes}m ${seconds}s"
    else
      duration="${minutes}m ${seconds}s"
    fi
  fi

  if [ $_P9K_COMMAND_DURATION -ge $POWERLEVEL9K_COMMAND_EXECUTION_TIME_THRESHOLD ]; then
    "$1_prompt_segment" "$0" "$2" "red" "226" "${duration}" 'EXECUTION_TIME_ICON'
  fi
}

powerlevel9k_preexec() {
  _P9K_TIMER_START=$(gdate +%s%3N)
}

powerlevel9k_prepare_prompts() {
  
  ...

  _P9K_TIMER_STOP=$(gdate +%s%3N)
  _P9K_COMMAND_DURATION=$((_P9K_TIMER_STOP - _P9K_TIMER_START))
  # Reset start time
  _P9K_TIMER_START=9999999999999

  ...

}

prompt_powerlevel9k_setup() {
  # Disable false display of command execution time
  _P9K_TIMER_START=9999999999999
  
  ...
  
}

This brings us back to specifying hours/minutes/seconds and away from a time string, which in hindsight -might- confuse someone who has the time segment enabled. Though the window for those two numbers being similar is slim. It is also does not yet account for OS specific date commands or gdate not being present on an OS X system. And given my admittedly limited understanding of what I wrote up there, it probably has a bug or two LOL - But it does work as I expect it to on my system. Probably worth pursuing if @bhilburn feels strongly about having this functionality in the theme.

The segment is joined on the left to the return status, the first .021 was a clear command and not a new terminal, new terminal shows an empty value which is expected.

P.S. - Sorry for the giant wall of text!

[rjorgenson]

I already found some bugs! lol

I forgot to work in support for the threshold cutoff, that would need to be changed to if [ $nduration -ge $POWERLEVEL9K_COMMAND_EXECUTION_TIME_THRESHOLD ]; then I believe. However commands that return in less than 1 second have an $nduration of '' - my regex-fu was not good enough to prepend a zero to durations of XXX without messing up durations of XXXX - I could prepend a zero to durations of XX and X(though I've never seen one this low). Perhaps it could just be done in a second step, or we could just check for a value of nduration and set it to zero if there is none since that will only happen with execution times below 1 second. Input is welcome on that =]

[dritter]

@rjorgenson @bhilburn I reworked this segment. Now it uses nanoseconds internally (provided by $EPOCHREALTIME see the zsh/datetime documentation). As this is an ZSH module, no need to hassle with date or gdate.

Even setting POWERLEVEL9K_COMMAND_EXECUTION_TIME_THRESHOLD to zero works now.

If the command runs less than a minute, the microtime is printed as well. If you want, you could even control the precision by setting POWERLEVEL9K_COMMAND_EXECUTION_TIME_PRECISION (defaults to 2). For full seconds, just set it to zero.
Timings above one minute are printed nicely formatted (thx to @rjorgenson).

[rjorgenson]

Well that's much slicker than what I came up with! Gonna pull this and give it a try tonight =]

[rjorgenson]

Tested out these changes and everything works great so far!

[bhilburn]

@dritter @rjorgenson - Really great work, guys.

When I'm not testing segments, my actual P9k config only used 6 segments. This just became the seventh segment in my permanent config =)