builtin time does not measure command substitutions

[floam]

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]

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]

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

[floam]

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]

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