Messages in this thread |  | | Date | Mon, 9 Apr 2007 02:14:14 +0200 | | From | "Dmitry Adamushko" <> | | Subject | Re: SD scheduler testing hitch |
| |
On 08/04/07, Mike Galbraith <efault@gmx.de> wrote: > On Sat, 2007-04-07 at 19:17 +0200, Mike Galbraith wrote: > > > I lowered the time to 500us, and ran at nice -10.. it starves tenpercent > > here every time. (ran as taskset -c 1 nice -n -10 ./fairtest) The > > starving 10% duty cycle task has trouble getting 1% CPU. >
Something is odd, very odd indeed. But surprise-surprise, it does not seem to be something merely SD-releated.
In short, the question is - can we always believe statistics being provided by "top" (i.e. the way it's being collected by the kernel)?
The tests are below. Somewhere in the middle are thoughts on how HZ and an interval of cpu usage by a given task may be connected to such a behaviour.
The system: Pentiium 3 Coppermine 750 MHz (iThinkPad T21), 256 RAM.
I tested 3 configurations:
(1) 2.6.13-15 (default in SuSE 10) (2) 2.6.19 (3) 2.6.21-rc5 + sd-0.39
TEST: just a tenp.c, i.e. without Mike's "steal" (either as xx.c or as a part of modified fairtest.c) thingy, but
tenp -- a tenp.c with a single running copy; tenp2 -- a tenp.c with 2 (1 additionally forked) running copies tenp15 - 15 copies (only for SD)
(1) 2.6.13-15
Tasks: 74 total, 1 running, 73 sleeping, 0 stopped, 0 zombie Cpu(s): 8.6% us, 0.7% sy, 0.0% ni, 90.4% id, 0.0% wa, 0.3% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5582 dimm 15 0 1460 428 348 S 6.0 0.2 0:02.03 tenp 4047 messageb 17 0 3520 1584 1324 S 1.3 0.6 0:00.28 dbus-daemon
Tasks: 76 total, 1 running, 75 sleeping, 0 stopped, 0 zombie Cpu(s): 14.9% us, 0.3% sy, 0.0% ni, 84.8% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5598 dimm 15 0 1460 428 348 S 7.2 0.2 0:01.42 tenp2 5599 dimm 15 0 1460 432 352 S 6.9 0.2 0:00.87 tenp2 5591 dimm 16 0 2108 988 764 R 0.3 0.4 0:00.47 top 1 root 16 0 688 260 224 S 0.0 0.1 0:01.78 init
I repeated 7 times each of the tests (tenp and tenp2). All are ok.
Now an interesting part starts.
(2) 2.6.19
[ 2.1 ]
ks: 73 total, 1 running, 72 sleeping, 0 stopped, 0 zombie Cpu(s): 1.3% us, 0.7% sy, 0.0% ni, 98.0% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 8312 root 15 0 27168 14m 2128 S 0.7 5.6 0:08.29 X 8640 dimm 15 0 28656 13m 9m S 0.7 5.4 0:03.44 konsole 8813 dimm 15 0 1460 432 352 S 0.3 0.2 0:00.32 tenp 1 root 15 0 696 268 228 S 0.0 0.1 0:01.12 init
[ 2.2 ]
ks: 73 total, 3 running, 70 sleeping, 0 stopped, 0 zombie Cpu(s): 6.6% us, 0.7% sy, 0.0% ni, 92.7% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 8816 dimm 15 0 1464 432 352 S 5.0 0.2 0:01.49 tenp 8312 root 15 0 27168 14m 2128 R 1.7 5.6 0:09.08 X
See a difference between [ 2.1 ] and [ 2.2 ] ? [ 2.2 ] (which is ok) has happened 3 out of 10 times.
Now for tenp2
[ 2.3 ]
ks: 74 total, 1 running, 73 sleeping, 0 stopped, 0 zombie Cpu(s): 14.6% us, 0.3% sy, 0.0% ni, 85.1% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 8850 dimm 15 0 1460 432 352 S 6.6 0.2 0:01.32 tenp2 8851 dimm 15 0 1460 112 32 S 6.3 0.0 0:00.77 tenp2 8312 root 15 0 27168 14m 2128 S 0.7 5.6 0:11.73 X
[ 2.4 ]
ks: 74 total, 2 running, 72 sleeping, 0 stopped, 0 zombie Cpu(s): 3.3% us, 0.3% sy, 0.0% ni, 96.3% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 8312 root 15 0 27168 14m 2128 S 2.0 5.6 0:12.97 X 8640 dimm 15 0 28748 13m 9m R 0.7 5.4 0:07.22 konsole 8532 dimm 18 0 2476 416 268 S 0.3 0.2 0:00.04 gpg-agent 8852 dimm 15 0 2116 996 772 R 0.3 0.4 0:00.27 top 8859 dimm 15 0 1460 432 352 S 0.3 0.2 0:00.44 tenp2 8860 dimm 15 0 1460 112 32 S 0.3 0.0 0:00.02 tenp2 1 root 15 0 696 268 228 S 0.0 0.1 0:01.12 init
Again, [ 2.3 ] took place only 3 times.
Some observations:
/1/ for the "ok" ( [ 2.2 ] and [ 2.3 ] ) cases, the "will run" and "will sleep" times from tenp's calibration output look /higher/ than on average :
e.g. Each fork will run for 5863 usecs and sleep for 52767 usecs
v.s. something in between
Each fork will run for 2392 usecs and sleep for 21528 usecs Each fork will run for 3880 usecs and sleep for 34920 usecs
for the most part of cases (when tenp's cpu% ~0.3).
/2/ HZ = 250 for 2.6.19 and I think it was still 1000 for 2.6.13 (arghh.. forgot to check and would like to avoid a reboot in this already late hour... but I believe it was still the time of 1000 by default).
=============
(*)
HZ == 250 ==> timer_tick is once in 4 ms. So - "will run for" < 4 ms - may come well unaccounted? :o)
The funny thing is (at least in theory) - if a task is using CPU in portions < 1/HZ s. and specially shifted against timer interrupts -> scheduler_tick() - its time_slice isn't decreasing at all (very theoretically) or just more or less slower (with another load a moment when the task is running should drift wrt moments of timer interrupts and hit them from time to time -> get accounted).
=============
(3) 2.6.21-rc5 + sd-0.39
Here the results are similar to (2).
Cpu(s): 10.6% us, 0.0% sy, 0.0% ni, 89.4% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3624 dimm 20 0 1460 428 352 S 5.0 0.2 0:01.50 tenp2 3625 dimm 20 0 1460 108 32 S 4.6 0.0 0:00.76 tenp2 2797 root 20 0 27112 13m 2128 S 0.3 5.6 0:18.62 X
Cpu(s): 2.0% us, 0.3% sy, 0.0% ni, 97.7% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3738 dimm 20 0 1460 432 352 S 0.3 0.2 0:00.60 tenp2 3739 dimm 20 0 1460 112 32 S 0.3 0.0 0:00.18 tenp2
and now let's run both tenp and tenp15
look at the "tenp" below
/1/
Tasks: 82 total, 10 running, 72 sleeping, 0 stopped, 0 zombie
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3760 dimm 31 0 1464 112 32 S 7.9 0.0 0:01.82 tenp15 3773 dimm 31 0 1460 432 352 R 7.2 0.2 0:01.24 tenp 3758 dimm 31 0 1464 112 32 S 6.9 0.0 0:01.73 tenp15 3759 dimm 31 0 1464 112 32 S 6.9 0.0 0:01.65 tenp15 3757 dimm 31 0 1464 432 352 R 6.2 0.2 0:01.89 tenp15 3762 dimm 31 0 1464 112 32 R 6.2 0.0 0:01.70 tenp15 3763 dimm 31 0 1464 112 32 S 6.2 0.0 0:01.75 tenp15 3765 dimm 31 0 1464 112 32 S 6.2 0.0 0:01.82 tenp15 3767 dimm 31 0 1464 112 32 S 6.2 0.0 0:01.73 tenp15 3764 dimm 31 0 1464 112 32 R 5.9 0.0 0:01.70 tenp15 3769 dimm 31 0 1464 112 32 R 5.9 0.0 0:01.65 tenp15 3761 dimm 31 0 1464 112 32 S 5.6 0.0 0:01.66 tenp15 3766 dimm 31 0 1464 112 32 R 5.6 0.0 0:01.68 tenp15 3768 dimm 31 0 1464 112 32 R 5.6 0.0 0:01.77 tenp15 3771 dimm 31 0 1464 112 32 R 5.6 0.0 0:01.72 tenp15 3770 dimm 31 0 1464 112 32 S 5.2 0.0 0:01.54 tenp15 3178 dimm 20 0 28996 13m 9m R 0.7 5.6 0:17.49 konsole
and now let's kill tenp15 so tenp remains alone.
Cpu(s): 0.0% us, 0.3% sy, 0.0% ni, 99.7% id, 0.0% wa, 0.0% hi, 0.0% si
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3773 dimm 20 0 1460 432 352 S 0.3 0.2 0:03.59 tenp 3775 dimm 20 0 2120 1000 772 R 0.3 0.4 0:00.19 top
strange.
I doesn't happen for tenp15 (each always consumes ~6%). I repeated about 10 times.
Well, it's a late hour, so maybe I'm missing something... but it does look to be HZ and "will run" time interval related issue. Like described in (*). Or maybe we both observe similar situations but have different reasons behind them.
> -Mike
-- Best regards, Dmitry Adamushko - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
|  |