Re: Bug/limitation in 'time'

[Pierre Gaston]

On Sun, Mar 17, 2013 at 4:33 AM, Bruce Dawson
<brucedawson@cygnus-software.com> wrote:
> Thanks -- good to know that there is a fast and POSIX compliant method of
> doing this. I should have included my optimized counting loop -- it's what
> we switched to when we realized that $(expr) was a problem. Here it is now:
>
> # This code performs quite well
> function BashCount() {
>         i=$1
>         while [ $i -gt 0 ]; do
>                 (( i-- ))
>         done
>         echo Just did $1 iterations using bash math
> }
> time BashCount 150000
>
> It's a *lot* faster, of course. BTW, I've poked around in the 'time' source
> code enough to know that it is just displaying the results of wait3(), so
> the misleading CPU consumption information is ultimately a wait3()/kernel
> issue. However showing this in the documentation would be great.

At least the man page of time on my ubuntu system is pretty much clear
about what it does.

The result is not striking me as impossible though, I can imagine a
lot of real time spent waiting for the scheduler to run expr and then
to run bash again.

I tried a little experiment that I think shows the importance of the
scheduler on the real time result:
I run at the same time this little loop with different "niceness"
i=0;time while ((i++<10000));do /bin/echo -n;done

sudo nice -n 19 bash -c 'i=0;time while ((i++<10000));do /bin/echo
-n;done' 2>&1| sed s/^/19:\ / &
sudo nice -n -20 bash -c 'i=0;time while ((i++<10000));do /bin/echo
-n;done' 2>&1| sed s/^/-20:\ /

I get:
-20: real       0m9.331s
-20: user       0m0.468s
-20: sys        0m1.504s

19: real        0m14.004s
19: user        0m0.532s
19: sys 0m1.660s

so the nicer loop takes twice as much real time indicating that much
real time is spent waiting for the process to run.