rpc.mountd high cpu usage

rpc.mountd high cpu usage

[Sander Klein]

Hi,

We have an NFS server with about 186 exports currently. Every time we 
add an export or mount an export the rpc.mountd starts eating 100% of 
the CPU for a long time and clients get timeouts during mounts.

At first I thought this was because of a mount storm so I created more 
rpc.mountd threads (16 currently on a 16 core CPU) to see if that would 
help. We also made sure that not all of our clients mount the export at 
the same time. But it didn't help.

After attaching a strace to one of the rpc.mountd processes I found out 
that a lot of newfstatat's are being done. For every export we create a 
newfstatat is being done for every way the a harddisk is seen the OS. 
Our system has 180 harddisks which are all multipathed so a these are a 
*LOT* of stats. 7206 per export in our case. Just a small part from the 
strace (sorry for the big paste):


statfs("/some/export", {f_type=0x2fc12fc1, f_bsize=131072, 
f_blocks=50331648, f_bfree=8355553, f_bavail=8355553, 
f_files=2139121087, f_ffree=2139021753, f_fsid={1912623216, 10933642}, 
f_namelen=255, f_frsize=131072}) = 0
stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
lstat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
lstat("/some/export/..", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
open("/sys/dev/block/0:187", O_RDONLY)  = -1 ENOENT (No such file or 
directory)
open("/dev", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 1093 entries */, 32768) = 30680
newfstatat(21, "dm-185", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 185), ...}, 0) = 0
newfstatat(21, "dm-184", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 184), ...}, 0) = 0
newfstatat(21, "dm-183", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 183), ...}, 0) = 0
newfstatat(21, "dm-182", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 182), ...}, 0) = 0
newfstatat(21, "dm-181", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 181), ...}, 0) = 0
newfstatat(21, "dm-180", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 180), ...}, 0) = 0
[...]
newfstatat(21, "dm-3", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 3), ...}, 0) = 0
newfstatat(21, "dm-2", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 2), ...}, 0) = 0
newfstatat(21, "loop7", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 7), ...}, 0) = 0
newfstatat(21, "loop6", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 6), ...}, 0) = 0
newfstatat(21, "loop5", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 5), ...}, 0) = 0
newfstatat(21, "loop4", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 4), ...}, 0) = 0
newfstatat(21, "loop3", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 3), ...}, 0) = 0
newfstatat(21, "loop2", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 2), ...}, 0) = 0
newfstatat(21, "loop1", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 1), ...}, 0) = 0
newfstatat(21, "shm", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=60, ...}, 
0) = 0
newfstatat(21, "sndstat", {st_mode=S_IFREG|0444, st_size=0, ...}, 0) = 0
newfstatat(21, "root", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 0), ...}, 0) = 0
newfstatat(21, "MAKEDEV", {st_mode=S_IFREG|0755, st_size=22880, ...}, 0) 
= 0
newfstatat(21, "dvdrw", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(11, 0), ...}, 0) = 0
newfstatat(21, "dvd", {st_mode=S_IFBLK|S_ISVTX|0660, st_rdev=makedev(11, 
0), ...}, 0) = 0
newfstatat(21, "cdrw", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(11, 0), ...}, 0) = 0
newfstatat(21, "cdrom", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(11, 0), ...}, 0) = 0
newfstatat(21, "hpilo", {st_mode=S_IFDIR|0755, st_size=200, ...}, 0) = 0
newfstatat(21, "snd", {st_mode=S_IFDIR|0755, st_size=80, ...}, 0) = 0
newfstatat(21, "loop0", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(7, 0), ...}, 0) = 0
newfstatat(21, "dm-1", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 1), ...}, 0) = 0
newfstatat(21, "os", {st_mode=S_IFDIR|0755, st_size=160, ...}, 0) = 0
newfstatat(21, "dm-0", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 0), ...}, 0) = 0
newfstatat(21, "sdnc", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 480), ...}, 0) = 0
newfstatat(21, "sdnb", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 464), ...}, 0) = 0
newfstatat(21, "sdna", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 448), ...}, 0) = 0
newfstatat(21, "sdmz", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 432), ...}, 0) = 0
newfstatat(21, "sdmy", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 416), ...}, 0) = 0
newfstatat(21, "sdmx", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 400), ...}, 0) = 0
newfstatat(21, "sdmw", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(70, 384), ...}, 0) = 0
[...]
newfstatat(21, "sdd", {st_mode=S_IFBLK|S_ISVTX|0660, st_rdev=makedev(8, 
48), ...}, 0) = 0
newfstatat(21, "sdc", {st_mode=S_IFBLK|S_ISVTX|0660, st_rdev=makedev(8, 
32), ...}, 0) = 0
newfstatat(21, "sdb", {st_mode=S_IFBLK|S_ISVTX|0660, st_rdev=makedev(8, 
16), ...}, 0) = 0
newfstatat(21, "bus", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 0
newfstatat(21, "bsg", {st_mode=S_IFDIR|0755, st_size=15280, ...}, 0) = 0
newfstatat(21, "rtc", {st_mode=S_IFCHR|0600, st_rdev=makedev(254, 0), 
...}, 0) = 0
newfstatat(21, "char", {st_mode=S_IFDIR|0755, st_size=25320, ...}, 0) = 
0
newfstatat(21, "mapper", {st_mode=S_IFDIR|0755, st_size=3780, ...}, 0) = 
0
newfstatat(21, "net", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 0
newfstatat(21, "cpu", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 0
newfstatat(21, "stderr", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), 
...}, 0) = 0
newfstatat(21, "stdout", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), 
...}, 0) = 0
newfstatat(21, "stdin", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), 
...}, 0) = 0
newfstatat(21, "fd", {st_mode=S_IFDIR|0500, st_size=0, ...}, 0) = 0
newfstatat(21, "core", {st_mode=S_IFREG|0400, st_size=140737486262272, 
...}, 0) = 0
newfstatat(21, "pts", {st_mode=S_IFDIR|0755, st_size=0, ...}, 0) = 0
newfstatat(21, "input", {st_mode=S_IFDIR|0755, st_size=120, ...}, 0) = 0
getdents(21, /* 0 entries */, 32768)    = 0
close(21)                               = 0
open("/devfs", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT 
(No such file or directory)
open("/devices", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT 
(No such file or directory)
open("/dev/input", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 6 entries */, 32768)    = 168
newfstatat(21, "by-path", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 
0
getdents(21, /* 0 entries */, 32768)    = 0
close(21)                               = 0
open("/dev/pts", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 6 entries */, 32768)    = 144
getdents(21, /* 0 entries */, 32768)    = 0
close(21)                               = 0
open("/dev/cpu", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 3 entries */, 32768)    = 80
getdents(21, /* 0 entries */, 32768)    = 0
close(21)                               = 0
open("/dev/net", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 3 entries */, 32768)    = 72
getdents(21, /* 0 entries */, 32768)    = 0
close(21)                               = 0
open("/dev/mapper", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 189 entries */, 32768)  = 7472
newfstatat(21, "os-home", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 185), ...}, 0) = 0
newfstatat(21, "os-var", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 184), ...}, 0) = 0
newfstatat(21, "os-usr", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 183), ...}, 0) = 0
newfstatat(21, "os-boot", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 182), ...}, 0) = 0
newfstatat(21, "35000cca01a8db828", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 181), ...}, 0) = 0
newfstatat(21, "35000cca01a9a63e8", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 180), ...}, 0) = 0
newfstatat(21, "35000cca01a89cae4", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 179), ...}, 0) = 0
newfstatat(21, "35000cca01a89dd04", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 178), ...}, 0) = 0
[...]
newfstatat(21, "35000cca03e40bd84", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 6), ...}, 0) = 0
newfstatat(21, "35000cca03e4b0250", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 3), ...}, 0) = 0
newfstatat(21, "35000cca03e368408", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 7), ...}, 0) = 0
newfstatat(21, "os-swap", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 1), ...}, 0) = 0
newfstatat(21, "os-root", {st_mode=S_IFBLK|S_ISVTX|0660, 
st_rdev=makedev(254, 0), ...}, 0) = 0
getdents(21, /* 0 entries */, 32768)    = 0
close(21)                               = 0
open("/dev/char", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
getdents(21, /* 1027 entries */, 32768) = 32768
newfstatat(21, "10:237", {st_mode=S_IFCHR|S_ISVTX|0600, 
st_rdev=makedev(10, 237), ...}, 0) = 0
newfstatat(21, "7:134", {st_mode=S_IFCHR|0600, st_rdev=makedev(7, 134), 
...}, 0) = 0
newfstatat(21, "7:6", {st_mode=S_IFCHR|0600, st_rdev=makedev(7, 6), 
...}, 0) = 0
newfstatat(21, "7:133", {st_mode=S_IFCHR|0600, st_rdev=makedev(7, 133), 
...}, 0) = 0
[...etc etc etc...]


Is this expected behavour or is this some kind of bug?

I'm using nfs-utils 1.2.8 from Debian testing, but also had this problem 
with 1.2.6. The kernel is 3.2.51.

If any more info is needed please let me know.

Regards,

Sander Klein

Re: rpc.mountd high cpu usage

[J. Bruce Fields]

On Thu, Dec 12, 2013 at 11:13:11AM +0100, Sander Klein wrote:
> Hi,
> 
> We have an NFS server with about 186 exports currently. Every time
> we add an export or mount an export the rpc.mountd starts eating
> 100% of the CPU for a long time and clients get timeouts during
> mounts.
> 
> At first I thought this was because of a mount storm so I created
> more rpc.mountd threads (16 currently on a 16 core CPU) to see if
> that would help. We also made sure that not all of our clients mount
> the export at the same time. But it didn't help.
> 
> After attaching a strace to one of the rpc.mountd processes I found
> out that a lot of newfstatat's are being done. For every export we
> create a newfstatat is being done for every way the a harddisk is
> seen the OS. Our system has 180 harddisks which are all multipathed
> so a these are a *LOT* of stats. 7206 per export in our case. Just a
> small part from the strace (sorry for the big paste):

That sounds like somewhat of an extreme setup, and I suspect the current
behavior is by design, but I agree that we should fix it.  I'm not
volunteering for now....

I think what happens is that exportfs flushes the kernel's export cache
at which point every use of an uncached export triggers an upcall to
mountd.  That upcall is probably visible in the strace as a read of a
file descriptor associated with /proc/net/sunrpc/nfsd.fh/content.

That upcall is handled by nfs-utils/utils/mountd/cache.c:nfsd_fh(),
which is given a filehandle fragment identifying the filesystem in
question and has to match it to an export.

That's done by match_fsid().  Which does do a stat of the export path,
but not of all the devices....  That's probably happening in one of the
libblkid calls in uuid_by_path()?  I wonder if there's something wrong
with libblkid configuration or with the way we're using it?

--b.

> 
> 
> statfs("/some/export", {f_type=0x2fc12fc1, f_bsize=131072,
> f_blocks=50331648, f_bfree=8355553, f_bavail=8355553,
> f_files=2139121087, f_ffree=2139021753, f_fsid={1912623216,
> 10933642}, f_namelen=255, f_frsize=131072}) = 0
> stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> lstat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> lstat("/some/export/..", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
> stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> open("/sys/dev/block/0:187", O_RDONLY)  = -1 ENOENT (No such file or
> directory)
> open("/dev", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 1093 entries */, 32768) = 30680
> newfstatat(21, "dm-185", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 185), ...}, 0) = 0
> newfstatat(21, "dm-184", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 184), ...}, 0) = 0
> newfstatat(21, "dm-183", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 183), ...}, 0) = 0
> newfstatat(21, "dm-182", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 182), ...}, 0) = 0
> newfstatat(21, "dm-181", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 181), ...}, 0) = 0
> newfstatat(21, "dm-180", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 180), ...}, 0) = 0
> [...]
> newfstatat(21, "dm-3", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 3), ...}, 0) = 0
> newfstatat(21, "dm-2", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 2), ...}, 0) = 0
> newfstatat(21, "loop7", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 7), ...}, 0) = 0
> newfstatat(21, "loop6", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 6), ...}, 0) = 0
> newfstatat(21, "loop5", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 5), ...}, 0) = 0
> newfstatat(21, "loop4", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 4), ...}, 0) = 0
> newfstatat(21, "loop3", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 3), ...}, 0) = 0
> newfstatat(21, "loop2", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 2), ...}, 0) = 0
> newfstatat(21, "loop1", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 1), ...}, 0) = 0
> newfstatat(21, "shm", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=60,
> ...}, 0) = 0
> newfstatat(21, "sndstat", {st_mode=S_IFREG|0444, st_size=0, ...}, 0) = 0
> newfstatat(21, "root", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 0), ...}, 0) = 0
> newfstatat(21, "MAKEDEV", {st_mode=S_IFREG|0755, st_size=22880,
> ...}, 0) = 0
> newfstatat(21, "dvdrw", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(11, 0), ...}, 0) = 0
> newfstatat(21, "dvd", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(11, 0), ...}, 0) = 0
> newfstatat(21, "cdrw", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(11, 0), ...}, 0) = 0
> newfstatat(21, "cdrom", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(11, 0), ...}, 0) = 0
> newfstatat(21, "hpilo", {st_mode=S_IFDIR|0755, st_size=200, ...}, 0) = 0
> newfstatat(21, "snd", {st_mode=S_IFDIR|0755, st_size=80, ...}, 0) = 0
> newfstatat(21, "loop0", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(7, 0), ...}, 0) = 0
> newfstatat(21, "dm-1", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 1), ...}, 0) = 0
> newfstatat(21, "os", {st_mode=S_IFDIR|0755, st_size=160, ...}, 0) = 0
> newfstatat(21, "dm-0", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 0), ...}, 0) = 0
> newfstatat(21, "sdnc", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 480), ...}, 0) = 0
> newfstatat(21, "sdnb", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 464), ...}, 0) = 0
> newfstatat(21, "sdna", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 448), ...}, 0) = 0
> newfstatat(21, "sdmz", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 432), ...}, 0) = 0
> newfstatat(21, "sdmy", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 416), ...}, 0) = 0
> newfstatat(21, "sdmx", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 400), ...}, 0) = 0
> newfstatat(21, "sdmw", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(70, 384), ...}, 0) = 0
> [...]
> newfstatat(21, "sdd", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(8, 48), ...}, 0) = 0
> newfstatat(21, "sdc", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(8, 32), ...}, 0) = 0
> newfstatat(21, "sdb", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(8, 16), ...}, 0) = 0
> newfstatat(21, "bus", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 0
> newfstatat(21, "bsg", {st_mode=S_IFDIR|0755, st_size=15280, ...}, 0) = 0
> newfstatat(21, "rtc", {st_mode=S_IFCHR|0600, st_rdev=makedev(254,
> 0), ...}, 0) = 0
> newfstatat(21, "char", {st_mode=S_IFDIR|0755, st_size=25320, ...},
> 0) = 0
> newfstatat(21, "mapper", {st_mode=S_IFDIR|0755, st_size=3780, ...},
> 0) = 0
> newfstatat(21, "net", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 0
> newfstatat(21, "cpu", {st_mode=S_IFDIR|0755, st_size=60, ...}, 0) = 0
> newfstatat(21, "stderr", {st_mode=S_IFCHR|0666, st_rdev=makedev(1,
> 3), ...}, 0) = 0
> newfstatat(21, "stdout", {st_mode=S_IFCHR|0666, st_rdev=makedev(1,
> 3), ...}, 0) = 0
> newfstatat(21, "stdin", {st_mode=S_IFCHR|0666, st_rdev=makedev(1,
> 3), ...}, 0) = 0
> newfstatat(21, "fd", {st_mode=S_IFDIR|0500, st_size=0, ...}, 0) = 0
> newfstatat(21, "core", {st_mode=S_IFREG|0400,
> st_size=140737486262272, ...}, 0) = 0
> newfstatat(21, "pts", {st_mode=S_IFDIR|0755, st_size=0, ...}, 0) = 0
> newfstatat(21, "input", {st_mode=S_IFDIR|0755, st_size=120, ...}, 0) = 0
> getdents(21, /* 0 entries */, 32768)    = 0
> close(21)                               = 0
> open("/devfs", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1
> ENOENT (No such file or directory)
> open("/devices", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1
> ENOENT (No such file or directory)
> open("/dev/input", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 6 entries */, 32768)    = 168
> newfstatat(21, "by-path", {st_mode=S_IFDIR|0755, st_size=60, ...},
> 0) = 0
> getdents(21, /* 0 entries */, 32768)    = 0
> close(21)                               = 0
> open("/dev/pts", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 6 entries */, 32768)    = 144
> getdents(21, /* 0 entries */, 32768)    = 0
> close(21)                               = 0
> open("/dev/cpu", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 3 entries */, 32768)    = 80
> getdents(21, /* 0 entries */, 32768)    = 0
> close(21)                               = 0
> open("/dev/net", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 3 entries */, 32768)    = 72
> getdents(21, /* 0 entries */, 32768)    = 0
> close(21)                               = 0
> open("/dev/mapper", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 189 entries */, 32768)  = 7472
> newfstatat(21, "os-home", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 185), ...}, 0) = 0
> newfstatat(21, "os-var", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 184), ...}, 0) = 0
> newfstatat(21, "os-usr", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 183), ...}, 0) = 0
> newfstatat(21, "os-boot", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 182), ...}, 0) = 0
> newfstatat(21, "35000cca01a8db828", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 181), ...}, 0) = 0
> newfstatat(21, "35000cca01a9a63e8", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 180), ...}, 0) = 0
> newfstatat(21, "35000cca01a89cae4", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 179), ...}, 0) = 0
> newfstatat(21, "35000cca01a89dd04", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 178), ...}, 0) = 0
> [...]
> newfstatat(21, "35000cca03e40bd84", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 6), ...}, 0) = 0
> newfstatat(21, "35000cca03e4b0250", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 3), ...}, 0) = 0
> newfstatat(21, "35000cca03e368408", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 7), ...}, 0) = 0
> newfstatat(21, "os-swap", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 1), ...}, 0) = 0
> newfstatat(21, "os-root", {st_mode=S_IFBLK|S_ISVTX|0660,
> st_rdev=makedev(254, 0), ...}, 0) = 0
> getdents(21, /* 0 entries */, 32768)    = 0
> close(21)                               = 0
> open("/dev/char", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 21
> getdents(21, /* 1027 entries */, 32768) = 32768
> newfstatat(21, "10:237", {st_mode=S_IFCHR|S_ISVTX|0600,
> st_rdev=makedev(10, 237), ...}, 0) = 0
> newfstatat(21, "7:134", {st_mode=S_IFCHR|0600, st_rdev=makedev(7,
> 134), ...}, 0) = 0
> newfstatat(21, "7:6", {st_mode=S_IFCHR|0600, st_rdev=makedev(7, 6),
> ...}, 0) = 0
> newfstatat(21, "7:133", {st_mode=S_IFCHR|0600, st_rdev=makedev(7,
> 133), ...}, 0) = 0
> [...etc etc etc...]
> 
> 
> Is this expected behavour or is this some kind of bug?
> 
> I'm using nfs-utils 1.2.8 from Debian testing, but also had this
> problem with 1.2.6. The kernel is 3.2.51.
> 
> If any more info is needed please let me know.
> 
> Regards,
> 
> Sander Klein
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: rpc.mountd high cpu usage

[Sander Klein]

On , J. Bruce Fields wrote:
> That sounds like somewhat of an extreme setup, and I suspect the 
> current
> behavior is by design, but I agree that we should fix it.  I'm not
> volunteering for now....

Ow dear, I never thought that this would classified as an extreme setup 
:-) .

> I think what happens is that exportfs flushes the kernel's export cache
> at which point every use of an uncached export triggers an upcall to
> mountd.  That upcall is probably visible in the strace as a read of a
> file descriptor associated with /proc/net/sunrpc/nfsd.fh/content.
> 
> That upcall is handled by nfs-utils/utils/mountd/cache.c:nfsd_fh(),
> which is given a filehandle fragment identifying the filesystem in
> question and has to match it to an export.
> 
> That's done by match_fsid().  Which does do a stat of the export path,
> but not of all the devices....  That's probably happening in one of the
> libblkid calls in uuid_by_path()?  I wonder if there's something wrong
> with libblkid configuration or with the way we're using it?

Is there any way I can help getting this fixed? My coding skills are 
limited but I am very willing to help in any way I can.

Greets,

Sander

Re: rpc.mountd high cpu usage

[J. Bruce Fields]

On Thu, Dec 12, 2013 at 05:42:44PM +0100, Sander Klein wrote:
> On , J. Bruce Fields wrote:
> >That sounds like somewhat of an extreme setup, and I suspect the
> >current
> >behavior is by design, but I agree that we should fix it.  I'm not
> >volunteering for now....
> 
> Ow dear, I never thought that this would classified as an extreme
> setup :-) .

Eh, maybe it's not.

> >I think what happens is that exportfs flushes the kernel's export cache
> >at which point every use of an uncached export triggers an upcall to
> >mountd.  That upcall is probably visible in the strace as a read of a
> >file descriptor associated with /proc/net/sunrpc/nfsd.fh/content.
> >
> >That upcall is handled by nfs-utils/utils/mountd/cache.c:nfsd_fh(),
> >which is given a filehandle fragment identifying the filesystem in
> >question and has to match it to an export.
> >
> >That's done by match_fsid().  Which does do a stat of the export path,
> >but not of all the devices....  That's probably happening in one of the
> >libblkid calls in uuid_by_path()?  I wonder if there's something wrong
> >with libblkid configuration or with the way we're using it?
> 
> Is there any way I can help getting this fixed? My coding skills are
> limited but I am very willing to help in any way I can.

I wonder if ltrace could help determine if libblkid is where most of
those stat's are coming from (and if so, which calls)?

May also be worth reading up on libblkid (man libblkid, etc.) and
checking your configuration to make sure there's nothing obvious broken
there.  (If so, maybe the libblkid commandline tools would exhibit the
same problem?)

--b.

Re: rpc.mountd high cpu usage

[Sander Klein]

On , J. Bruce Fields wrote:
>> >I think what happens is that exportfs flushes the kernel's export cache
>> >at which point every use of an uncached export triggers an upcall to
>> >mountd.  That upcall is probably visible in the strace as a read of a
>> >file descriptor associated with /proc/net/sunrpc/nfsd.fh/content.
>> >
>> >That upcall is handled by nfs-utils/utils/mountd/cache.c:nfsd_fh(),
>> >which is given a filehandle fragment identifying the filesystem in
>> >question and has to match it to an export.
>> >
>> >That's done by match_fsid().  Which does do a stat of the export path,
>> >but not of all the devices....  That's probably happening in one of the
>> >libblkid calls in uuid_by_path()?  I wonder if there's something wrong
>> >with libblkid configuration or with the way we're using it?
>> 
>> Is there any way I can help getting this fixed? My coding skills are
>> limited but I am very willing to help in any way I can.
> 
> I wonder if ltrace could help determine if libblkid is where most of
> those stat's are coming from (and if so, which calls)?
> 
> May also be worth reading up on libblkid (man libblkid, etc.) and
> checking your configuration to make sure there's nothing obvious broken
> there.  (If so, maybe the libblkid commandline tools would exhibit the
> same problem?)

I didn't have any config in /etc/blkid.conf and the manpage says it will 
use EVALUATE=udev,scan which in fact scans through all the 
/dev/disk/by-* dirs and parses the /proc/partitions. I put 
'EVALUATE=scan' in /etc/blkid.conf but that doesn't help. I restarted 
anything NFS related...

I also attached ltrace to the rpc.mountd process. The output of the 
trace is at http://pastebin.com/ika1Vetq . I'm not sure what I'm looking 
for. The ltrace is done on a server with only 10 harddisks but the 
strace showed the same behavour of newfstatat-ing every disk in a lot of 
ways.

Greets,

Sander

Re: rpc.mountd high cpu usage

[J. Bruce Fields]

On Fri, Dec 13, 2013 at 08:32:56PM +0100, Sander Klein wrote:
> On , J. Bruce Fields wrote:
> >>>I think what happens is that exportfs flushes the kernel's export cache
> >>>at which point every use of an uncached export triggers an upcall to
> >>>mountd.  That upcall is probably visible in the strace as a read of a
> >>>file descriptor associated with /proc/net/sunrpc/nfsd.fh/content.
> >>>
> >>>That upcall is handled by nfs-utils/utils/mountd/cache.c:nfsd_fh(),
> >>>which is given a filehandle fragment identifying the filesystem in
> >>>question and has to match it to an export.
> >>>
> >>>That's done by match_fsid().  Which does do a stat of the export path,
> >>>but not of all the devices....  That's probably happening in one of the
> >>>libblkid calls in uuid_by_path()?  I wonder if there's something wrong
> >>>with libblkid configuration or with the way we're using it?
> >>
> >>Is there any way I can help getting this fixed? My coding skills are
> >>limited but I am very willing to help in any way I can.
> >
> >I wonder if ltrace could help determine if libblkid is where most of
> >those stat's are coming from (and if so, which calls)?
> >
> >May also be worth reading up on libblkid (man libblkid, etc.) and
> >checking your configuration to make sure there's nothing obvious broken
> >there.  (If so, maybe the libblkid commandline tools would exhibit the
> >same problem?)
> 
> I didn't have any config in /etc/blkid.conf and the manpage says it
> will use EVALUATE=udev,scan which in fact scans through all the
> /dev/disk/by-* dirs and parses the /proc/partitions. I put
> 'EVALUATE=scan' in /etc/blkid.conf but that doesn't help. I
> restarted anything NFS related...
> 
> I also attached ltrace to the rpc.mountd process. The output of the
> trace is at http://pastebin.com/ika1Vetq . I'm not sure what I'm
> looking for. The ltrace is done on a server with only 10 harddisks
> but the strace showed the same behavour of newfstatat-ing every disk
> in a lot of ways.

Hm.  I *think* that those SYS_262's are the newfstatat's.  And it looks
like they happen as part of the implementation of blkid_devno_to_devname
(just because you see that call start above the SYS_262's and return
only after).

That is indeed called from utils/mountd/cache.c:get_uuid_blkdev().

So libblkid is mapping device numbers to paths by stat'ing lots of stuff
under /dev.

I'm not sure what to do about that.... Cc'ing util-linux in case they
can help.

--b.

Re: rpc.mountd high cpu usage

[Sander Klein]

On , J. Bruce Fields wrote:
> On Fri, Dec 13, 2013 at 08:32:56PM +0100, Sander Klein wrote:
>> On , J. Bruce Fields wrote:
>> >>>I think what happens is that exportfs flushes the kernel's export cache
>> >>>at which point every use of an uncached export triggers an upcall to
>> >>>mountd.  That upcall is probably visible in the strace as a read of a
>> >>>file descriptor associated with /proc/net/sunrpc/nfsd.fh/content.
>> >>>
>> >>>That upcall is handled by nfs-utils/utils/mountd/cache.c:nfsd_fh(),
>> >>>which is given a filehandle fragment identifying the filesystem in
>> >>>question and has to match it to an export.
>> >>>
>> >>>That's done by match_fsid().  Which does do a stat of the export path,
>> >>>but not of all the devices....  That's probably happening in one of the
>> >>>libblkid calls in uuid_by_path()?  I wonder if there's something wrong
>> >>>with libblkid configuration or with the way we're using it?
>> >>
>> >>Is there any way I can help getting this fixed? My coding skills are
>> >>limited but I am very willing to help in any way I can.
>> >
>> >I wonder if ltrace could help determine if libblkid is where most of
>> >those stat's are coming from (and if so, which calls)?
>> >
>> >May also be worth reading up on libblkid (man libblkid, etc.) and
>> >checking your configuration to make sure there's nothing obvious broken
>> >there.  (If so, maybe the libblkid commandline tools would exhibit the
>> >same problem?)
>> 
>> I didn't have any config in /etc/blkid.conf and the manpage says it
>> will use EVALUATE=udev,scan which in fact scans through all the
>> /dev/disk/by-* dirs and parses the /proc/partitions. I put
>> 'EVALUATE=scan' in /etc/blkid.conf but that doesn't help. I
>> restarted anything NFS related...
>> 
>> I also attached ltrace to the rpc.mountd process. The output of the
>> trace is at http://pastebin.com/ika1Vetq . I'm not sure what I'm
>> looking for. The ltrace is done on a server with only 10 harddisks
>> but the strace showed the same behavour of newfstatat-ing every disk
>> in a lot of ways.
> 
> Hm.  I *think* that those SYS_262's are the newfstatat's.  And it looks
> like they happen as part of the implementation of 
> blkid_devno_to_devname
> (just because you see that call start above the SYS_262's and return
> only after).
> 
> That is indeed called from utils/mountd/cache.c:get_uuid_blkdev().
> 
> So libblkid is mapping device numbers to paths by stat'ing lots of 
> stuff
> under /dev.
> 
> I'm not sure what to do about that.... Cc'ing util-linux in case they
> can help.
> 
> --b.

Anything else I can do to help a bit getting this fixed?

Regards,

Sander

Re: rpc.mountd high cpu usage

[Karel Zak]

On Thu, Dec 12, 2013 at 10:46:42AM -0500, J. Bruce Fields wrote:
> That's done by match_fsid().  Which does do a stat of the export path,
> but not of all the devices....  That's probably happening in one of the
> libblkid calls in uuid_by_path()?  I wonder if there's something wrong
> with libblkid configuration or with the way we're using it?

The blkid EVALUATE=<methods> configuration matters for UUID to
devname conversion, not vice versa. 
 
If you want to get filesystem UUID you have to ask udev (link with
libudev) or read it from the device (link with libblkid).

> > statfs("/some/export", {f_type=0x2fc12fc1, f_bsize=131072,
> > f_blocks=50331648, f_bfree=8355553, f_bavail=8355553,
> > f_files=2139121087, f_ffree=2139021753, f_fsid={1912623216,
> > 10933642}, f_namelen=255, f_frsize=131072}) = 0
> > stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> > lstat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> > lstat("/some/export/..", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
> > stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> > open("/sys/dev/block/0:187", O_RDONLY)  = -1 ENOENT (No such file or
> > directory)

This is blkid_devno_to_devname(), the first attempt is /sys, but it
failed, then it tries to scan /dev (which is pretty expensive method).

BTW, what is device 0:187? 

It seems like btrfs... maybe we can  optimize the code to ignore such
devices especially when get_uuid_blkdev() filters out btrfs :-)

The another problem is poorly designed relationship between match_fsid()
and uuid_by_path().  The function uuid_by_path() is called in loop and 
blkid is *always* requested, but the blkid_val is used when type==0. 
It would be better to call get_uuid_blkdev() only when type==0.

The patch below is just untested suggestion :-)

    Karel

>From e4f5b38c87ef8d713c6d0a3169afaf1acc7e22c6 Mon Sep 17 00:00:00 2001
From: Karel Zak <kzak@redhat.com>
Date: Mon, 6 Jan 2014 12:03:01 +0100
Subject: [PATCH] mountd: optimize libblkid usage

 * use get_uuid_blkdev() only first time for the path (it means
   that uuid_by_path() is called with type==0)

 * don't use libblkid for btrfs, network or pseudo filesystems

Note that the patch defines the fs type ID rather than include
<linux/magic.h> as this file seems incomplete and libc specific).

Signed-off-by: Karel Zak <kzak@redhat.com>
---
 utils/mountd/cache.c | 38 +++++++++++++++++++++++++++++++++++---
 1 file changed, 35 insertions(+), 3 deletions(-)

diff --git a/utils/mountd/cache.c b/utils/mountd/cache.c
index e04b86e..73c0be6 100644
--- a/utils/mountd/cache.c
+++ b/utils/mountd/cache.c
@@ -266,6 +266,26 @@ static int get_uuid(const char *val, size_t uuidlen, char *u)
 	return 1;
 }
 
+
+/*
+ * Don't ask libblkid for these filesystems. Note that BTRF is ignored, because
+ * we generate the identifier from statfs->f_fsid. The rest are network or
+ * pseudo filesystems. (See <linux/magic.h> for the basic IDs.)
+ */
+static const long int nonblkid_filesystems[] = {
+	0x9123683E,	/* BTRFS_SUPER_MAGIC */
+	0xFF534D42,	/* CIFS_MAGIC_NUMBER */
+	0x1373,		/* DEVFS_SUPER_MAGIC */
+	0x73757245,	/* CODA_SUPER_MAGIC */
+	0x564C,		/* NCP_SUPER_MAGIC */
+	0x6969,		/* NFS_SUPER_MAGIC */
+	0x9FA0,		/* PROC_SUPER_MAGIC */
+	0x62656572,	/* SYSFS_MAGIC */
+	0x517B,		/* SMB_SUPER_MAGIC */
+	0x01021994,	/* TMPFS_SUPER_MAGIC */
+	0		/* last */
+};
+
 static int uuid_by_path(char *path, int type, size_t uuidlen, char *uuid)
 {
 	/* get a uuid for the filesystem found at 'path'.
@@ -297,12 +317,24 @@ static int uuid_by_path(char *path, int type, size_t uuidlen, char *uuid)
 	 */
 	struct statfs64 st;
 	char fsid_val[17];
-	const char *blkid_val;
+	const char *blkid_val = NULL;
 	const char *val;
+	int rc;
 
-	blkid_val = get_uuid_blkdev(path);
+	rc = statfs64(path, &st);
+
+	if (type == 0 && rc == 0) {
+		const long int *bad;
+
+		for (bad = nonblkid_filesystems; *bad; bad++) {
+			if (*bad == st.f_type)
+				break;
+		}
+		if (*bad == 0)
+			blkid_val = get_uuid_blkdev(path);
+	}
 
-	if (statfs64(path, &st) == 0 &&
+	if (rc == 0 &&
 	    (st.f_fsid.__val[0] || st.f_fsid.__val[1]))
 		snprintf(fsid_val, 17, "%08x%08x",
 			 st.f_fsid.__val[0], st.f_fsid.__val[1]);
-- 
1.8.4.2

Re: rpc.mountd high cpu usage

[Sander Klein]

Hi,

On 06.01.2014 12:18, Karel Zak wrote:
>> > statfs("/some/export", {f_type=0x2fc12fc1, f_bsize=131072,
>> > f_blocks=50331648, f_bfree=8355553, f_bavail=8355553,
>> > f_files=2139121087, f_ffree=2139021753, f_fsid={1912623216,
>> > 10933642}, f_namelen=255, f_frsize=131072}) = 0
>> > stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
>> > lstat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
>> > lstat("/some/export/..", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
>> > stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
>> > open("/sys/dev/block/0:187", O_RDONLY)  = -1 ENOENT (No such file or
>> > directory)
> 
> This is blkid_devno_to_devname(), the first attempt is /sys, but it
> failed, then it tries to scan /dev (which is pretty expensive method).
> 
> BTW, what is device 0:187?
> 
> It seems like btrfs... maybe we can  optimize the code to ignore such
> devices especially when get_uuid_blkdev() filters out btrfs :-)

This machine is running ZFS On Linux with 180 multipathed disks. I 
wouldn't be amazed if ZFS and BTRFS suffer from the same problem because 
they are both volume managers and filesystems in one.

> The another problem is poorly designed relationship between 
> match_fsid()
> and uuid_by_path().  The function uuid_by_path() is called in loop and
> blkid is *always* requested, but the blkid_val is used when type==0.
> It would be better to call get_uuid_blkdev() only when type==0.
> 
> The patch below is just untested suggestion :-)

Should/Would ZFS_SUPER_MAGIC 0x2fc12fc1 be added to make this untested 
suggestion theoretically work with ZFS? I got this from the ZFS On Linux 
source code 
(https://github.com/zfsonlinux/zfs/blob/master/include/sys/zfs_vfsops.h). 
Oh, and I just noticed it is also in the f_type above :-)

Greets,

Sander

Re: rpc.mountd high cpu usage

[Karel Zak]

On Mon, Jan 06, 2014 at 05:20:12PM +0100, Sander Klein wrote:
> Hi,
> 
> On 06.01.2014 12:18, Karel Zak wrote:
> >>> statfs("/some/export", {f_type=0x2fc12fc1, f_bsize=131072,
> >>> f_blocks=50331648, f_bfree=8355553, f_bavail=8355553,
> >>> f_files=2139121087, f_ffree=2139021753, f_fsid={1912623216,
> >>> 10933642}, f_namelen=255, f_frsize=131072}) = 0
> >>> stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> >>> lstat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> >>> lstat("/some/export/..", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
> >>> stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> >>> open("/sys/dev/block/0:187", O_RDONLY)  = -1 ENOENT (No such file or
> >>> directory)
> >
> >This is blkid_devno_to_devname(), the first attempt is /sys, but it
> >failed, then it tries to scan /dev (which is pretty expensive method).
> >
> >BTW, what is device 0:187?
> >
> >It seems like btrfs... maybe we can  optimize the code to ignore such
> >devices especially when get_uuid_blkdev() filters out btrfs :-)
> 
> This machine is running ZFS On Linux with 180 multipathed disks. I wouldn't
> be amazed if ZFS and BTRFS suffer from the same problem because they are
> both volume managers and filesystems in one.
> 
> >The another problem is poorly designed relationship between match_fsid()
> >and uuid_by_path().  The function uuid_by_path() is called in loop and
> >blkid is *always* requested, but the blkid_val is used when type==0.
> >It would be better to call get_uuid_blkdev() only when type==0.
> >
> >The patch below is just untested suggestion :-)
> 
> Should/Would ZFS_SUPER_MAGIC 0x2fc12fc1 be added to make this untested

yep, try it, test it ;-)

    Karel

-- 
 Karel Zak  <kzak@redhat.com>
 http://karelzak.blogspot.com

Re: rpc.mountd high cpu usage

[J. Bruce Fields]

On Mon, Jan 06, 2014 at 12:18:05PM +0100, Karel Zak wrote:
> On Thu, Dec 12, 2013 at 10:46:42AM -0500, J. Bruce Fields wrote:
> > That's done by match_fsid().  Which does do a stat of the export path,
> > but not of all the devices....  That's probably happening in one of the
> > libblkid calls in uuid_by_path()?  I wonder if there's something wrong
> > with libblkid configuration or with the way we're using it?
> 
> The blkid EVALUATE=<methods> configuration matters for UUID to
> devname conversion, not vice versa. 
>  
> If you want to get filesystem UUID you have to ask udev (link with
> libudev) or read it from the device (link with libblkid).
> 
> > > statfs("/some/export", {f_type=0x2fc12fc1, f_bsize=131072,
> > > f_blocks=50331648, f_bfree=8355553, f_bavail=8355553,
> > > f_files=2139121087, f_ffree=2139021753, f_fsid={1912623216,
> > > 10933642}, f_namelen=255, f_frsize=131072}) = 0
> > > stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> > > lstat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> > > lstat("/some/export/..", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
> > > stat("/some/export", {st_mode=S_IFDIR|0775, st_size=15, ...}) = 0
> > > open("/sys/dev/block/0:187", O_RDONLY)  = -1 ENOENT (No such file or
> > > directory)
> 
> This is blkid_devno_to_devname(), the first attempt is /sys, but it
> failed, then it tries to scan /dev (which is pretty expensive method).
> 
> BTW, what is device 0:187? 
> 
> It seems like btrfs... maybe we can  optimize the code to ignore such
> devices especially when get_uuid_blkdev() filters out btrfs :-)
> 
> The another problem is poorly designed relationship between match_fsid()
> and uuid_by_path().  The function uuid_by_path() is called in loop and 
> blkid is *always* requested, but the blkid_val is used when type==0. 
> It would be better to call get_uuid_blkdev() only when type==0.
> 
> The patch below is just untested suggestion :-)

Thanks!

It's too bad we need to special-case these filesystems.

--b.


> 
>     Karel
> 
> >From e4f5b38c87ef8d713c6d0a3169afaf1acc7e22c6 Mon Sep 17 00:00:00 2001
> From: Karel Zak <kzak@redhat.com>
> Date: Mon, 6 Jan 2014 12:03:01 +0100
> Subject: [PATCH] mountd: optimize libblkid usage
> 
>  * use get_uuid_blkdev() only first time for the path (it means
>    that uuid_by_path() is called with type==0)
> 
>  * don't use libblkid for btrfs, network or pseudo filesystems
> 
> Note that the patch defines the fs type ID rather than include
> <linux/magic.h> as this file seems incomplete and libc specific).
> 
> Signed-off-by: Karel Zak <kzak@redhat.com>
> ---
>  utils/mountd/cache.c | 38 +++++++++++++++++++++++++++++++++++---
>  1 file changed, 35 insertions(+), 3 deletions(-)
> 
> diff --git a/utils/mountd/cache.c b/utils/mountd/cache.c
> index e04b86e..73c0be6 100644
> --- a/utils/mountd/cache.c
> +++ b/utils/mountd/cache.c
> @@ -266,6 +266,26 @@ static int get_uuid(const char *val, size_t uuidlen, char *u)
>  	return 1;
>  }
>  
> +
> +/*
> + * Don't ask libblkid for these filesystems. Note that BTRF is ignored, because
> + * we generate the identifier from statfs->f_fsid. The rest are network or
> + * pseudo filesystems. (See <linux/magic.h> for the basic IDs.)
> + */
> +static const long int nonblkid_filesystems[] = {
> +	0x9123683E,	/* BTRFS_SUPER_MAGIC */
> +	0xFF534D42,	/* CIFS_MAGIC_NUMBER */
> +	0x1373,		/* DEVFS_SUPER_MAGIC */
> +	0x73757245,	/* CODA_SUPER_MAGIC */
> +	0x564C,		/* NCP_SUPER_MAGIC */
> +	0x6969,		/* NFS_SUPER_MAGIC */
> +	0x9FA0,		/* PROC_SUPER_MAGIC */
> +	0x62656572,	/* SYSFS_MAGIC */
> +	0x517B,		/* SMB_SUPER_MAGIC */
> +	0x01021994,	/* TMPFS_SUPER_MAGIC */
> +	0		/* last */
> +};
> +
>  static int uuid_by_path(char *path, int type, size_t uuidlen, char *uuid)
>  {
>  	/* get a uuid for the filesystem found at 'path'.
> @@ -297,12 +317,24 @@ static int uuid_by_path(char *path, int type, size_t uuidlen, char *uuid)
>  	 */
>  	struct statfs64 st;
>  	char fsid_val[17];
> -	const char *blkid_val;
> +	const char *blkid_val = NULL;
>  	const char *val;
> +	int rc;
>  
> -	blkid_val = get_uuid_blkdev(path);
> +	rc = statfs64(path, &st);
> +
> +	if (type == 0 && rc == 0) {
> +		const long int *bad;
> +
> +		for (bad = nonblkid_filesystems; *bad; bad++) {
> +			if (*bad == st.f_type)
> +				break;
> +		}
> +		if (*bad == 0)
> +			blkid_val = get_uuid_blkdev(path);
> +	}
>  
> -	if (statfs64(path, &st) == 0 &&
> +	if (rc == 0 &&
>  	    (st.f_fsid.__val[0] || st.f_fsid.__val[1]))
>  		snprintf(fsid_val, 17, "%08x%08x",
>  			 st.f_fsid.__val[0], st.f_fsid.__val[1]);
> -- 
> 1.8.4.2
> 

Re: rpc.mountd high cpu usage

[Sander Klein]

Hi,

Thank you very much for this patch. I've added the ZFS magic and tested 
it on my nfs-utils-1.2.8 package and it looks like it fixes my issue.

Is there any chance this patch will be accepted upstream with the 
ZFS_SUPER_MAGIC as shown below?

Greets,

Sander

 From e4f5b38c87ef8d713c6d0a3169afaf1acc7e22c6 Mon Sep 17 00:00:00 2001
 From: Karel Zak <kzak@redhat.com>
Date: Mon, 6 Jan 2014 12:03:01 +0100
Subject: [PATCH] mountd: optimize libblkid usage

  * use get_uuid_blkdev() only first time for the path (it means
    that uuid_by_path() is called with type==0)

  * don't use libblkid for btrfs, network or pseudo filesystems

Note that the patch defines the fs type ID rather than include
<linux/magic.h> as this file seems incomplete and libc specific).

Signed-off-by: Karel Zak <kzak@redhat.com>
---
  utils/mountd/cache.c | 38 +++++++++++++++++++++++++++++++++++---
  1 file changed, 35 insertions(+), 3 deletions(-)

Index: nfs-utils-1.2.8/utils/mountd/cache.c
===================================================================
--- nfs-utils-1.2.8.orig/utils/mountd/cache.c	2013-05-02 
14:21:12.000000000 +0200
+++ nfs-utils-1.2.8/utils/mountd/cache.c	2014-01-07 20:46:55.799904557 
+0100
@@ -266,6 +266,27 @@
  	return 1;
  }

+
+/*
+ * Don't ask libblkid for these filesystems. Note that BTRF is ignored, 
because
+ * we generate the identifier from statfs->f_fsid. The rest are network 
or
+ * pseudo filesystems. (See <linux/magic.h> for the basic IDs.)
+ */
+static const long int nonblkid_filesystems[] = {
+	0x2fc12fc1,	/* ZFS_SUPER_MAGIC */
+	0x9123683E,	/* BTRFS_SUPER_MAGIC */
+	0xFF534D42,	/* CIFS_MAGIC_NUMBER */
+	0x1373,		/* DEVFS_SUPER_MAGIC */
+	0x73757245,	/* CODA_SUPER_MAGIC */
+	0x564C,		/* NCP_SUPER_MAGIC */
+	0x6969,		/* NFS_SUPER_MAGIC */
+	0x9FA0,		/* PROC_SUPER_MAGIC */
+	0x62656572,	/* SYSFS_MAGIC */
+	0x517B,		/* SMB_SUPER_MAGIC */
+	0x01021994,	/* TMPFS_SUPER_MAGIC */
+	0		/* last */
+};
+
  static int uuid_by_path(char *path, int type, size_t uuidlen, char 
*uuid)
  {
  	/* get a uuid for the filesystem found at 'path'.
@@ -297,12 +318,24 @@
  	 */
  	struct statfs64 st;
  	char fsid_val[17];
-	const char *blkid_val;
+	const char *blkid_val = NULL;
  	const char *val;
+	int rc;
+
+	rc = statfs64(path, &st);
+
+	if (type == 0 && rc == 0) {
+		const long int *bad;

-	blkid_val = get_uuid_blkdev(path);
+		for (bad = nonblkid_filesystems; *bad; bad++) {
+			if (*bad == st.f_type)
+				break;
+		}
+		if (*bad == 0)
+			blkid_val = get_uuid_blkdev(path);
+	}

-	if (statfs64(path, &st) == 0 &&
+	if (rc == 0 &&
  	    (st.f_fsid.__val[0] || st.f_fsid.__val[1]))
  		snprintf(fsid_val, 17, "%08x%08x",
  			 st.f_fsid.__val[0], st.f_fsid.__val[1]);

Re: rpc.mountd high cpu usage

[J. Bruce Fields]

On Tue, Jan 07, 2014 at 08:55:12PM +0100, Sander Klein wrote:
> Hi,
> 
> Thank you very much for this patch. I've added the ZFS magic and
> tested it on my nfs-utils-1.2.8 package and it looks like it fixes
> my issue.
> 
> Is there any chance this patch will be accepted upstream with the
> ZFS_SUPER_MAGIC as shown below?

OK by me; cc'ing steved.

--b.

> 
> Greets,
> 
> Sander
> 
> From e4f5b38c87ef8d713c6d0a3169afaf1acc7e22c6 Mon Sep 17 00:00:00 2001
> From: Karel Zak <kzak@redhat.com>
> Date: Mon, 6 Jan 2014 12:03:01 +0100
> Subject: [PATCH] mountd: optimize libblkid usage
> 
>  * use get_uuid_blkdev() only first time for the path (it means
>    that uuid_by_path() is called with type==0)
> 
>  * don't use libblkid for btrfs, network or pseudo filesystems
> 
> Note that the patch defines the fs type ID rather than include
> <linux/magic.h> as this file seems incomplete and libc specific).
> 
> Signed-off-by: Karel Zak <kzak@redhat.com>
> ---
>  utils/mountd/cache.c | 38 +++++++++++++++++++++++++++++++++++---
>  1 file changed, 35 insertions(+), 3 deletions(-)
> 
> Index: nfs-utils-1.2.8/utils/mountd/cache.c
> ===================================================================
> --- nfs-utils-1.2.8.orig/utils/mountd/cache.c	2013-05-02
> 14:21:12.000000000 +0200
> +++ nfs-utils-1.2.8/utils/mountd/cache.c	2014-01-07
> 20:46:55.799904557 +0100
> @@ -266,6 +266,27 @@
>  	return 1;
>  }
> 
> +
> +/*
> + * Don't ask libblkid for these filesystems. Note that BTRF is
> ignored, because
> + * we generate the identifier from statfs->f_fsid. The rest are
> network or
> + * pseudo filesystems. (See <linux/magic.h> for the basic IDs.)
> + */
> +static const long int nonblkid_filesystems[] = {
> +	0x2fc12fc1,	/* ZFS_SUPER_MAGIC */
> +	0x9123683E,	/* BTRFS_SUPER_MAGIC */
> +	0xFF534D42,	/* CIFS_MAGIC_NUMBER */
> +	0x1373,		/* DEVFS_SUPER_MAGIC */
> +	0x73757245,	/* CODA_SUPER_MAGIC */
> +	0x564C,		/* NCP_SUPER_MAGIC */
> +	0x6969,		/* NFS_SUPER_MAGIC */
> +	0x9FA0,		/* PROC_SUPER_MAGIC */
> +	0x62656572,	/* SYSFS_MAGIC */
> +	0x517B,		/* SMB_SUPER_MAGIC */
> +	0x01021994,	/* TMPFS_SUPER_MAGIC */
> +	0		/* last */
> +};
> +
>  static int uuid_by_path(char *path, int type, size_t uuidlen, char
> *uuid)
>  {
>  	/* get a uuid for the filesystem found at 'path'.
> @@ -297,12 +318,24 @@
>  	 */
>  	struct statfs64 st;
>  	char fsid_val[17];
> -	const char *blkid_val;
> +	const char *blkid_val = NULL;
>  	const char *val;
> +	int rc;
> +
> +	rc = statfs64(path, &st);
> +
> +	if (type == 0 && rc == 0) {
> +		const long int *bad;
> 
> -	blkid_val = get_uuid_blkdev(path);
> +		for (bad = nonblkid_filesystems; *bad; bad++) {
> +			if (*bad == st.f_type)
> +				break;
> +		}
> +		if (*bad == 0)
> +			blkid_val = get_uuid_blkdev(path);
> +	}
> 
> -	if (statfs64(path, &st) == 0 &&
> +	if (rc == 0 &&
>  	    (st.f_fsid.__val[0] || st.f_fsid.__val[1]))
>  		snprintf(fsid_val, 17, "%08x%08x",
>  			 st.f_fsid.__val[0], st.f_fsid.__val[1]);
> 

Re: rpc.mountd high cpu usage

[Steve Dickson]

On 07/01/14 14:55, Sander Klein wrote:
> Hi,
> 
> Thank you very much for this patch. I've added the ZFS magic and tested it on my nfs-utils-1.2.8 package and it looks like it fixes my issue.
> 
> Is there any chance this patch will be accepted upstream with the ZFS_SUPER_MAGIC as shown below?
It looks reasonable to me... I committed... 

steved.

> 
> Greets,
> 
> Sander
> 
> From e4f5b38c87ef8d713c6d0a3169afaf1acc7e22c6 Mon Sep 17 00:00:00 2001
> From: Karel Zak <kzak@redhat.com>
> Date: Mon, 6 Jan 2014 12:03:01 +0100
> Subject: [PATCH] mountd: optimize libblkid usage
> 
>  * use get_uuid_blkdev() only first time for the path (it means
>    that uuid_by_path() is called with type==0)
> 
>  * don't use libblkid for btrfs, network or pseudo filesystems
> 
> Note that the patch defines the fs type ID rather than include
> <linux/magic.h> as this file seems incomplete and libc specific).
> 
> Signed-off-by: Karel Zak <kzak@redhat.com>
> ---
>  utils/mountd/cache.c | 38 +++++++++++++++++++++++++++++++++++---
>  1 file changed, 35 insertions(+), 3 deletions(-)
> 
> Index: nfs-utils-1.2.8/utils/mountd/cache.c
> ===================================================================
> --- nfs-utils-1.2.8.orig/utils/mountd/cache.c    2013-05-02 14:21:12.000000000 +0200
> +++ nfs-utils-1.2.8/utils/mountd/cache.c    2014-01-07 20:46:55.799904557 +0100
> @@ -266,6 +266,27 @@
>      return 1;
>  }
> 
> +
> +/*
> + * Don't ask libblkid for these filesystems. Note that BTRF is ignored, because
> + * we generate the identifier from statfs->f_fsid. The rest are network or
> + * pseudo filesystems. (See <linux/magic.h> for the basic IDs.)
> + */
> +static const long int nonblkid_filesystems[] = {
> +    0x2fc12fc1,    /* ZFS_SUPER_MAGIC */
> +    0x9123683E,    /* BTRFS_SUPER_MAGIC */
> +    0xFF534D42,    /* CIFS_MAGIC_NUMBER */
> +    0x1373,        /* DEVFS_SUPER_MAGIC */
> +    0x73757245,    /* CODA_SUPER_MAGIC */
> +    0x564C,        /* NCP_SUPER_MAGIC */
> +    0x6969,        /* NFS_SUPER_MAGIC */
> +    0x9FA0,        /* PROC_SUPER_MAGIC */
> +    0x62656572,    /* SYSFS_MAGIC */
> +    0x517B,        /* SMB_SUPER_MAGIC */
> +    0x01021994,    /* TMPFS_SUPER_MAGIC */
> +    0        /* last */
> +};
> +
>  static int uuid_by_path(char *path, int type, size_t uuidlen, char *uuid)
>  {
>      /* get a uuid for the filesystem found at 'path'.
> @@ -297,12 +318,24 @@
>       */
>      struct statfs64 st;
>      char fsid_val[17];
> -    const char *blkid_val;
> +    const char *blkid_val = NULL;
>      const char *val;
> +    int rc;
> +
> +    rc = statfs64(path, &st);
> +
> +    if (type == 0 && rc == 0) {
> +        const long int *bad;
> 
> -    blkid_val = get_uuid_blkdev(path);
> +        for (bad = nonblkid_filesystems; *bad; bad++) {
> +            if (*bad == st.f_type)
> +                break;
> +        }
> +        if (*bad == 0)
> +            blkid_val = get_uuid_blkdev(path);
> +    }
> 
> -    if (statfs64(path, &st) == 0 &&
> +    if (rc == 0 &&
>          (st.f_fsid.__val[0] || st.f_fsid.__val[1]))
>          snprintf(fsid_val, 17, "%08x%08x",
>               st.f_fsid.__val[0], st.f_fsid.__val[1]);
> 
> -- 
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: rpc.mountd high cpu usage

[Sander Klein]

On 07.01.2014 22:01, Steve Dickson wrote:
> On 07/01/14 14:55, Sander Klein wrote:
>> Hi,
>> 
>> Thank you very much for this patch. I've added the ZFS magic and 
>> tested it on my nfs-utils-1.2.8 package and it looks like it fixes my 
>> issue.
>> 
>> Is there any chance this patch will be accepted upstream with the 
>> ZFS_SUPER_MAGIC as shown below?
> It looks reasonable to me... I committed...
> 

Great, thank you all very much for fixing this.

Regards,

Sander