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

builtin time does not measure command substitutions #9100

Closed
floam opened this issue Jul 31, 2022 · 4 comments · Fixed by #10466
Closed

builtin time does not measure command substitutions #9100

floam opened this issue Jul 31, 2022 · 4 comments · Fixed by #10466

Comments

@floam
Copy link
Member

floam commented Jul 31, 2022

I was trying to figure out why some benchmarking of a git.fish completion change I was considering, seemed not to be evidencing the same difference if I used time, versus if I ran it a bunch of times and compared with CMD_DURATION.

Specifically, the change was to the line test "$root/$relfile" = (pwd -P)/$relfile;:

~/f/fish-shell $ set relfile ./fish.png
~/f/fish-shell $ set root /Users/floam/fish/fish-shell/
~/f/fish-shell $ for i in (seq 100); test "$root/$relfile" = (pwd -P)/$relfile; end
~/f/fish-shell $ echo $CMD_DURATION
25
~/f/fish-shell $ for i in (seq 100); test "$root/$relfile" -ef ./$relfile; end
~/f/fish-shell $ echo $CMD_DURATION
11

So it using test … -ef … here appears to be twice as fast.

However, time reports:

~/f/fish-shell $ time test "$root/$relfile" -ef ./$relfile

________________________________________________________
Executed in   61.00 micros    fish           external
   usr time    9.00 micros    9.00 micros    0.00 micros
   sys time   55.00 micros   55.00 micros    0.00 micros

~/f/fish-shell $ time test "$root/$relfile" = (pwd -P)/$relfile

________________________________________________________
Executed in    8.00 micros    fish           external
   usr time    8.00 micros    8.00 micros    0.00 micros
   sys time    4.00 micros    4.00 micros    0.00 micros
@floam floam added the bug Something that's not working as intended label Jul 31, 2022
@floam
Copy link
Member Author

floam commented Jul 31, 2022

and finally:

$ time echo -n (sleep 1)

________________________________________________________
Executed in   66.00 micros    fish           external
   usr time   37.00 micros   37.00 micros    0.00 micros
   sys time   32.00 micros   32.00 micros    0.00 micros

@floam
Copy link
Member Author

floam commented Jul 31, 2022

Obviously, the command substitution is expanded before the timer starts, but that just can't be how we let it work.

@floam
Copy link
Member Author

floam commented Jul 31, 2022

And the workaround:

~/f/fish-shell $ time begin; test "$root/$relfile" = (pwd -P)/$relfile; end

________________________________________________________
Executed in  311.00 micros    fish           external
   usr time   65.00 micros   65.00 micros    0.00 micros
   sys time  139.00 micros  139.00 micros    0.00 micros

~/f/fish-shell $ time begin; test "$root/$relfile" -ef ./$relfile; end

________________________________________________________
Executed in   40.00 micros    fish           external
   usr time   13.00 micros   13.00 micros    0.00 micros
   sys time   30.00 micros   30.00 micros    0.00 micros

@mqudsi
Copy link
Contributor

mqudsi commented Aug 31, 2022

I imagine the most accurate option would be timing eval directly?

@faho faho added enhancement and removed bug Something that's not working as intended labels Sep 26, 2022
@faho faho added this to the fish-future milestone Sep 26, 2022
@faho faho changed the title builtin time does not agree with CMD_DURATION for commands with substitutions builtin time does not measure command substitutions Jun 29, 2023
@krobelus krobelus modified the milestones: fish-future, fish next-3.x May 3, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants