* extremely slow disk access due to mremap?
@ 2005-08-26 15:09 Justin Heesemann
2005-08-26 16:27 ` Diego Calleja
0 siblings, 1 reply; 2+ messages in thread
From: Justin Heesemann @ 2005-08-26 15:09 UTC (permalink / raw)
To: linux-kernel
hello.
i've been experiencing a strange problem on two computers.
disk access is sometimes very slow. e.g.
copying files or downloading them via http first is quite fast, then
stalls at a certain points (after 1 min or so it starts again..)
finally i found a good reproducable way to test this behavior:
# time grep ^....$ /usr/share/dict/words > /dev/null
real 0m7.728s
user 0m7.713s
sys 0m0.011s
the words file size is 400k.
since these two computers are supposed to be fast (2GB Ram, one has a
Adaptec Smartraid V raid controller, the other one a Mylex DAC960PG)
and the same operation takes only
# time grep ^....$ /usr/share/dict/words > /dev/null
real 0m0.223s
user 0m0.197s
sys 0m0.024s
on another much slower computer, i was wondering.
stracing the whole process shed some light:
....
open("/usr/share/dict/words", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=408865, ...}) = 0
read(3, "Aarhus\nAaron\nAbaba\naback\nabaft\na"..., 32768) = 32768
brk(0) = 0x8086000
brk(0x80b9000) = 0x80b9000
fstat64(1, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), ...}) = 0
ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfddaf24) = -1 ENOTTY
(Inappropriate ioctl for device)
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x40177000
read(3, "ions\navert\naverted\naverting\naver"..., 32768) = 32768
mmap2(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x40178000
mremap(0x40178000, 135168, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 131072, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 131072, 126976, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 126976, 126976, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 126976, 126976, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 126976, 126976, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 126976, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 122880, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 122880, 118784, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 118784, 118784, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 118784, 118784, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 118784, 118784, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 118784, 118784, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 118784, 118784, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 118784, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 114688, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 114688, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 110592, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 110592, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 106496, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 106496, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 102400, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 102400, 98304, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 98304, 98304, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 98304, 98304, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 98304, 98304, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 98304, 94208, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 94208, 94208, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 94208, 94208, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 94208, 94208, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 94208, 90112, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 90112, 90112, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 90112, 90112, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 90112, 90112, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 90112, 90112, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 90112, 90112, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 90112, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 86016, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 86016, 81920, MREMAP_MAYMOVE) = 0x40178000
mremap(0x40178000, 81920, 81920, MREMAP_MAYMOVE) = 0x40178000
... (this goes on, until it has reached 4096, then another read starts,
again lots of lots of mremaps...)
whilest should look something like this (straced from the epia box):
....
open("/usr/share/dict/words", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2486824, ...}) = 0
read(3, "A\na\naa\naal\naalii\naam\nAani\naardva"..., 32768) = 32768
fstat64(1, {st_mode=S_IFCHR|0777, st_rdev=makedev(1, 3), ...}) = 0
ioctl(1, SNDCTL_TMR_TIMEBASE, 0xbfffdb24) = -1 ENOTTY (Inappropriate
ioctl for device)
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7e62000
read(3, "tasia\naerial\naerialist\naeriality"..., 32768) = 32768
read(3, "ulancer\nambulant\nambulate\nambula"..., 32768) = 32768
read(3, "ize\nanthology\nantholysis\nAntholy"..., 32768) = 32768
write(1, "Aani\nAaru\nabac\nabas\nAbba\nAbby\nab"..., 1024) = 1024
read(3, "rborator\narboreal\narboreally\narb"..., 32768) = 32768
...
why all those mremap calls?
i've tried different kernels (2.4.31, 2.6.12.4 and 2.6.5) with highmem
support and without. same results.
the funny thing is: if i don't grep for a regexp, it's working fine:
# grep asdf /usr/share/dict/words
...
open("/usr/share/dict/words", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=408865, ...}) = 0
read(3, "Aarhus\nAaron\nAbaba\naback\nabaft\na"..., 32768) = 32768
read(3, "ions\navert\naverted\naverting\naver"..., 32768) = 32768
read(3, "ton\ncartons\ncartoon\ncartoons\ncar"..., 32768) = 32768
read(3, "\ncreators\ncreature\ncreatures\ncre"..., 32768) = 32768
read(3, "\nEisner\neither\nejaculate\nejacula"..., 32768) = 32768
read(3, "\ngangling\ngangplank\ngangrene\ngan"..., 32768) = 32768
read(3, "ormant\ninformants\nInformatica\nin"..., 32768) = 32768
read(3, "ker\nmarkers\nmarket\nmarketability"..., 32768) = 32768
read(3, "overhangs\noverhaul\noverhauling\no"..., 32768) = 32768
read(3, "purse\npursed\npurser\npurses\npursu"..., 32768) = 32768
read(3, "hweitzer\nscience\nsciences\nscient"..., 32768) = 32768
read(3, "sidize\nsubsidized\nsubsidizes\nsub"..., 32768) = 32768
read(3, "cuous\nvacuously\nvacuum\nvacuumed\n"..., 32768) = 15649
read(3, "", 20480) = 0
close(3) = 0
...
since right now i'm out of ideas what to look for next, could you please
help me?
--
Justin Heesemann
^ permalink raw reply [flat|nested] 2+ messages in thread
* Re: extremely slow disk access due to mremap?
2005-08-26 15:09 extremely slow disk access due to mremap? Justin Heesemann
@ 2005-08-26 16:27 ` Diego Calleja
0 siblings, 0 replies; 2+ messages in thread
From: Diego Calleja @ 2005-08-26 16:27 UTC (permalink / raw)
To: Justin Heesemann; +Cc: linux-kernel
El Fri, 26 Aug 2005 17:09:58 +0200,
Justin Heesemann <jh@ionium.org> escribió:
> finally i found a good reproducable way to test this behavior:
>
> # time grep ^....$ /usr/share/dict/words > /dev/null
>
> real 0m7.728s
> user 0m7.713s
> sys 0m0.011s
The problem seems (IMO) to be in userspace, your software seems to be doing
too much stuff for no good reason. If grep calls mremap() too many times
that's their problem; and even if it's doing that, the kernel is doing the
mremap() stuff quite fast
> the funny thing is: if i don't grep for a regexp, it's working fine:
> # grep asdf /usr/share/dict/words
[...]
> since right now i'm out of ideas what to look for next, could you please
> help me?
Maybe a bug in the regexp code in your /bin/grep? Are you using
different distro/versions in your two boxes?
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2005-08-26 16:27 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2005-08-26 15:09 extremely slow disk access due to mremap? Justin Heesemann
2005-08-26 16:27 ` Diego Calleja
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®