mountd eats CPU, issues tons of ioctls

Marcus Better marcus at better.se
Thu Jul 5 13:49:22 EDT 2007


Hi,

the rpc.mountd on my NFSv4 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.

I have about the same setup on other i386 servers that don't show this behaviour. Of course the NSLU2 is a really slow device, but it still seems suspicious. The server uses Kerberos authentication.

Below are parts of the strace output. Any idea what might be wrong?

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, "\0@\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\10\213\37F]\230BZ\314"..., 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




More information about the NFSv4 mailing list