Process accounting/timing has broken recently
David Xu
davidxu at freebsd.org
Wed Dec 8 02:54:07 UTC 2010
John Baldwin wrote:
> On Monday, December 06, 2010 7:11:28 pm David Xu wrote:
>> John Baldwin wrote:
>>> On Sunday, December 05, 2010 6:18:29 pm Steve Kargl wrote:
>>>
>>>> Sometime in the last 7-10 days, some one made a
>>>> change that has broken process accounting/timing.
>>>>
>>>> laptop:kargl[42] foreach i ( 0 1 2 3 4 5 6 7 8 9 )
>>>> foreach? time ./testf
>>>> foreach? end
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 69.55 real 38.39 user 30.94 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 68.82 real 40.95 user 27.60 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 69.14 real 38.90 user 30.02 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 68.79 real 40.59 user 27.99 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 68.93 real 39.76 user 28.96 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 68.71 real 41.21 user 27.29 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 69.05 real 39.68 user 29.15 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 68.99 real 39.98 user 28.80 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 69.02 real 39.64 user 29.16 sys
>>>> Max ULP: 0.501607 for x in [-18.000000:88.709999] with dx = 1.067100e-04
>>>> 69.38 real 37.49 user 31.67 sys
>>>>
>>>> testf is a numerically intensive program that tests the
>>>> accuracy of expf() in a tight loop. User time varies
>>>> by ~3 seconds on my lightly loaded 2 GHz core2 duo processor.
>>>> I'm fairly certain that the code does not suddenly grow/loose
>>>> 6 GFLOP of operations.
>>>>
>>> The user/sys thing is a hack (and has been). We sample the PC at stathz (~128
>>> hz) to figure out a user vs sys split and use that to divide up the total
>>> runtime (which actually is fairly accurate). All you need is for the clock
>>> ticks to fire just a bit differently between runs to get a swing in user vs
>>> system time.
>>>
>>> What I would like is to keep separate raw bintime's for user vs system time in
>>> the raw data instead, but that would involve checking the CPU ticker more
>>> often (e.g. twice for each syscall, interrupt, and trap in addition to the
>>> current once per context switch). So far folks seem to be more worried about
>>> the extra overhead rather than the loss of accuracy.
>>>
>>>
>> Adding any instruction into global syscall path should be cautioned, it
>> is worse then before, thinking about a threaded application, a userland
>> thread may have locked a mutex and calls a system call, the overhead
>> added to system call path can directly affect a threaded application's
>> performance now, because the time window the mutex is held
>> is longer than before, I have seen some people likes to fiddle with
>> system call path, it should be cautioned.
>
> OTOH, the current getrusage(2) stats cannot be trusted. The only meaningful
> thing you can do is to sum them since the total is known to be accurate at
> least.
>
> If it wouldn't make things so messy I'd consider a new kernel option
> 'ACCURATE_RUSAGE' or some such.
>
Our getrusage is already very slow, everytime, it needs to
iterate the threads list with a process SLOCK held. I saw some mysql
versions heavily use getrusage, and a horribly slow. I think a
ACCURATE_RUSAGE will make it worse ?
More information about the freebsd-current
mailing list