hyperfine icon indicating copy to clipboard operation
hyperfine copied to clipboard

Larger system time than runtime reported

Open haampie opened this issue 3 years ago • 6 comments

I'm consistently seeing:

  Time (mean ± σ):     289.0 ms ±   7.6 ms    [User: 243.0 ms, System: 862.1 ms]
  Range (min … max):   280.8 ms … 299.9 ms    10 runs

a large system time of 862.1ms, even though mean runtime is 289ms. Why is this?

haampie avatar May 24 '22 09:05 haampie

That is certainly possible if multiple cores are involved. You should see a similar behavior using time. User and system time are summed up across all cores.

We should really document this somehow (see also #443).

Example to reproduce using stress:

system > real time

▶ hyperfine "stress --vm 2 --timeout 1" 
Benchmark 1: stress --vm 2 --timeout 1
  Time (mean ± σ):      1.006 s ±  0.002 s    [User: 0.218 s, System: 1.781 s]
  Range (min … max):    1.002 s …  1.008 s    10 runs

user > real time

▶ hyperfine "stress --cpu 2 --timeout 1"  
Benchmark 1: stress --cpu 2 --timeout 1
  Time (mean ± σ):      1.001 s ±  0.000 s    [User: 1.987 s, System: 0.000 s]
  Range (min … max):    1.001 s …  1.001 s    10 runs

sharkdp avatar May 24 '22 10:05 sharkdp

Hm, I was aware, but I thought the application was single-threaded. Maybe I'm mistaken...

$ time taskset -c 0 julia -O3 example.jl
1.0

real	0m0.282s
user	0m0.206s
sys	0m0.058s

$ time julia -O3 example.jl
1.0

real	0m0.284s
user	0m0.222s
sys	0m0.881s

Sorry for the noise :D

haampie avatar May 24 '22 11:05 haampie

Sorry for the noise :D

No reason to apologize. I actually think this ticket should be left open, as a reminder to update the documentation.

sharkdp avatar May 24 '22 16:05 sharkdp

Your benchmark is quite interesting. It's actually not faster using multiple threads, it just spends a lot of time in kernel mode? Strange.

sharkdp avatar May 24 '22 16:05 sharkdp

It's probably a filesystem quirk

haampie avatar May 24 '22 17:05 haampie