Re: Process accounting/timing has broken recently

On Mon, Dec 06, 2010 at 09:00:54PM +0200, Alexander Motin wrote:
> On 06.12.2010 20:49, Steve Kargl wrote:
> >On Mon, Dec 06, 2010 at 08:46:15PM +0200, Andriy Gapon wrote:
> >>on 06/12/2010 20:43 Steve Kargl said the following:
> >>>The 7-10 days is an estimate.  I upgraded world/kernel on
> >>>Saturday.  The previous world/kernel could have been older
> >>>than I'm guessing.  It could be upto 4 weeks old because
> >>>my laptop tends to lag behind the upgrades to my servers.
> >>
> >>I see.
> >>
> >>>I would normally use gprof to measure execution times
> >>>for the functions I'm writing, but in some quick
> >>>testing last night gprof appears to be broken.  I'm
> >>>seeing a larger variation that I would expect in
> >>>self-seconds for the accumulated time for execution
> >>>of expf.
> >>
> >>Just guessing - could you try setting sysctl kern.eventtimer.periodic=1 
> >>if it's
> >>not 1 already?
> >>
> >>And cc-ing Alexander, just in case.
> >
> >Thanks for the suggestion.  I'll try this tonight (I left the
> >laptop at home) and will report back here.
> 
> Unless your application utilizes all CPUs all the time, you can also try 
> to set sysctl kern.eventtimer.idletick=1.
> 

To follow-up on the effect these tunables, I have the following results
for my application:

kern.eventtimer.idletick=0
kern.eventtimer.periodic=0

      139.39 real        78.34 user        60.62 sys
      138.70 real        79.26 user        59.01 sys
      138.99 real        78.54 user        60.03 sys
      139.04 real        78.96 user        59.65 sys
      139.25 real        77.65 user        61.17 sys
      138.95 real        79.07 user        59.45 sys
      139.00 real        78.85 user        59.72 sys
      139.04 real        78.32 user        60.29 sys
      138.96 real        78.49 user        60.05 sys
      138.97 real        78.24 user        60.31 sys

kern.eventtimer.idletick=1
kern.eventtimer.periodic=0

      137.79 real        85.32 user        52.04 sys
      137.67 real        84.08 user        53.16 sys
      137.59 real        84.24 user        52.93 sys
      137.58 real        84.50 user        52.65 sys
      137.21 real        85.81 user        50.97 sys
      137.84 real        84.14 user        53.27 sys
      137.41 real        84.32 user        52.67 sys
      137.74 real        83.00 user        54.32 sys
      137.34 real        84.15 user        52.76 sys
      137.82 real        83.83 user        53.57 sys

kern.eventtimer.idletick=1
kern.eventtimer.periodic=1

      138.35 real        98.02 user        39.89 sys
      138.14 real        98.29 user        39.43 sys
      138.62 real        98.17 user        40.01 sys
      138.62 real        97.69 user        40.51 sys
      138.39 real        97.83 user        40.14 sys
      138.77 real        97.28 user        41.07 sys
      138.51 real        97.89 user        40.19 sys
      138.23 real        97.46 user        40.35 sys
      138.53 real        97.34 user        40.77 sys
      138.90 real        97.27 user        41.20 sys

kern.eventtimer.idletick=0
kern.eventtimer.periodic=1

      138.93 real        98.23 user        40.26 sys
      138.74 real        97.45 user        40.87 sys
      138.55 real        98.33 user        39.80 sys
      138.50 real        98.57 user        39.50 sys
      138.22 real        96.45 user        41.35 sys
      138.41 real        98.05 user        39.93 sys
      138.58 real        98.14 user        40.01 sys
      138.80 real        97.25 user        41.12 sys
      138.62 real        97.01 user        41.17 sys
      138.51 real        96.98 user        41.10 sys

In the end, I'll go with jhb's explanation that getrusage 
is not robust when it comes to accounting for user time versus
system time.  I'll have to devise some other method for
monitoring execution speed of the functions I'm writing.

-- 
Steve