clone 413661 -1 reassign -1 nfs-kernel-server found -1 1:1.1.0-4 retitle -1 rpc.mountd eats CPU, issues tons of ioctls found 413661 e2fsprogs/1.39+1.40-wip-2006.11.14+dfsg-1 thanks
rpc.mountd on my NFS server stalls for several minutes at the first mount attempt from the client. During this time, "top" shows mountd eating some 90% of the CPU time. After a while it calms down, the mount succeeds and everything works. strace shows that mountd is issuing lots of ioctls during this time (over 20k calls in a minute or so). The system is a Linksys NSLU2 running Debian etch (arm), nfs-kernel-server 1.1.0-4, Debian kernel 2.6.21-1-ixp4xx. The configuration is NFSv4 with Kerberos authentication. Upstream suggested [1] that this was related to #413661, so I'm cloning the bug. I have about the same setup on other i386 servers where I didn't notice this behaviour. That may be because the NSLU2 is so slow. Attached is a part of the strace output. Regards, Marcus
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
<...lots more of the same...>
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
stat64("/devices/mtdblock2", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/devfs/mtdblock2", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/dev/mtdblock2", {st_mode=S_IFBLK|0660, st_rdev=makedev(31, 2), ...}) = 0
time(NULL) = 1183649062
open("/dev/mtdblock2", O_RDONLY) = 12
fstat64(12, {st_mode=S_IFBLK|0660, st_rdev=makedev(31, 2), ...}) = 0
uname({sys="Linux", node="slug", ...}) = 0
ioctl(12, BLKGETSIZE64, 0xbef90ca0) = 0
lseek(12, 65536, SEEK_SET) = 65536
read(12, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) =
4096
lseek(12, 0, SEEK_SET) = 0
read(12, "\0\1\377\340\0\0\0\0\0\0\0\0\0\0\0\0\356\21?\20\343\303"..., 69632) =
69632
close(12) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
<...lots more of the same...>
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
stat64("/devices/mtdblock3", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/devfs/mtdblock3", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/dev/mtdblock3", {st_mode=S_IFBLK|0660, st_rdev=makedev(31, 3), ...}) = 0
time(NULL) = 1183649064
open("/dev/mtdblock3", O_RDONLY) = 12
fstat64(12, {st_mode=S_IFBLK|0660, st_rdev=makedev(31, 3), ...}) = 0
uname({sys="Linux", node="slug", ...}) = 0
ioctl(12, BLKGETSIZE64, 0xbef90ca0) = 0
lseek(12, 1245184, SEEK_SET) = 1245184
read(12, "\377\377\377\377\377\377\377\377\377\377\377\377\377\377"..., 4096) =
4096
lseek(12, 0, SEEK_SET) = 0
read(12, "\0\22\342p\0\0\0\0\0\0\0\0\0\0\0\0\341\240\0\0\341\240"..., 69632) =
69632
close(12) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
<...lots more of the same...>
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
stat64("/devices/mtdblock4", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/devfs/mtdblock4", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/dev/mtdblock4", {st_mode=S_IFBLK|0660, st_rdev=makedev(31, 4), ...}) = 0
time(NULL) = 1183649066
open("/dev/mtdblock4", O_RDONLY) = 12
fstat64(12, {st_mode=S_IFBLK|0660, st_rdev=makedev(31, 4), ...}) = 0
uname({sys="Linux", node="slug", ...}) = 0
ioctl(12, BLKGETSIZE64, 0xbef90ca0) = 0
lseek(12, 6356992, SEEK_SET) = 6356992
read(12, "\377\377\377\377\377\377\377\377\377\377\377\377\377\377"..., 4096) =
4096
lseek(12, 0, SEEK_SET) = 0
read(12, "[EMAIL PROTECTED]"..., 69632) = 69632
close(12) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
<...lots more of the same...>
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
stat64("/devices/sda2", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/devfs/sda2", 0xbef91d1c) = -1 ENOENT (No such file or directory)
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
<...lots more of the same...>
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
stat64("/devices/sdb5", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/devfs/sdb5", 0xbef91d1c) = -1 ENOENT (No such file or directory)
stat64("/dev/sdb5", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 21), ...}) = 0
time(NULL) = 1183649074
open("/dev/sdb5", O_RDONLY) = 12
fstat64(12, {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 21), ...}) = 0
uname({sys="Linux", node="slug", ...}) = 0
ioctl(12, BLKGETSIZE64, 0xbef90ca0) = 0
_llseek(12, 150473146368, [150473146368], SEEK_SET) = 0
read(12, "\377\377\377\377\377\377\377\377\377\377\377\377\377\377"..., 4096) =
4096
lseek(12, 0, SEEK_SET) = 0
read(12, "\377\377\377\377\377\377\377\377\377\377\377\377\377\377"..., 69632)
= 69632
close(12) = 0
ioctl(10, DM_LIST_DEVICES, 0x37410) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
ioctl(10, DM_TABLE_DEPS, 0x3b418) = 0
signature.asc
Description: This is a digitally signed message part.
