Kai Henningsen wrote:
>
> So: IMAO, the right way is (1) fix those areas where you can see that
> there is obviously a local problem
Yes.
Linus is okay with the addition of a few tasteful and carefully designed
conditional_reschedule() calls to work around this issue in 2.4.
Robert & co are okay with an _occasional_ scheduling delay - with a
sufficiently powerful and correctly set up machine, it could well be
that a tiny subset of the low-latency patch will fix their problems.
So the way forward is to identify the worst
areas where these stalls are occuring and try to cleanly fix them.
Surely?
I've done a few measurements on a 2x500MHz machine. Both of the
attached files show results across a kernel build. All times (min, max,
avg, total) are in microseconds.
syscalls.txt shows the amount of wall-clock time a CPU spent in a
particular system call.
copy_usr.txt shows the elapsed time which the system spent in
copy_to_user and copy_from_user. Again, this is wall-clock time, so any
interrupt which occurs will add to these times.
These numbers aren't particularly useful yet, but they can be improved
when I understand the problem better.
They do show that the longest time that was ever spent in copy_*_user()
was 570 uSecs, which would suggest that this was simply a convenient
place for the conditional_reschedule rather than being a CPU pig in
itself.
They also show that sys_brk can sometimes take a very long time. I
really don't see why this should be, as at no time during the build did
I have less than 50Mbytes of free memory.
I'll try stopping & restarting the instrumentation within
schedule(). This will give the _real_ scheduling latency figures.
(eek. That's going to take a lot of coding. Several days worth).
Does anyone actually _know_ where the problems are occurring?
Has anyone incrementally applied the low-latency patch to see which
fixes are the most effective?
Robert, Paul: test cases, please. Can you please tell me what system
activity causes the most problems? Is there a particular system
activity or application which will reliably kill scheduling latency? If
I can't reproduce it here will you be able to apply a truckload of
patches (against 2.4.0) so we can get to the bottom of it?
Generally speaking, can we please all stop shouting at each other and,
umm, y'know, do some technical stuff?
nr_times min max avg total
start 0162:0 -> stop 0162:0 13 70.37 36867305.82 3293742.81 42818656.54 nanosleep
start 0003:0 -> stop 0003:0 135604 .56 15004292.07 2476.55 335830746.49 read
start 0142:0 -> stop 0142:0 1173 5.91 9447280.43 196672.32 230696638.97 select
start 0114:0 -> stop 0114:0 1186 .73 3092356.14 14327.26 16992136.44 wait4
start 0001:0 -> stop 0001:0 2345 193.44 2461665.00 3525.92 8268285.36 exit
start 0179:0 -> stop 0179:0 8 33.84 827280.09 231713.72 1853709.82 sigsuspend
start 0036:0 -> stop 0036:0 7 1096.74 552073.82 94707.80 662954.64 sync
start 0011:0 -> stop 0011:0 10263 4.86 209516.45 321.38 3298342.53 execve
start 0004:0 -> stop 0004:0 57305 .51 157715.44 198.77 11391008.91 write
start 0045:0 -> stop 0045:0 445810 .36 154005.14 46.65 20798458.34 brk
start 0106:0 -> stop 0106:0 26645 3.58 131423.69 62.20 1657500.39 newstat
start 0107:0 -> stop 0107:0 13252 3.99 115579.30 465.08 6163361.26 newlstat
start 0006:0 -> stop 0006:0 89874 .36 94709.37 18.07 1624571.03 close
start 0091:0 -> stop 0091:0 6185 3.90 67443.46 69.94 432613.09 munmap
start 0141:0 -> stop 0141:0 11893 1.00 64348.94 577.40 6867067.92 getdents
start 0163:0 -> stop 0163:0 451 7.83 56350.26 217.21 97963.51 mremap
start 0005:0 -> stop 0005:0 91666 4.34 52861.29 78.71 7215900.72 open
start 0010:0 -> stop 0010:0 841 12.66 34119.20 4257.77 3580788.44 unlink
start 0190:0 -> stop 0190:0 458 121.83 14801.81 476.59 218279.86 vfork
start 0090:0 -> stop 0090:0 21435 3.81 3003.70 23.05 494310.97 old_mmap
start 0174:0 -> stop 0174:0 12821 1.63 2573.70 9.20 118002.73 sigaction
start 0108:0 -> stop 0108:0 143415 1.95 1905.15 5.58 800491.94 newfstat
start 0002:0 -> stop 0002:0 474 280.81 1871.95 690.97 327522.48
start 0140:0 -> stop 0140:0 18254 .71 1693.63 4.99 91223.08
start 0033:0 -> stop 0033:0 4632 3.93 1650.84 20.16 93419.69
start 0136:0 -> stop 0136:0 2141 .89 1622.48 5.97 12802.72
start 0102:0 -> stop 0102:0 76 2.87 1455.19 114.84 8728.43
start 0183:0 -> stop 0183:0 891 5.17 882.27 31.21 27815.30
start 0013:0 -> stop 0013:0 827 .22 824.68 5.43 4495.74
start 0020:0 -> stop 0020:0 3414 .28 716.18 3.74 12775.20
start 0064:0 -> stop 0064:0 444 .93 630.36 8.55 3799.04
start 0019:0 -> stop 0019:0 222 .69 587.30 9.52 2115.35
start 0077:0 -> stop 0077:0 396 5.97 573.17 18.57 7357.43
start 0175:0 -> stop 0175:0 61629 1.49 534.16 3.19 197253.19
start 0024:0 -> stop 0024:0 441 .87 411.62 2.62 1157.10
start 0042:0 -> stop 0042:0 860 13.14 361.09 98.22 84477.00
start 0038:0 -> stop 0038:0 7 173.26 350.43 250.61 1754.33
start 0055:0 -> stop 0055:0 6201 .61 335.95 3.13 19431.05
start 0012:0 -> stop 0012:0 5517 2.35 286.69 5.84 32225.35
start 0041:0 -> stop 0041:0 1355 .91 274.12 8.44 11441.32
start 0054:0 -> stop 0054:0 528 .77 240.24 27.84 14704.30
start 0063:0 -> stop 0063:0 553 .97 201.58 15.87 8780.12
start 0075:0 -> stop 0075:0 351 3.87 190.89 8.37 2940.38
start 0065:0 -> stop 0065:0 440 .50 185.62 1.88 830.60
start 0047:0 -> stop 0047:0 441 .31 167.92 1.71 758.69
start 0125:0 -> stop 0125:0 3479 3.02 142.88 18.28 63616.59
start 0078:0 -> stop 0078:0 396 1.83 104.46 14.27 5653.10
start 0040:0 -> stop 0040:0 1 70.48 70.48 70.48 70.48
start 0066:0 -> stop 0066:0 24 32.42 69.86 52.27 1254.73
start 0015:0 -> stop 0015:0 19 3.06 60.51 17.98 341.66
start 0122:0 -> stop 0122:0 494 3.22 54.50 16.16 7983.98
start 0119:0 -> stop 0119:0 1545 .74 38.63 7.79 12044.13
start 0027:0 -> stop 0027:0 135 1.36 35.71 12.70 1715.26
start 0037:0 -> stop 0037:0 1 31.51 31.51 31.51 31.51
start 0076:0 -> stop 0076:0 350 4.59 21.72 9.36 3277.34
start 0057:0 -> stop 0057:0 13 3.33 20.13 5.96 77.59
start 0023:0 -> stop 0023:0 24 5.25 18.07 10.37 248.91
start 0081:0 -> stop 0081:0 24 5.72 17.80 10.67 256.29
start 0080:0 -> stop 0080:0 40 5.17 16.33 9.17 366.90
start 0182:0 -> stop 0182:0 4 8.53 12.21 10.00 40.04
start 0043:0 -> stop 0043:0 26 4.10 10.59 6.27 163.17
start 0046:0 -> stop 0046:0 24 2.81 10.18 5.35 128.59
start 0030:0 -> stop 0030:0 1 8.02 8.02 8.02 8.02
start 0133:0 -> stop 0133:0 4 3.94 6.10 4.60 18.41
start 0049:0 -> stop 0049:0 442 .28 3.14 .31 137.64
start 0060:0 -> stop 0060:0 21 .25 2.17 1.00 21.11
start 0050:0 -> stop 0050:0 439 .27 .70 .28 126.74
nr_times min max avg total
pipe.c:97 -> pipe.c:97 45522 .27 574.81 90.66 4127268.07
pipe.c:195 -> pipe.c:195 45478 .27 603.22 80.32 3652920.80
filemap.c:2518 -> filemap.c:2518 55059 .27 571.44 49.63 2732940.67
stat.c:114 -> stat.c:114 173223 .25 222.73 .42 73837.04
exec.c:227 -> exec.c:227 183500 .27 268.69 .35 65460.86
readdir.c:185 -> readdir.c:185 122832 .26 86.13 .36 45271.27
signal.c:684 -> signal.c:684 58938 .18 93.24 .26 15989.74
sys_i386.c:102 -> sys_i386.c:102 21386 .21 222.89 .52 11197.06
signal.c:720 -> signal.c:720 30725 .19 83.39 .26 8081.66
n_tty.c:913 -> n_tty.c:913 1808 .28 42.42 3.28 5935.69
read_write.c:107 -> read_write.c:107 18218 .20 51.80 .29 5411.32
signal.c:1075 -> signal.c:1075 12752 .20 68.96 .38 4907.51
signal.c:1068 -> signal.c:1068 12752 .20 52.59 .32 4162.93
sys.c:968 -> sys.c:968 494 .80 32.63 7.10 3510.72
n_tty.c:255 -> n_tty.c:255 2837 .26 9.42 .91 2597.98
dcache.c:990 -> dcache.c:990 885 .36 13.34 1.76 1558.34
iovec.c:91 -> iovec.c:91 439 .27 60.92 1.10 485.22
sys.c:1137 -> sys.c:1137 392 .27 3.65 1.19 468.70
sys_i386.c:38 -> sys_i386.c:38 859 .18 2.15 .46 401.77
tty_ioctl.c:401 -> tty_ioctl.c:401 161 .24 4.89 2.40 387.69
time.c:118 -> time.c:118 396 .19 77.61 .93 369.31
sys.c:1069 -> sys.c:1069 350 .30 21.00 .99 349.43
sys.c:1058 -> sys.c:1058 350 .26 2.54 .80 281.74
tcp.c:901 -> tcp.c:901 111 .28 19.61 1.84 204.83
pty.c:158 -> pty.c:158 415 .28 2.34 .46 195.14
socket.c:1476 -> socket.c:1476 77 .26 4.12 1.31 101.36
uid16.c:122 -> uid16.c:122 40 .36 5.02 2.00 80.34
timer.c:842 -> timer.c:842 24 .22 10.89 2.03 48.80
uid16.c:137 -> uid16.c:137 24 .61 3.85 2.02 48.57
generic.c:107 -> generic.c:107 1 46.91 46.91 46.91 46.91
ide.c:2592 -> ide.c:2592 12 1.16 8.81 3.13 37.58
tty_ioctl.c:159 -> tty_ioctl.c:159 47 .24 2.86 .77 36.43
time.c:122 -> time.c:122 26 .19 2.75 1.36 35.54
timer.c:814 -> timer.c:814 36 .18 2.89 .84 30.39
sys.c:749 -> sys.c:749 26 .40 2.94 1.06 27.64
tty_io.c:1491 -> tty_io.c:1491 27 .19 2.26 .55 15.06
ide.c:2567 -> ide.c:2567 12 .71 2.25 1.18 14.19
signal.c:103 -> signal.c:103 13 .41 1.77 .86 11.29
socket.c:219 -> socket.c:219 9 .39 2.25 .93 8.44
tty_io.c:1501 -> tty_io.c:1501 9 .21 .57 .25 2.27
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/
This archive was generated by hypermail 2b29 : Fri Jul 07 2000 - 21:00:10 EST