Re: first mkdir takes a long time (on ext3)
On Thu, 19 May 2011, Hartmut Niemann wrote:
I observe that it often takes very long time (20s) to mkdir on an ext3 drive,
especially the first directory.
What could the reason be?
I used to have that problem. I never figured out the cause, but it
disappeared when I upgraded from kernel 2.6.33 to 2.6.38.
I my case, mkdir was slow the first time it's executed after evicting
pagecache (either via `echo 1 > /proc/sys/vm/drop_caches`, or any
memory-intensive operation.)
All of the time was spent in the mkdir syscall itself:
strace -r mkdir foo
0.000000 execve("/bin/mkdir", ["mkdir", "foo"], [/* 63 vars */]) = 0
0.021878 brk(0) = 0x60c000
0.000053 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbc65a8a000
0.000035 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
0.000021 open("/etc/ld.so.cache", O_RDONLY) = 3
0.000020 fstat(3, {st_mode=S_IFREG|0644, st_size=104398, ...}) = 0
0.000027 mmap(NULL, 104398, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fbc65a70000
0.000018 close(3) = 0
0.000026 open("/lib/libc.so.6", O_RDONLY) = 3
0.000022 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\354\1\0\0\0\0\0"..., 832) = 832
0.000026 fstat(3, {st_mode=S_IFREG|0755, st_size=1420568, ...}) = 0
0.000029 mmap(NULL, 3528744, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fbc65510000
0.000020 mprotect(0x7fbc65665000, 2093056, PROT_NONE) = 0
0.000019 mmap(0x7fbc65864000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x154000) = 0x7fbc65864000
0.000025 mmap(0x7fbc65869000, 18472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fbc65869000
0.000022 close(3) = 0
0.000024 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbc65a6f000
0.000023 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbc65a6e000
0.000020 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbc65a6d000
0.000020 arch_prctl(ARCH_SET_FS, 0x7fbc65a6e700) = 0
0.000087 mprotect(0x7fbc65864000, 16384, PROT_READ) = 0
0.000022 mprotect(0x60a000, 4096, PROT_READ) = 0
0.000019 mprotect(0x7fbc65a8b000, 4096, PROT_READ) = 0
0.000017 munmap(0x7fbc65a70000, 104398) = 0
0.000099 brk(0) = 0x60c000
0.000015 brk(0x62d000) = 0x62d000
0.000022 open("/usr/lib64/locale/locale-archive", O_RDONLY) = 3
0.000025 fstat(3, {st_mode=S_IFREG|0644, st_size=3677376, ...}) = 0
0.000028 mmap(NULL, 3677376, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fbc6518e000
0.000020 close(3) = 0
0.000051 mkdir("foo", 0777) = 0
2.770282 close(1) = 0
0.000030 close(2) = 0
0.000025 exit_group(0) = ?
The next step would have been to apply blktrace to figure out what
exactly was being loaded from disk, but I stopped looking when the upgrade
fixed it.
Reply to: