linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* 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

* 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-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

* 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-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

* 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-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 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

* [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

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).