Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Expose the command duration via a callback #1029

Closed
krader1961 opened this issue May 16, 2020 · 9 comments
Closed

Expose the command duration via a callback #1029

krader1961 opened this issue May 16, 2020 · 9 comments

Comments

@krader1961
Copy link
Contributor

The fish shell has a $CMD_DURATION variable which is the number of milliseconds that the last interactive command ran. I use that in my right prompt to show a human friendly duration for the most recently run command. An Elvish user can simulate that via the $edit:before-readline and $edit:after-readline hooks but that has problems.

First, it requires a lot of effort from the user to produce data that should be provided by the shell.

Second, unless you carefully structure the implementation, similar to https://github.com/zzamboni/elvish-modules/blob/master/long-running-notifications.elv, you won't get even a semi-accurate measurement. Even @zzamboni's carefully written solution is less accurate than it could be because it includes additional overhead that could materially increase the computed duration. A naive user will attempt to save the start time in the $edit:before-readline hook and use that in the $edit:after-readline hook to calculate the duration. Oops! The duration now includes the time between issuing a new prompt and the user pressing [enter].

@krader1961
Copy link
Contributor Author

krader1961 commented May 16, 2020

I would like to see something like a $edit:cmd-duration variable introduced. This should not be in the builtin namespace because we don't want, or need, to measure the elapsed duration of every statement by default. This is an interactive REPL feature primarily meant to be used in the interactive prompts or related command hooks.

@krader1961
Copy link
Contributor Author

krader1961 commented May 16, 2020

Also, note that the solution used by https://github.com/zzamboni/elvish-modules/blob/master/long-running-notifications.elv has a resolution of seconds. The proposed $edit:cmd-duration variable should have millisecond, or better, resolution. And the @zzamboni implementation requires running the external date command. Which shouldn't be necessary. But that's a separate issue.

@xiaq
Copy link
Member

xiaq commented May 17, 2020

I'd rather we introduce an after-cmd hook and supply this information as part of the hook, which localizes the information instead of making it a global variable.

@xiaq
Copy link
Member

xiaq commented May 17, 2020

Before #1030 is resolved, I am open to an experimental API that exposes this information as a global, perhaps named edit:-last-cmd-duration-sec.

@krader1961
Copy link
Contributor Author

An after-cmd hook might be a good idea but creates some questions. In particular, it would be an expensive mechanism to solely capture the execution duration of the most recent interactive command.

I agree that assigning a float64 of the elapsed fractional seconds to a edit:-cmd-duration-sec var (I don't see the point of including last- in that var name) is better than a nominal integer scaled by milliseconds or microseconds.

FWIW, On my primary macOS server using the @zzamboni approach, but using date '%s.%N' for nanosecond resolution, consistently results in a command duration of 6 to 8 ms when simply pressing [enter]; i.e., not running any command at all. Which shows that using the existing hooks is unexpectedly expensive.

@zzamboni
Copy link
Contributor

I agree that it might be better for precision that the shell itself measures and exposes how much a command took. Display/reporting can then of course be done by hooks.

Though honestly, I don't think this is a must - I can't really think of a good use case (other than the kind of thing long-running-notifications does) for having this measurements. So I would consider it as a low priority.

Finally, a question based on the discussion above: isn't the existing before-readline hook effectively the same as the proposed after-cmd hook? What am I missing?

@krader1961
Copy link
Contributor Author

isn't the existing before-readline hook effectively the same as the proposed after-cmd hook?

No, since the after-cmd hook would only fire when a command was actually run. Simply displaying a new prompt, such as from pressing [enter] on an empty command line, wouldn't trigger it. Also, it wouldn't be tied to interactive prompts, making it usable from a script. Which means that a after-cmd hook would eliminate the need for the time command.

What arguments would be passed to a after-cmd hook? Obviously the statement that was run and the elapsed time in seconds. A third argument could be a list of exceptions thrown by the statement or an empty list if there were no exceptions. A fourth argument could be the getrusage data for any external commands. A fifth argument could be the getrusage delta for the shell itself.

@krader1961 krader1961 changed the title Expose the command duration as a variable Expose the command duration via a callback May 20, 2020
@krader1961
Copy link
Contributor Author

I started working on a resolution for this issue and realized that simply pressing Enter should not affect the recorded duration of the most recent command since no command was executed. Also, introducing an after-cmd hook might be useful but is not needed to resolve this issue and needlessly complicates capturing the duration of an interactive statement. The resolution I'm working on introduces a edit:command:duration float64 variable.

@krader1961
Copy link
Contributor Author

I'd rather we introduce an after-cmd hook and supply this information as part of the hook, which localizes the information instead of making it a global variable.

I've been using a change that introduces the $edit:command:-duration variable for a few days. Along with a related change to my ~/.elvish/rc.elv that displays that var in my right prompt. I'm pretty happy with the behavior. Especially that it captures the cost to source ~/.elvish/rc.elv before the first prompt is rendered. Which, on my primary server, is on the order of 400 ms. It also ignores any code block that consists entirely of whitespace. This means that simply pressing Enter does not modify the value of that variable (assuming only whitespace characters were entered before pressing Enter).

I am also working on a change to introduce a edit:after-command hook. It is still unclear if the value of that hook justifies the cost(s) but it does open other possibilities such as capturing any error from executing a code block.

krader1961 added a commit to krader1961/elvish that referenced this issue Mar 21, 2021
The `edit:command:-duration` variable is the elapsed seconds of the most
recently run interactive command. It is currently marked experimental by
virtue of a `-` prefix since it might be removed in favor of the command
execution callback solution.

Related elves#1029
krader1961 added a commit to krader1961/elvish that referenced this issue Mar 21, 2021
This introduces a $edit:after-command callback. It is called with three
arguments: the command line that was run, the duration of that command
in seconds, and any error that occurred ($nil if no error occurred).

Related elves#1029
krader1961 added a commit to krader1961/elvish that referenced this issue Apr 23, 2021
The `edit:after-command` hooks are called with a single argument:
a pseudo-map with these keys:

    "command": the command line that was run
    "duration": the execution duration in seconds
    "error": any error that occurred ($nil if no error occurred)

The `edit:command-duration` variable is the elapsed seconds (as a
float64) of the most recently run interactive command.

Resolves elves#1029
krader1961 added a commit to krader1961/elvish that referenced this issue May 5, 2021
The `edit:after-command` hooks are called with a single argument:
a pseudo-map with these keys:

    "command": the command line that was run
    "duration": the execution duration in seconds
    "error": any error that occurred ($nil if no error occurred)

The `edit:command-duration` variable is the elapsed seconds (as a
float64) of the most recently run interactive command.

Resolves elves#1029
@xiaq xiaq closed this as completed in e2f8100 May 5, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants