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 real78.34 user60.62 sys 138.70 real79.26 user59.01 sys 138.99 real78.54 user60.03 sys 139.04 real78.96 user59.65 sys 139.25 real77.65 user61.17 sys 138.95 real79.07 user59.45 sys 139.00 real78.85 user59.72 sys 139.04 real78.32 user60.29 sys 138.96 real78.49 user60.05 sys 138.97 real78.24 user60.31 sys kern.eventtimer.idletick=1 kern.eventtimer.periodic=0 137.79 real85.32 user52.04 sys 137.67 real84.08 user53.16 sys 137.59 real84.24 user52.93 sys 137.58 real84.50 user52.65 sys 137.21 real85.81 user50.97 sys 137.84 real84.14 user53.27 sys 137.41 real84.32 user52.67 sys 137.74 real83.00 user54.32 sys 137.34 real84.15 user52.76 sys 137.82 real83.83 user53.57 sys kern.eventtimer.idletick=1 kern.eventtimer.periodic=1 138.35 real98.02 user39.89 sys 138.14 real98.29 user39.43 sys 138.62 real98.17 user40.01 sys 138.62 real97.69 user40.51 sys 138.39 real97.83 user40.14 sys 138.77 real97.28 user41.07 sys 138.51 real97.89 user40.19 sys 138.23 real97.46 user40.35 sys 138.53 real97.34 user40.77 sys 138.90 real97.27 user41.20 sys kern.eventtimer.idletick=0 kern.eventtimer.periodic=1 138.93 real98.23 user40.26 sys 138.74 real97.45 user40.87 sys 138.55 real98.33 user39.80 sys 138.50 real98.57 user39.50 sys 138.22 real96.45 user41.35 sys 138.41 real98.05 user39.93 sys 138.58 real98.14 user40.01 sys 138.80 real97.25 user41.12 sys 138.62 real97.01 user41.17 sys 138.51 real96.98 user41.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 ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Tuesday, December 07, 2010 9:54:05 pm David Xu wrote: 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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 ? Using 'time foo' only retrieves the usage once at the end via wait(). However, FWIW, I think ACCURATE_RUSAGE would simplify calcru1() quite a bit since you would just sum up the thread's usage (as we do know), but then do a direct conversion from bintime to timeval for user and system without ever having to worry about time going backwards, etc. All the hacks to enforce monotonicity that are currently in place would go away since we would have the real measurements and not be inferring them from statclock ticks. -- John Baldwin ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
John Baldwin wrote: On Tuesday, December 07, 2010 9:54:05 pm David Xu wrote: 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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 ? Using 'time foo' only retrieves the usage once at the end via wait(). However, FWIW, I think ACCURATE_RUSAGE would simplify calcru1() quite a bit since you would just sum up the thread's usage (as we do know), but then do a direct conversion from bintime to timeval for user and system without ever having to worry about time going backwards, etc. All the hacks to enforce monotonicity that are currently in place would go away since we would have the real measurements and not be inferring them from statclock ticks. I don't worry getrusage, though it is not necessary that it is used with wait(), I saw mysql used it to measure its internal code's performance, it did not use it with wait(), it is questionable if this usage is correct. However, I worry anyone who adds overhead to system call path. ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. -- John Baldwin ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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 ? ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. -- John Baldwin ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Mon, Dec 06, 2010 at 09:44:03AM -0500, 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 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. John, Thanks for the comment. It seems this splitting has become worse (for some definition of worse) in that previously the user time variation was on the order of tenth of a second not seconds. In thinking about the issue, I recalled that some changes to npx.c were committed 10 days ago. Perhaps, there is slightly more context switch overhead in dealing with the FPU registers, and this has increased the sys time. -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Mon, Dec 06, 2010 at 08:38:30AM -0800, Steve Kargl wrote: On Mon, Dec 06, 2010 at 09:44:03AM -0500, 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 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. John, Thanks for the comment. It seems this splitting has become worse (for some definition of worse) in that previously the user time variation was on the order of tenth of a second not seconds. In thinking about the issue, I recalled that some changes to npx.c were committed 10 days ago. Perhaps, there is slightly more context switch overhead in dealing with the FPU registers, and this has increased the sys time. If you can confirm this statement, it would be interesting. Otherwise, I claim that the changes did not affected the context switch path at all. The changes were mostly relevant for context(2) family of functions and debugger access to the FPU register file. pgp22NKWrueGR.pgp Description: PGP signature
Re: Process accounting/timing has broken recently
On Monday, December 06, 2010 11:38:30 am Steve Kargl wrote: On Mon, Dec 06, 2010 at 09:44:03AM -0500, 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 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. John, Thanks for the comment. It seems this splitting has become worse (for some definition of worse) in that previously the user time variation was on the order of tenth of a second not seconds. In thinking about the issue, I recalled that some changes to npx.c were committed 10 days ago. Perhaps, there is slightly more context switch overhead in dealing with the FPU registers, and this has increased the sys time. Hmm, I wonder if the eventtimer stuff that has gone into HEAD recently could be a factor? It might change when statclock() is called. -- John Baldwin ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Mon, Dec 06, 2010 at 07:35:31PM +0200, Kostik Belousov wrote: On Mon, Dec 06, 2010 at 08:38:30AM -0800, Steve Kargl wrote: John, Thanks for the comment. It seems this splitting has become worse (for some definition of worse) in that previously the user time variation was on the order of tenth of a second not seconds. In thinking about the issue, I recalled that some changes to npx.c were committed 10 days ago. Perhaps, there is slightly more context switch overhead in dealing with the FPU registers, and this has increased the sys time. If you can confirm this statement, it would be interesting. Otherwise, I claim that the changes did not affected the context switch path at all. The changes were mostly relevant for context(2) family of functions and debugger access to the FPU register file. I won't be able to test this possibiolity until later tonight (about 9 hours from now). -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
on 06/12/2010 20:01 John Baldwin said the following: Hmm, I wonder if the eventtimer stuff that has gone into HEAD recently could be a factor? It might change when statclock() is called. But I think that that code was committed more than 7-10 days ago, which Steve mentioned. -- Andriy Gapon ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Mon, Dec 06, 2010 at 08:24:27PM +0200, Andriy Gapon wrote: on 06/12/2010 20:01 John Baldwin said the following: Hmm, I wonder if the eventtimer stuff that has gone into HEAD recently could be a factor? It might change when statclock() is called. But I think that that code was committed more than 7-10 days ago, which Steve mentioned. 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 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. -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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. -- Andriy Gapon ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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. -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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. -- Alexander Motin ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. Regards, David Xu ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On 12/5/10 3:18 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. I know it's a lot to ask but it may be something that you can help with if you had the time to triangulate in on the change that did it.. I presume that since you are an old hand you can check out sources at different revisions.. ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Sun, Dec 05, 2010 at 04:00:32PM -0800, Julian Elischer wrote: On 12/5/10 3:18 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. I know it's a lot to ask but it may be something that you can help with if you had the time to triangulate in on the change that did it.. I presume that since you are an old hand you can check out sources at different revisions.. I was hoping that someone (possibly the person responsible) would recognize the symptoms and recommend a revision or two to revert. Otherwise, doing a binary search will take some time in that it takes 4+ hours for a buildworld/kernel cycle on my laptop. -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Sun, Dec 5, 2010 at 10:12 PM, Steve Kargl s...@troutmask.apl.washington.edu wrote: On Sun, Dec 05, 2010 at 04:00:32PM -0800, Julian Elischer wrote: On 12/5/10 3:18 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.00:88.70] with dx = 1.067100e-04 69.55 real 38.39 user 30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real 40.95 user 27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real 38.90 user 30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real 40.59 user 27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real 39.76 user 28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real 41.21 user 27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real 39.68 user 29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real 39.98 user 28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real 39.64 user 29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] 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. I know it's a lot to ask but it may be something that you can help with if you had the time to triangulate in on the change that did it.. I presume that since you are an old hand you can check out sources at different revisions.. I was hoping that someone (possibly the person responsible) would recognize the symptoms and recommend a revision or two to revert. Otherwise, doing a binary search will take some time in that it takes 4+ hours for a buildworld/kernel cycle on my laptop. If you can provide the source for the application you're running above and instructions on how to compile it, I can at least give you a bit of a head start :). Thanks, -Garrett ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On 12/5/10 10:19 PM, Garrett Cooper wrote: On Sun, Dec 5, 2010 at 10:12 PM, Steve Kargl s...@troutmask.apl.washington.edu wrote: On Sun, Dec 05, 2010 at 04:00:32PM -0800, Julian Elischer wrote: On 12/5/10 3:18 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. I know it's a lot to ask but it may be something that you can help with if you had the time to triangulate in on the change that did it.. I presume that since you are an old hand you can check out sources at different revisions.. I was hoping that someone (possibly the person responsible) would recognize the symptoms and recommend a revision or two to revert. Otherwise, doing a binary search will take some time in that it takes 4+ hours for a buildworld/kernel cycle on my laptop. If you can provide the source for the application you're running above and instructions on how to compile it, I can at least give you a bit of a head start :). Thanks, -Garrett plus which probably just `cd /sys/amd64/conf config GENERIC;cd ../compile/GENERIC; make kernel` would be enough... ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Sun, Dec 5, 2010 at 10:22 PM, Julian Elischer jul...@freebsd.org wrote: On 12/5/10 10:19 PM, Garrett Cooper wrote: On Sun, Dec 5, 2010 at 10:12 PM, Steve Kargl s...@troutmask.apl.washington.edu wrote: On Sun, Dec 05, 2010 at 04:00:32PM -0800, Julian Elischer wrote: On 12/5/10 3:18 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.00:88.70] with dx = 1.067100e-04 69.55 real 38.39 user 30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real 40.95 user 27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real 38.90 user 30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real 40.59 user 27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real 39.76 user 28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real 41.21 user 27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real 39.68 user 29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real 39.98 user 28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real 39.64 user 29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] 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. I know it's a lot to ask but it may be something that you can help with if you had the time to triangulate in on the change that did it.. I presume that since you are an old hand you can check out sources at different revisions.. I was hoping that someone (possibly the person responsible) would recognize the symptoms and recommend a revision or two to revert. Otherwise, doing a binary search will take some time in that it takes 4+ hours for a buildworld/kernel cycle on my laptop. If you can provide the source for the application you're running above and instructions on how to compile it, I can at least give you a bit of a head start :). Thanks, -Garrett plus which probably just `cd /sys/amd64/conf config GENERIC;cd ../compile/GENERIC; make kernel` would be enough... But couldn't it be libthr changes? There have been a handful of those that have been committed recently by davidxu. HTH, -Garrett ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On 12/5/10 10:24 PM, Garrett Cooper wrote: On Sun, Dec 5, 2010 at 10:22 PM, Julian Elischerjul...@freebsd.org wrote: On 12/5/10 10:19 PM, Garrett Cooper wrote: On Sun, Dec 5, 2010 at 10:12 PM, Steve Kargl s...@troutmask.apl.washington.eduwrote: On Sun, Dec 05, 2010 at 04:00:32PM -0800, Julian Elischer wrote: On 12/5/10 3:18 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.00:88.70] with dx = 1.067100e-04 69.55 real38.39 user30.94 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.82 real40.95 user27.60 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.14 real38.90 user30.02 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.79 real40.59 user27.99 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.93 real39.76 user28.96 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.71 real41.21 user27.29 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.05 real39.68 user29.15 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 68.99 real39.98 user28.80 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.02 real39.64 user29.16 sys Max ULP: 0.501607 for x in [-18.00:88.70] with dx = 1.067100e-04 69.38 real37.49 user31.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. I know it's a lot to ask but it may be something that you can help with if you had the time to triangulate in on the change that did it.. I presume that since you are an old hand you can check out sources at different revisions.. I was hoping that someone (possibly the person responsible) would recognize the symptoms and recommend a revision or two to revert. Otherwise, doing a binary search will take some time in that it takes 4+ hours for a buildworld/kernel cycle on my laptop. If you can provide the source for the application you're running above and instructions on how to compile it, I can at least give you a bit of a head start :). Thanks, -Garrett plus which probably just `cd /sys/amd64/conf config GENERIC;cd ../compile/GENERIC; make kernel` would be enough... But couldn't it be libthr changes? There have been a handful of those that have been committed recently by davidxu. Unlikely as there was no mention of there being any thread involvement. probably just replacing the kernel would be enough.. It'd be easy to find out.. see if one 2 weeks old fixes the problem :-) HTH, -Garrett ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Sun, Dec 05, 2010 at 10:24:12PM -0800, Garrett Cooper wrote: But couldn't it be libthr changes? There have been a handful of those that have been committed recently by davidxu. HTH, There is no threading involved in the application. However, it was David's recent changes that caused me to upgrade from a 7-10 day old install. The recent libthr chnages have improved the stalling that I experience with firefox. -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: Process accounting/timing has broken recently
On Sun, Dec 05, 2010 at 10:19:12PM -0800, Garrett Cooper wrote: If you can provide the source for the application you're running above and instructions on how to compile it, I can at least give you a bit of a head start :). Thanks, -Garrett The app is statically linked. I can give you the binary. Compiling the code would be a pain. You need mpfr and gmp from ports and you would need to patch libm with my expf implementation. Unfortunately, I have extensive libm patches that will take sometime to unravel for only my expf file. My give my a 1/2 hour. I recompile with standard libm expf. -- Steve ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
