* Re: [BENCHMARK] 2.5.46-mm1 with contest
@ 2002-11-08 0:32 Alan Willis
2002-11-08 0:48 ` Andrew Morton
0 siblings, 1 reply; 15+ messages in thread
From: Alan Willis @ 2002-11-08 0:32 UTC (permalink / raw)
To: linux-kernel
> Why? We are preempting during the generic file write/read routines, I
> bet, which can otherwise be long periods of latency. CPU is up and I
> bet the throughput is down, but his test is getting the attention it
> wants.
I'm curious, would running contest after a fresh boot and with profile=2
provide a profile that tells exactly where time is being spent? Since
about 2.5.45 I've had some strange slow periods, and starting aterm
would take a while, redrawing windows in X would slow down, it 'feels'
like my workstation becomes a laptop that is just waking up. Sometimes
this is after only a few minutes of inactivity, or after switching
virtual desktops in kde, or when I have alot of aterm instances running.
Normal activity for me involves untarring and compiling lots of
software on a regular basis, on a 1.2Ghz celeron and 256mb of mem. I'm
using 2.5.46+reiser4 patches at the moment. I'll boot to 2.5.46-mm1
shortly, but I'd love to use reiser4 with akpm's tree though.
Would oprofile help figure out why aterm gets so effing slow at times?
I guess I need to sit down and figure out how to use it.
-alan
^ permalink raw reply [flat|nested] 15+ messages in thread* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-08 0:32 [BENCHMARK] 2.5.46-mm1 with contest Alan Willis @ 2002-11-08 0:48 ` Andrew Morton 2002-11-08 21:08 ` Alan Willis 0 siblings, 1 reply; 15+ messages in thread From: Andrew Morton @ 2002-11-08 0:48 UTC (permalink / raw) To: alan; +Cc: linux-kernel Alan Willis wrote: > > > Why? We are preempting during the generic file write/read routines, I > > bet, which can otherwise be long periods of latency. CPU is up and I > > bet the throughput is down, but his test is getting the attention it > > wants. > > I'm curious, would running contest after a fresh boot and with profile=2 > provide a profile that tells exactly where time is being spent? Since > about 2.5.45 I've had some strange slow periods, and starting aterm > would take a while, redrawing windows in X would slow down, it 'feels' > like my workstation becomes a laptop that is just waking up. Sometimes > this is after only a few minutes of inactivity, or after switching > virtual desktops in kde, or when I have alot of aterm instances running. - Run `vmstat 1', and see if the slowdowns coincide with any unusual IO activity. - Could be the scheduler. Try renice -19 $(pidof X) $(pidof aterm) $(pidof other stuff) ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-08 0:48 ` Andrew Morton @ 2002-11-08 21:08 ` Alan Willis 2002-11-08 21:21 ` Andrew Morton 0 siblings, 1 reply; 15+ messages in thread From: Alan Willis @ 2002-11-08 21:08 UTC (permalink / raw) To: akpm; +Cc: linux-kernel [-- Attachment #1: Type: text/plain, Size: 3678 bytes --] Ok, it just happened again. Everything got slow, changing desktops, starting new aterms,. etc. I flipped to a tty, and started a vmstat log, and went back into X, and reprioritised stuff with a terminal that was just bearably slow enough to work. After renicing X stuff got a bit better. A little. After renicing my aterms, it got slightly better still. alan@aries:~$ sudo renice -19 `pgrep X` 499: old priority 0, new priority -19 alan@aries:~$ sudo renice -19 `pgrep aterm` 686: old priority 0, new priority -19 818: old priority 0, new priority -19 1030: old priority 0, new priority -19 1130: old priority 0, new priority -19 1202: old priority 0, new priority -19 1691: old priority 0, new priority -19 1762: old priority 0, new priority -19 2013: old priority 0, new priority -19 2164: old priority 0, new priority -19 2281: old priority 0, new priority -19 2406: old priority 0, new priority -19 2490: old priority 0, new priority -19 2558: old priority 0, new priority -19 2559: old priority 0, new priority -19 2838: old priority 0, new priority -19 3050: old priority 0, new priority -19 3056: old priority 0, new priority -19 3158: old priority 0, new priority -19 After flipping back to my vmstat log tty, I found that vmstat had segfaulted instead of run, I didnt see it because I ran it in the background and ran a tail of the file it was supposed to log to. I'm using procps 2.0.7 as distributed in RH8.0, which I assume is too old a version. I attached an strace of it running if anyone is curious. To give an example ofhow intermitently slow this is, I took one of my reniced aterms, and tried running aterm with the options I usually use. I started another instance of aterm elsewhere, and in my current terminal, I ran the following: alan@aries:~$ time /usr/local/bin/aterm -tr -trsb -fade 60 -bg blue -fg -e exit real 0m0.924s user 0m0.017s sys 0m0.014s alan@aries:~$ time /usr/local/bin/aterm -tr -trsb -fade 60 -bg blue -fg -e exit real 0m4.895s user 0m0.018s sys 0m0.018s alan@aries:~$ time /usr/local/bin/aterm -tr -trsb -fade 60 -bg blue -fg -e exit real 0m1.436s user 0m0.014s sys 0m0.018s alan@aries:~$ time /usr/local/bin/aterm -tr -trsb -fade 60 -bg blue -fg -e exit real 0m0.797s user 0m0.017s sys 0m0.017s alan@aries:~$ time /usr/local/bin/aterm -tr -trsb -fade 60 -bg blue -fg -e exit real 0m1.122s user 0m0.017s sys 0m0.019s I had enough time to run aterm this way about four times before I got that other instance of aterm to give me a usable prompt. I'll go upgrade my procps so I have a working vmstat for you next time, sorry about that. Whose shall I use? (riel/rml or calahan, or both?) -alan > Alan Willis wrote: >> >> > Why? We are preempting during the generic file write/read routines, >> I bet, which can otherwise be long periods of latency. CPU is up >> and I bet the throughput is down, but his test is getting the >> attention it wants. >> >> I'm curious, would running contest after a fresh boot and with >> profile=2 >> provide a profile that tells exactly where time is being spent? Since >> about 2.5.45 I've had some strange slow periods, and starting aterm >> would take a while, redrawing windows in X would slow down, it 'feels' >> like my workstation becomes a laptop that is just waking up. >> Sometimes this is after only a few minutes of inactivity, or after >> switching virtual desktops in kde, or when I have alot of aterm >> instances running. > > - Run `vmstat 1', and see if the slowdowns coincide with any unusual > IO activity. > > - Could be the scheduler. Try > renice -19 $(pidof X) $(pidof aterm) $(pidof other stuff) [-- Attachment #2: vmstat-strace.log --] [-- Type: application/octet-stream, Size: 21818 bytes --] execve("/usr/bin/vmstat", ["vmstat", "5"], [/* 23 vars */]) = 0 uname({sys="Linux", node="aries", ...}) = 0 brk(0) = 0x804d000 open("/etc/ld.so.preload", O_RDONLY) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=76458, ...}) = 0 old_mmap(NULL, 76458, PROT_READ, MAP_PRIVATE, 3, 0) = 0x40013000 close(3) = 0 open("/lib/libproc.so.2.0.7", O_RDONLY) = 3 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0p#\0\000"..., 1024) = 1024 fstat64(3, {st_mode=S_IFREG|0755, st_size=49311, ...}) = 0 old_mmap(NULL, 47880, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x40026000 mprotect(0x4002f000, 11016, PROT_NONE) = 0 old_mmap(0x4002f000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x9000) = 0x4002f000 old_mmap(0x40030000, 6920, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40030000 close(3) = 0 open("/lib/i686/libc.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220Y\1"..., 1024) = 1024 fstat64(3, {st_mode=S_IFREG|0755, st_size=1395734, ...}) = 0 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40032000 old_mmap(0x42000000, 1239844, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x42000000 mprotect(0x42126000, 35620, PROT_NONE) = 0 old_mmap(0x42126000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x126000) = 0x42126000 old_mmap(0x4212b000, 15140, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x4212b000 close(3) = 0 munmap(0x40013000, 76458) = 0 uname({sys="Linux", node="aries", ...}) = 0 open("/proc/uptime", O_RDONLY) = 3 lseek(3, 0, SEEK_SET) = 0 read(3, "85696.90 83983.95\n", 1023) = 18 open("/proc/stat", O_RDONLY) = 4 lseek(4, 0, SEEK_SET) = 0 read(4, "cpu 141741 587 44511 8346279 36"..., 1023) = 694 lseek(3, 0, SEEK_SET) = 0 read(3, "85696.90 83983.95\n", 1023) = 18 ioctl(1, 0x5413, {ws_row=22, ws_col=80, ws_xpixel=0, ws_ypixel=0}) = 0 fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 13), ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40013000 write(1, " procs me"..., 80) = 80 write(1, " r b w swpd free buff c"..., 80) = 80 open("/proc", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 5 fstat64(5, {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0 fcntl64(5, F_SETFD, FD_CLOEXEC) = 0 brk(0) = 0x804d000 brk(0x804e000) = 0x804e000 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 1000 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 688 open("/proc/1/stat", O_RDONLY) = 6 read(6, "1 (init) S 0 1 1 0 -1 256 80 536"..., 8191) = 195 close(6) = 0 open("/proc/2/stat", O_RDONLY) = 6 read(6, "2 (ksoftirqd/0) S 1 1 1 0 -1 656"..., 8191) = 129 close(6) = 0 open("/proc/3/stat", O_RDONLY) = 6 read(6, "3 (events/0) S 1 1 1 0 -1 65600 "..., 8191) = 131 close(6) = 0 open("/proc/4/stat", O_RDONLY) = 6 read(6, "4 (kswapd0) S 1 1 1 0 -1 1050688"..., 8191) = 130 close(6) = 0 open("/proc/5/stat", O_RDONLY) = 6 read(6, "5 (pdflush) S 1 1 1 0 -1 8256 0 "..., 8191) = 124 close(6) = 0 open("/proc/6/stat", O_RDONLY) = 6 read(6, "6 (pdflush) S 1 1 1 0 -1 8256 0 "..., 8191) = 125 close(6) = 0 open("/proc/7/stat", O_RDONLY) = 6 read(6, "7 (aio/0) S 1 1 1 0 -1 65600 0 0"..., 8191) = 127 close(6) = 0 open("/proc/8/stat", O_RDONLY) = 6 read(6, "8 (pagebufd) S 1 1 1 0 -1 2112 0"..., 8191) = 125 close(6) = 0 open("/proc/9/stat", O_RDONLY) = 6 read(6, "9 (pagebuf/0) S 1 1 1 0 -1 65600"..., 8191) = 131 close(6) = 0 open("/proc/10/stat", O_RDONLY) = 6 read(6, "10 (kseriod) S 1 1 1 0 -1 64 0 0"..., 8191) = 115 close(6) = 0 open("/proc/11/stat", O_RDONLY) = 6 read(6, "11 (kjournald) S 1 1 1 0 -1 64 0"..., 8191) = 126 close(6) = 0 open("/proc/108/stat", O_RDONLY) = 6 read(6, "108 (reiserfs/0) S 1 1 1 0 -1 65"..., 8191) = 140 close(6) = 0 open("/proc/109/stat", O_RDONLY) = 6 read(6, "109 (kjournald) S 1 1 1 0 -1 64 "..., 8191) = 132 close(6) = 0 open("/proc/110/stat", O_RDONLY) = 6 read(6, "110 (ktxnmgrd:wait) S 1 1 1 0 -1"..., 8191) = 136 close(6) = 0 open("/proc/350/stat", O_RDONLY) = 6 read(6, "350 (syslogd) S 1 350 350 0 -1 6"..., 8191) = 183 close(6) = 0 open("/proc/354/stat", O_RDONLY) = 6 read(6, "354 (klogd) S 1 354 354 0 -1 320"..., 8191) = 187 close(6) = 0 open("/proc/376/stat", O_RDONLY) = 6 read(6, "376 (gpm) S 1 376 376 0 -1 320 9"..., 8191) = 181 close(6) = 0 open("/proc/385/stat", O_RDONLY) = 6 read(6, "385 (crond) S 1 385 385 0 -1 64 "..., 8191) = 191 close(6) = 0 open("/proc/392/stat", O_RDONLY) = 6 read(6, "392 (login) S 1 392 392 0 -1 256"..., 8191) = 183 close(6) = 0 open("/proc/393/stat", O_RDONLY) = 6 read(6, "393 (login) S 1 393 393 0 -1 256"..., 8191) = 183 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 480 open("/proc/394/stat", O_RDONLY) = 6 read(6, "394 (mingetty) S 1 394 394 1027 "..., 8191) = 184 close(6) = 0 open("/proc/395/stat", O_RDONLY) = 6 read(6, "395 (mingetty) S 1 395 395 1028 "..., 8191) = 184 close(6) = 0 open("/proc/396/stat", O_RDONLY) = 6 read(6, "396 (mingetty) S 1 396 396 1029 "..., 8191) = 184 close(6) = 0 open("/proc/397/stat", O_RDONLY) = 6 read(6, "397 (mingetty) S 1 397 397 1030 "..., 8191) = 184 close(6) = 0 open("/proc/401/stat", O_RDONLY) = 6 read(6, "401 (bash) S 392 401 401 1025 48"..., 8191) = 207 close(6) = 0 open("/proc/465/stat", O_RDONLY) = 6 read(6, "465 (ssh-agent) S 1 465 465 0 -1"..., 8191) = 185 close(6) = 0 open("/proc/486/stat", O_RDONLY) = 6 read(6, "486 (startx) S 401 486 401 1025 "..., 8191) = 193 close(6) = 0 open("/proc/498/stat", O_RDONLY) = 6 read(6, "498 (xinit) S 486 486 401 1025 4"..., 8191) = 182 close(6) = 0 open("/proc/499/stat", O_RDONLY) = 6 read(6, "499 (X) S 498 499 401 0 -1 256 2"..., 8191) = 210 close(6) = 0 open("/proc/503/stat", O_RDONLY) = 6 read(6, "503 (startkde) S 498 503 401 102"..., 8191) = 198 close(6) = 0 open("/proc/559/stat", O_RDONLY) = 6 read(6, "559 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 199 close(6) = 0 open("/proc/562/stat", O_RDONLY) = 6 read(6, "562 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 189 close(6) = 0 open("/proc/565/stat", O_RDONLY) = 6 read(6, "565 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 186 close(6) = 0 open("/proc/567/stat", O_RDONLY) = 6 read(6, "567 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 190 close(6) = 0 open("/proc/581/stat", O_RDONLY) = 6 read(6, "581 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 188 close(6) = 0 open("/proc/583/stat", O_RDONLY) = 6 read(6, "583 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 187 close(6) = 0 open("/proc/584/stat", O_RDONLY) = 6 read(6, "584 (kwrapper) S 503 503 401 102"..., 8191) = 185 close(6) = 0 open("/proc/586/stat", O_RDONLY) = 6 read(6, "586 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 187 close(6) = 0 open("/proc/587/stat", O_RDONLY) = 6 read(6, "587 (kdeinit) S 559 559 559 0 -1"..., 8191) = 192 close(6) = 0 open("/proc/589/stat", O_RDONLY) = 6 read(6, "589 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 198 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 480 open("/proc/591/stat", O_RDONLY) = 6 read(6, "591 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 191 close(6) = 0 open("/proc/596/stat", O_RDONLY) = 6 read(6, "596 (kdeinit) S 1 559 559 0 -1 6"..., 8191) = 190 close(6) = 0 open("/proc/598/stat", O_RDONLY) = 6 read(6, "598 (pam-panel-icon) S 559 559 5"..., 8191) = 190 close(6) = 0 open("/proc/602/stat", O_RDONLY) = 6 read(6, "602 (kalarmd) S 1 559 559 0 -1 6"..., 8191) = 186 close(6) = 0 open("/proc/604/stat", O_RDONLY) = 6 read(6, "604 (pam_timestamp_c) S 598 559 "..., 8191) = 186 close(6) = 0 open("/proc/607/stat", O_RDONLY) = 6 read(6, "607 (gaim) S 559 559 559 0 -1 0 "..., 8191) = 189 close(6) = 0 open("/proc/608/stat", O_RDONLY) = 6 read(6, "608 (xchat) S 559 559 559 0 -1 0"..., 8191) = 193 close(6) = 0 open("/proc/619/stat", O_RDONLY) = 6 read(6, "619 (mozilla-bin) S 559 559 559 "..., 8191) = 211 close(6) = 0 open("/proc/651/stat", O_RDONLY) = 6 read(6, "651 (mozilla-bin) S 619 559 559 "..., 8191) = 203 close(6) = 0 open("/proc/652/stat", O_RDONLY) = 6 read(6, "652 (mozilla-bin) S 651 559 559 "..., 8191) = 198 close(6) = 0 open("/proc/653/stat", O_RDONLY) = 6 read(6, "653 (mozilla-bin) S 651 559 559 "..., 8191) = 193 close(6) = 0 open("/proc/654/stat", O_RDONLY) = 6 read(6, "654 (mozilla-bin) S 651 559 559 "..., 8191) = 195 close(6) = 0 open("/proc/677/stat", O_RDONLY) = 6 read(6, "677 (netstat) T 619 559 559 0 -1"..., 8191) = 132 close(6) = 0 open("/proc/686/stat", O_RDONLY) = 6 read(6, "686 (aterm) S 559 559 559 0 -1 0"..., 8191) = 186 close(6) = 0 open("/proc/687/stat", O_RDONLY) = 6 read(6, "687 (bash) S 686 687 687 34817 2"..., 8191) = 209 close(6) = 0 open("/proc/780/stat", O_RDONLY) = 6 read(6, "780 (java) S 619 559 559 0 -1 0 "..., 8191) = 198 close(6) = 0 open("/proc/791/stat", O_RDONLY) = 6 read(6, "791 (java) S 780 559 559 0 -1 64"..., 8191) = 199 close(6) = 0 open("/proc/792/stat", O_RDONLY) = 6 read(6, "792 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/793/stat", O_RDONLY) = 6 read(6, "793 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/794/stat", O_RDONLY) = 6 read(6, "794 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 480 open("/proc/795/stat", O_RDONLY) = 6 read(6, "795 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/796/stat", O_RDONLY) = 6 read(6, "796 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/797/stat", O_RDONLY) = 6 read(6, "797 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/798/stat", O_RDONLY) = 6 read(6, "798 (java) S 791 559 559 0 -1 64"..., 8191) = 191 close(6) = 0 open("/proc/799/stat", O_RDONLY) = 6 read(6, "799 (java) S 791 559 559 0 -1 64"..., 8191) = 189 close(6) = 0 open("/proc/800/stat", O_RDONLY) = 6 read(6, "800 (java) S 791 559 559 0 -1 64"..., 8191) = 189 close(6) = 0 open("/proc/802/stat", O_RDONLY) = 6 read(6, "802 (java) S 791 559 559 0 -1 64"..., 8191) = 189 close(6) = 0 open("/proc/803/stat", O_RDONLY) = 6 read(6, "803 (java) S 791 559 559 0 -1 64"..., 8191) = 190 close(6) = 0 open("/proc/804/stat", O_RDONLY) = 6 read(6, "804 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/805/stat", O_RDONLY) = 6 read(6, "805 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/808/stat", O_RDONLY) = 6 read(6, "808 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/809/stat", O_RDONLY) = 6 read(6, "809 (java) S 791 559 559 0 -1 64"..., 8191) = 188 close(6) = 0 open("/proc/810/stat", O_RDONLY) = 6 read(6, "810 (java) S 791 559 559 0 -1 64"..., 8191) = 189 close(6) = 0 open("/proc/818/stat", O_RDONLY) = 6 read(6, "818 (aterm) S 559 559 559 0 -1 0"..., 8191) = 186 close(6) = 0 open("/proc/819/stat", O_RDONLY) = 6 read(6, "819 (bash) S 818 819 819 34818 1"..., 8191) = 212 close(6) = 0 open("/proc/1030/stat", O_RDONLY) = 6 read(6, "1030 (aterm) S 559 559 559 0 -1 "..., 8191) = 187 close(6) = 0 open("/proc/1031/stat", O_RDONLY) = 6 read(6, "1031 (bash) S 1030 1031 1031 348"..., 8191) = 209 close(6) = 0 open("/proc/1102/stat", O_RDONLY) = 6 read(6, "1102 (java) S 791 559 559 0 -1 6"..., 8191) = 189 close(6) = 0 open("/proc/1130/stat", O_RDONLY) = 6 read(6, "1130 (aterm) S 559 559 559 0 -1 "..., 8191) = 188 close(6) = 0 open("/proc/1131/stat", O_RDONLY) = 6 read(6, "1131 (bash) S 1130 1131 1131 348"..., 8191) = 214 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 480 open("/proc/1202/stat", O_RDONLY) = 6 read(6, "1202 (aterm) S 559 559 559 0 -1 "..., 8191) = 186 close(6) = 0 open("/proc/1203/stat", O_RDONLY) = 6 read(6, "1203 (bash) S 1202 1203 1203 348"..., 8191) = 210 close(6) = 0 open("/proc/1637/stat", O_RDONLY) = 6 read(6, "1637 (su) S 819 1637 819 34818 1"..., 8191) = 201 close(6) = 0 open("/proc/1640/stat", O_RDONLY) = 6 read(6, "1640 (bash) S 1637 1640 819 3481"..., 8191) = 209 close(6) = 0 open("/proc/1691/stat", O_RDONLY) = 6 read(6, "1691 (aterm) S 559 559 559 0 -1 "..., 8191) = 187 close(6) = 0 open("/proc/1692/stat", O_RDONLY) = 6 read(6, "1692 (bash) S 1691 1692 1692 348"..., 8191) = 214 close(6) = 0 open("/proc/1762/stat", O_RDONLY) = 6 read(6, "1762 (aterm) S 559 559 559 0 -1 "..., 8191) = 186 close(6) = 0 open("/proc/1763/stat", O_RDONLY) = 6 read(6, "1763 (bash) S 1762 1763 1763 348"..., 8191) = 214 close(6) = 0 open("/proc/1832/stat", O_RDONLY) = 6 read(6, "1832 (ssh) S 1763 1832 1763 3482"..., 8191) = 197 close(6) = 0 open("/proc/1833/stat", O_RDONLY) = 6 read(6, "1833 (ssh) S 1692 1833 1692 3482"..., 8191) = 196 close(6) = 0 open("/proc/2013/stat", O_RDONLY) = 6 read(6, "2013 (aterm) S 559 559 559 0 -1 "..., 8191) = 186 close(6) = 0 open("/proc/2014/stat", O_RDONLY) = 6 read(6, "2014 (bash) S 2013 2014 2014 348"..., 8191) = 214 close(6) = 0 open("/proc/2164/stat", O_RDONLY) = 6 read(6, "2164 (aterm) S 559 559 559 0 -1 "..., 8191) = 186 close(6) = 0 open("/proc/2165/stat", O_RDONLY) = 6 read(6, "2165 (bash) S 2164 2165 2165 348"..., 8191) = 214 close(6) = 0 open("/proc/2234/stat", O_RDONLY) = 6 read(6, "2234 (bc) S 2165 2234 2165 34827"..., 8191) = 192 close(6) = 0 open("/proc/2281/stat", O_RDONLY) = 6 read(6, "2281 (aterm) S 559 559 559 0 -1 "..., 8191) = 186 close(6) = 0 open("/proc/2282/stat", O_RDONLY) = 6 read(6, "2282 (bash) S 2281 2282 2282 348"..., 8191) = 213 close(6) = 0 open("/proc/2351/stat", O_RDONLY) = 6 read(6, "2351 (ssh) S 2282 2351 2282 3482"..., 8191) = 197 close(6) = 0 open("/proc/2358/stat", O_RDONLY) = 6 read(6, "2358 (kdeinit) S 559 559 559 0 -"..., 8191) = 195 close(6) = 0 open("/proc/2391/stat", O_RDONLY) = 6 read(6, "2391 (ssh) S 2014 2391 2014 3482"..., 8191) = 196 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 480 open("/proc/2406/stat", O_RDONLY) = 6 read(6, "2406 (aterm) S 559 559 559 0 -1 "..., 8191) = 186 close(6) = 0 open("/proc/2409/stat", O_RDONLY) = 6 read(6, "2409 (bash) S 2406 2409 2409 348"..., 8191) = 210 close(6) = 0 open("/proc/2490/stat", O_RDONLY) = 6 read(6, "2490 (aterm) S 559 559 559 0 -1 "..., 8191) = 187 close(6) = 0 open("/proc/2491/stat", O_RDONLY) = 6 read(6, "2491 (bash) S 2490 2491 2491 348"..., 8191) = 214 close(6) = 0 open("/proc/2553/stat", O_RDONLY) = 6 read(6, "2553 (su) S 1131 2553 1131 34820"..., 8191) = 203 close(6) = 0 open("/proc/2558/stat", O_RDONLY) = 6 read(6, "2558 (aterm) S 559 559 559 0 -1 "..., 8191) = 184 close(6) = 0 open("/proc/2559/stat", O_RDONLY) = 6 read(6, "2559 (aterm) S 559 559 559 0 -1 "..., 8191) = 184 close(6) = 0 open("/proc/2561/stat", O_RDONLY) = 6 read(6, "2561 (su) S 687 2561 687 34817 2"..., 8191) = 201 close(6) = 0 open("/proc/2562/stat", O_RDONLY) = 6 read(6, "2562 (bash) S 2558 2562 2562 348"..., 8191) = 210 close(6) = 0 open("/proc/2564/stat", O_RDONLY) = 6 read(6, "2564 (bash) S 2559 2564 2564 348"..., 8191) = 209 close(6) = 0 open("/proc/2578/stat", O_RDONLY) = 6 read(6, "2578 (bash) S 2553 2578 1131 348"..., 8191) = 211 close(6) = 0 open("/proc/2599/stat", O_RDONLY) = 6 read(6, "2599 (bash) S 2561 2599 687 3481"..., 8191) = 210 close(6) = 0 open("/proc/2680/stat", O_RDONLY) = 6 read(6, "2680 (bash) S 393 2680 2680 1026"..., 8191) = 209 close(6) = 0 open("/proc/2838/stat", O_RDONLY) = 6 read(6, "2838 (aterm) S 559 559 559 0 -1 "..., 8191) = 184 close(6) = 0 open("/proc/2839/stat", O_RDONLY) = 6 read(6, "2839 (bash) S 2838 2839 2839 348"..., 8191) = 210 close(6) = 0 open("/proc/3056/stat", O_RDONLY) = 6 read(6, "3056 (aterm) S 559 559 559 0 -1 "..., 8191) = 184 close(6) = 0 open("/proc/3057/stat", O_RDONLY) = 6 read(6, "3057 (bash) S 3056 3057 3057 348"..., 8191) = 209 close(6) = 0 open("/proc/3158/stat", O_RDONLY) = 6 read(6, "3158 (aterm) S 559 559 559 0 -1 "..., 8191) = 184 close(6) = 0 open("/proc/3166/stat", O_RDONLY) = 6 read(6, "3166 (bash) S 3158 3166 3166 348"..., 8191) = 210 close(6) = 0 open("/proc/3411/stat", O_RDONLY) = 6 read(6, "3411 (su) S 2491 3411 2491 34829"..., 8191) = 203 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 96 open("/proc/3414/stat", O_RDONLY) = 6 read(6, "3414 (bash) S 3411 3414 2491 348"..., 8191) = 215 close(6) = 0 open("/proc/3461/stat", O_RDONLY) = 6 read(6, "3461 (mozilla-bin) S 651 559 559"..., 8191) = 192 close(6) = 0 open("/proc/3463/stat", O_RDONLY) = 6 read(6, "3463 (strace) S 3414 3463 2491 3"..., 8191) = 198 close(6) = 0 open("/proc/3464/stat", O_RDONLY) = 6 read(6, "3464 (vmstat) R 3463 3463 2491 3"..., 8191) = 179 close(6) = 0 getdents64(0x5, 0x804d038, 0x400, 0xbffffa6c) = 0 close(5) = 0 open("/proc/meminfo", O_RDONLY) = 5 lseek(5, 0, SEEK_SET) = 0 read(5, "MemTotal: 251332 kB\nMemFre"..., 1023) = 615 open("/proc/stat", O_RDONLY) = 6 read(6, "cpu 141742 587 44513 8346279 36"..., 8191) = 694 close(6) = 0 --- SIGSEGV (Segmentation fault) --- +++ killed by SIGSEGV +++ ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-08 21:08 ` Alan Willis @ 2002-11-08 21:21 ` Andrew Morton [not found] ` <YWxhbg==.a11f3fbc6d68c50c7f190513c1d3bacf@1037045821.cotse.net> 0 siblings, 1 reply; 15+ messages in thread From: Andrew Morton @ 2002-11-08 21:21 UTC (permalink / raw) To: alan; +Cc: linux-kernel Alan Willis wrote: > > Ok, it just happened again. That's good. > I'll go upgrade my procps so I have a working vmstat for you next time, > sorry about that. Whose shall I use? (riel/rml or calahan, or both?) Either should do. The surriel.com/procps one is presumably more redhatty, but whatever. Also, run top and see if something is burning CPU. /proc/meminfo, /proc/slabinfo, all that stuff. The clues will be in there somewhere - it's a matter of hunting around... ^ permalink raw reply [flat|nested] 15+ messages in thread
[parent not found: <YWxhbg==.a11f3fbc6d68c50c7f190513c1d3bacf@1037045821.cotse.net>]
* Re: [BENCHMARK] 2.5.46-mm1 with contest [not found] ` <YWxhbg==.a11f3fbc6d68c50c7f190513c1d3bacf@1037045821.cotse.net> @ 2002-11-11 21:03 ` Andrew Morton 2002-11-11 21:11 ` Alan Willis 0 siblings, 1 reply; 15+ messages in thread From: Andrew Morton @ 2002-11-11 21:03 UTC (permalink / raw) To: alan; +Cc: linux-kernel, vs Alan Willis wrote: > > Attached are the slabinfo, meminfo, and output of vmstat 1. My system > was almost unusable at the time, so I got what I could. I don't have > anything in my crontab. This morning my system had been sitting > quietly all weekend, I did a few things, and then removed a large > directory and untarred 2.5.47, less than a minute after which my system > got unbearably slow. > > It should be noted that I have a 2.5.46 + reiser4 patches, which I think > made a few changes under mm/. I also had a reiser4 partition mounted at > the time, with slightly under 1 million empty files in it. I hadn't > accessed it in a while though. > MemTotal: 251332 kB MemFree: 1748 kB MemShared: 0 kB Buffers: 352 kB Cached: 30040 kB This is presumably active mmapped memory. executable text. SwapCached: 41748 kB Active: 165064 kB That's a lot of active memory. Inactive: 976 kB HighTotal: 0 kB HighFree: 0 kB LowTotal: 251332 kB LowFree: 1748 kB SwapTotal: 1028152 kB SwapFree: 834084 kB Dirty: 0 kB Writeback: 0 kB Mapped: 164592 kB That's an awful lot of mapped memory. Have you been altering /proc/sys/vm/swappiness? Has some application run berzerk and used tons of memory? Slab: 7592 kB Committed_AS: 423120 kB PageTables: 1996 kB ReverseMaps: 69425 HugePages_Total: 15 HugePages_Free: 15 Hugepagesize: 4096 kB You've lost 60 megabytes in hugepages! Bill's patch (which is in .47) changes the initial number of hugetlb pages to zero, which is rather kinder. So I don't _think_ there's a leak here. It could be that your normal workload fits OK ito 256 megs, but thrashes when it is squeezed into 196 megs. Suggest you do `echo 0 > /proc/sys/vm/nr_hugepages' and retest. ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-11 21:03 ` Andrew Morton @ 2002-11-11 21:11 ` Alan Willis 2002-11-11 21:32 ` Andrew Morton 0 siblings, 1 reply; 15+ messages in thread From: Alan Willis @ 2002-11-11 21:11 UTC (permalink / raw) To: akpm; +Cc: alan, linux-kernel, vs > That's an awful lot of mapped memory. Have you been altering > /proc/sys/vm/swappiness? Has some application run berzerk > and used tons of memory? > > Slab: 7592 kB > Committed_AS: 423120 kB > PageTables: 1996 kB > ReverseMaps: 69425 > HugePages_Total: 15 > HugePages_Free: 15 > Hugepagesize: 4096 kB vm.swappiness was set to 0 > > You've lost 60 megabytes in hugepages! Bill's patch (which is in .47) > changes the initial number of hugetlb pages to zero, which is rather > kinder. > > So I don't _think_ there's a leak here. It could be that your > normal workload fits OK ito 256 megs, but thrashes when it is > squeezed into 196 megs. > > Suggest you do `echo 0 > /proc/sys/vm/nr_hugepages' and retest. Done, vm.nr_hugepages = 0 # from 15 I'll stick to 2.5.46 for a while yet I guess, to be sure. -alan ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-11 21:11 ` Alan Willis @ 2002-11-11 21:32 ` Andrew Morton 2002-11-13 0:14 ` Denis Vlasenko 0 siblings, 1 reply; 15+ messages in thread From: Andrew Morton @ 2002-11-11 21:32 UTC (permalink / raw) To: alan; +Cc: linux-kernel, vs Alan Willis wrote: > > > That's an awful lot of mapped memory. Have you been altering > > /proc/sys/vm/swappiness? Has some application run berzerk > > and used tons of memory? > > > > Slab: 7592 kB > > Committed_AS: 423120 kB > > PageTables: 1996 kB > > ReverseMaps: 69425 > > HugePages_Total: 15 > > HugePages_Free: 15 > > Hugepagesize: 4096 kB > > vm.swappiness was set to 0 OK ;) That sucker really works. I run my desktop machines (768M and 256M) at swappiness=80% or 90%. I end up with 10-20 megs in swap after a day or two, which seems about right. The default of 60 is probably a little too unswappy. > I'll stick to 2.5.46 for a while yet I guess, to be sure. Thanks. ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-11 21:32 ` Andrew Morton @ 2002-11-13 0:14 ` Denis Vlasenko 2002-11-12 20:07 ` Alan Willis 0 siblings, 1 reply; 15+ messages in thread From: Denis Vlasenko @ 2002-11-13 0:14 UTC (permalink / raw) To: Andrew Morton, alan; +Cc: linux-kernel, vs On 11 November 2002 19:32, Andrew Morton wrote: > That sucker really works. I run my desktop machines (768M and 256M) > at swappiness=80% or 90%. I end up with 10-20 megs in swap after a > day or two, which seems about right. The default of 60 is probably a > little too unswappy. I think swappiness should depend also on mem/disk latency ratio. Imagine you have 32Gb IDE 'disk' made internally of tons of DRAM chips (such things exist). I suppose you would like to swap more to it, since access times are not ~10 ms, they are more like 10 us. Hand tuning for optimal performance is doomed to be periodically obsoleted by technology jumps. Today RAM is 1000000 times faster than mass storage. Nobody knows what will happen in five years. -- vda ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-13 0:14 ` Denis Vlasenko @ 2002-11-12 20:07 ` Alan Willis 0 siblings, 0 replies; 15+ messages in thread From: Alan Willis @ 2002-11-12 20:07 UTC (permalink / raw) To: vda; +Cc: akpm, alan, linux-kernel, vs Still running 2.5.46, put more memory in this machine (I need it anyway, 256mb for what I do is truly masochistic) and now I have 384Mb. This time when pressuring memory (ever setup KDevelop for the first time and index your documentation? not pretty) things got a bit sluggish, then I tuned vm.swappiness to 50 (from 0). About a minute later it began swapping a bit more, and things are much better. When vm.swappiness was at 0, 1300 bytes were swapped. As I'm writing this, (vm.swappiness at 100) 39448 bytes are swapped, after less than five minutes. -alan > On 11 November 2002 19:32, Andrew Morton wrote: >> That sucker really works. I run my desktop machines (768M and 256M) >> at swappiness=80% or 90%. I end up with 10-20 megs in swap after a >> day or two, which seems about right. The default of 60 is probably a >> little too unswappy. > > I think swappiness should depend also on mem/disk latency ratio. > Imagine you have 32Gb IDE 'disk' made internally of tons of DRAM chips > (such things exist). I suppose you would like to swap more to it, > since access times are not ~10 ms, they are more like 10 us. > > Hand tuning for optimal performance is doomed to be periodically > obsoleted by technology jumps. Today RAM is 1000000 times faster > than mass storage. Nobody knows what will happen in five years. > -- > vda ^ permalink raw reply [flat|nested] 15+ messages in thread
* [BENCHMARK] 2.5.46-mm1 with contest @ 2002-11-07 22:53 Con Kolivas 2002-11-07 23:48 ` Robert Love 0 siblings, 1 reply; 15+ messages in thread From: Con Kolivas @ 2002-11-07 22:53 UTC (permalink / raw) To: linux kernel mailing list; +Cc: Andrew Morton -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Here are contest results showing 2.5.46-mm1 with preempt enabled. The other kernels have it disabled. noload: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 75.7 91 0 0 1.06 2.5.46 [2] 74.1 92 0 0 1.04 2.5.46-mm1 [5] 74.0 93 0 0 1.04 cacherun: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 69.3 99 0 0 0.97 2.5.46 [2] 67.9 99 0 0 0.95 2.5.46-mm1 [5] 68.9 99 0 0 0.96 process_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 190.6 36 166 63 2.67 2.5.45 [5] 91.0 75 33 27 1.27 2.5.46 [1] 92.9 74 36 29 1.30 2.5.46-mm1 [5] 82.7 82 21 21 1.16 Much improved ctar_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 97.3 79 1 5 1.36 2.5.46 [1] 98.3 80 1 7 1.38 2.5.46-mm1 [5] 95.3 80 1 5 1.33 xtar_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 207.6 37 2 7 2.91 2.5.46 [1] 113.5 67 1 8 1.59 2.5.46-mm1 [5] 227.1 34 3 7 3.18 Whatever was causing this to be high in 2.5.44-mm6 is still there now. io_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 284.1 28 20 10 3.98 2.5.46 [1] 600.5 13 48 12 8.41 2.5.46-mm1 [5] 134.3 58 6 8 1.88 Big change here. IO load is usually the one we feel the most. read_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 104.3 73 7 4 1.46 2.5.46 [1] 103.5 75 7 4 1.45 2.5.46-mm1 [5] 103.2 74 6 4 1.45 list_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 95.3 75 1 20 1.33 2.5.46 [1] 96.8 74 2 22 1.36 2.5.46-mm1 [5] 101.4 70 1 22 1.42 mem_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 226.9 33 50 2 3.18 2.5.46 [3] 148.0 51 34 2 2.07 2.5.46-mm1 [5] 180.5 41 35 1 2.53 And this remains relatively high but better than 2.5.44-mm6 Unfortunately I've only run this with preempt enabled so far and I believe many of the improvements are showing this effect. Con. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.2.0 (GNU/Linux) iD8DBQE9yu7eF6dfvkL3i1gRAqGIAJ9f6XFfwO0sQOVBn5qZPfAFY5JdlwCggOZt WXizAEgC23W+AURXApih9xc= =MCT0 -----END PGP SIGNATURE----- ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-07 22:53 Con Kolivas @ 2002-11-07 23:48 ` Robert Love 2002-11-07 23:58 ` Andrew Morton 0 siblings, 1 reply; 15+ messages in thread From: Robert Love @ 2002-11-07 23:48 UTC (permalink / raw) To: Con Kolivas; +Cc: linux kernel mailing list, Andrew Morton On Thu, 2002-11-07 at 17:53, Con Kolivas wrote: > io_load: > Kernel [runs] Time CPU% Loads LCPU% Ratio > 2.5.44-mm6 [3] 284.1 28 20 10 3.98 > 2.5.46 [1] 600.5 13 48 12 8.41 > 2.5.46-mm1 [5] 134.3 58 6 8 1.88 > > Big change here. IO load is usually the one we feel the most. Nice. > Unfortunately I've only run this with preempt enabled so far and I believe > many of the improvements are showing this effect. Since your aim is desktop performance, I would like it if you always ran with kernel preemption enabled. That is what we are targeting for desktop performance. Good job, Robert Love ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-07 23:48 ` Robert Love @ 2002-11-07 23:58 ` Andrew Morton 2002-11-08 0:04 ` Robert Love 2002-11-08 0:10 ` Benjamin LaHaise 0 siblings, 2 replies; 15+ messages in thread From: Andrew Morton @ 2002-11-07 23:58 UTC (permalink / raw) To: Robert Love; +Cc: Con Kolivas, linux kernel mailing list Robert Love wrote: > > On Thu, 2002-11-07 at 17:53, Con Kolivas wrote: > > > io_load: > > Kernel [runs] Time CPU% Loads LCPU% Ratio > > 2.5.44-mm6 [3] 284.1 28 20 10 3.98 > > 2.5.46 [1] 600.5 13 48 12 8.41 > > 2.5.46-mm1 [5] 134.3 58 6 8 1.88 > > > > Big change here. IO load is usually the one we feel the most. > > Nice. Mysterious. > > Unfortunately I've only run this with preempt enabled so far and I believe > > many of the improvements are showing this effect. > > Since your aim is desktop performance, I would like it if you always ran > with kernel preemption enabled. That is what we are targeting for > desktop performance. I'd be interested in average-of-five runs both with and without preemption. Preemption seemed to do odd things to process_load as well. gcc gained 10% and the "load" lost 40%. But the %LCPU fell only 25%, which is probably dodgy accounting. I wonder what's up with all that. ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-07 23:58 ` Andrew Morton @ 2002-11-08 0:04 ` Robert Love 2002-11-08 6:04 ` Con Kolivas 2002-11-08 0:10 ` Benjamin LaHaise 1 sibling, 1 reply; 15+ messages in thread From: Robert Love @ 2002-11-08 0:04 UTC (permalink / raw) To: Andrew Morton; +Cc: Con Kolivas, linux kernel mailing list On Thu, 2002-11-07 at 18:58, Andrew Morton wrote: > Robert Love wrote: > > > > On Thu, 2002-11-07 at 17:53, Con Kolivas wrote: > > > > > io_load: > > > Kernel [runs] Time CPU% Loads LCPU% Ratio > > > 2.5.44-mm6 [3] 284.1 28 20 10 3.98 > > > 2.5.46 [1] 600.5 13 48 12 8.41 > > > 2.5.46-mm1 [5] 134.3 58 6 8 1.88 > > > > > > Big change here. IO load is usually the one we feel the most. > > > > Nice. > > Mysterious. Why? We are preempting during the generic file write/read routines, I bet, which can otherwise be long periods of latency. CPU is up and I bet the throughput is down, but his test is getting the attention it wants. Robert Love ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-08 0:04 ` Robert Love @ 2002-11-08 6:04 ` Con Kolivas 0 siblings, 0 replies; 15+ messages in thread From: Con Kolivas @ 2002-11-08 6:04 UTC (permalink / raw) To: Robert Love, Andrew Morton, Benjamin LaHaise; +Cc: linux kernel mailing list -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Ok well I guess some more data is required to interpret this. >On Thu, 2002-11-07 at 18:58, Andrew Morton wrote: >> Robert Love wrote: >> > On Thu, 2002-11-07 at 17:53, Con Kolivas wrote: >> > > io_load: >> > > Kernel [runs] Time CPU% Loads LCPU% Ratio >> > > 2.5.44-mm6 [3] 284.1 28 20 10 3.98 >> > > 2.5.46 [1] 600.5 13 48 12 8.41 >> > > 2.5.46-mm1 [5] 134.3 58 6 8 1.88 >> > > >> > > Big change here. IO load is usually the one we feel the most. >> > >> > Nice. >> >> Mysterious. > >Why? We are preempting during the generic file write/read routines, I >bet, which can otherwise be long periods of latency. CPU is up and I >bet the throughput is down, but his test is getting the attention it >wants. Here are the results with 2.5.46-mm1 with and without preempt (2.5.46-mmnp) only where they _differ_ for clarity: process_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 190.6 36 166 63 2.67 2.5.46 [1] 92.9 74 36 29 1.30 2.5.46-mm1 [5] 82.7 82 21 21 1.16 2.5.46-mmnp [3] 93.8 72 37 29 1.31 Note that 2.5.46-mm1 without preempt here is comparable to 2.5.46 vanilla. Also, this one is prone to the process_load getting stuck endlessly piping data around and me having to kill the run. These were the 3 successful runs. Are the changes that fixed this problem in 2.5.44-mm6 backed out in 2.5.46-mm1? Also it seems interesting to me that preempt manages to break out of this loop and is not prone to that hang. io_load: Kernel [runs] Time CPU% Loads LCPU% Ratio 2.5.44-mm6 [3] 284.1 28 20 10 3.98 2.5.46 [1] 600.5 13 48 12 8.41 2.5.46-mm1 [5] 134.3 58 6 8 1.88 2.5.46-mmnp [4] 357.6 22 27 11 5.01 I guess this is the one we were most interested in and no doubt it takes less time with preempt enabled A few more things to clarify that were queried: Only the kernel compilation time and cpu% are accurate. The "Loads" field takes the total number of iterations done by the load over the duration of the load running and divides it by the time the load ran over the kernel compilation time. Thus it is not reliably accurate enough because the duration the load runs beyond kernel compilation time is variable :- It takes a variable length of time to kill the load. The load cpu% (lcpu%) is that spit out by "time load" and as I said this runs for longer than the kernel compilation so will be an overestimate. I haven't found a way around this. It seems to be routine that loads done drops disproportionately when kernel compilation shortens. This seems to be more a load accounting problem (dont have a fix for that). Furthermore, since kernel compilation is -j4 and the load is one task all at the same nice level it would seem to be ideal for kernel compilation time to increase by 5/4 (and ratio to equal 1.25) , and concomitantly for cpu% to drop to 4/5 (80%) of noload. Con. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.2.0 (GNU/Linux) iD8DBQE9y1PeF6dfvkL3i1gRAkNXAJ47qgYAd9mygNpF7KDnzyuR6xjX3ACeORH7 Eo3HgfvJ7hJe1ykoaPEEQyQ= =2L0b -----END PGP SIGNATURE----- ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: [BENCHMARK] 2.5.46-mm1 with contest 2002-11-07 23:58 ` Andrew Morton 2002-11-08 0:04 ` Robert Love @ 2002-11-08 0:10 ` Benjamin LaHaise 1 sibling, 0 replies; 15+ messages in thread From: Benjamin LaHaise @ 2002-11-08 0:10 UTC (permalink / raw) To: Andrew Morton; +Cc: Robert Love, Con Kolivas, linux kernel mailing list On Thu, Nov 07, 2002 at 03:58:48PM -0800, Andrew Morton wrote: > > Nice. > > Mysterious. Nah, that's the allocator changes kicking in. -ben -- "Do you seek knowledge in time travel?" ^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2002-11-12 20:07 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2002-11-08 0:32 [BENCHMARK] 2.5.46-mm1 with contest Alan Willis
2002-11-08 0:48 ` Andrew Morton
2002-11-08 21:08 ` Alan Willis
2002-11-08 21:21 ` Andrew Morton
[not found] ` <YWxhbg==.a11f3fbc6d68c50c7f190513c1d3bacf@1037045821.cotse.net>
2002-11-11 21:03 ` Andrew Morton
2002-11-11 21:11 ` Alan Willis
2002-11-11 21:32 ` Andrew Morton
2002-11-13 0:14 ` Denis Vlasenko
2002-11-12 20:07 ` Alan Willis
-- strict thread matches above, loose matches on Subject: below --
2002-11-07 22:53 Con Kolivas
2002-11-07 23:48 ` Robert Love
2002-11-07 23:58 ` Andrew Morton
2002-11-08 0:04 ` Robert Love
2002-11-08 6:04 ` Con Kolivas
2002-11-08 0:10 ` Benjamin LaHaise
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).