Received-SPF: pass (google.com: best guess record for domain of linux-nfs-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
MIME-Version: 1.0
From:   John Bartoszewski <john.bartoszewski@gmail.com>
Date:   Fri, 5 Jul 2019 16:59:02 -0600
Message-ID: <CAMttjSSQibhZ4ekSMVRF0jeREA9n9s6puAJcOTR2vyn=W2W5sg@mail.gmail.com>
Subject: zfs server slow mounting ( mtab ?)
To:     linux-nfs@vger.kernel.org
Content-Type: text/plain; charset="UTF-8"
Sender: linux-nfs-owner@vger.kernel.org
Precedence: bulk

Hello,

I'm trying to setup a nfs server with over 3500+ zfs datasets
being exported. Only NFSv3 is needed.

The OS had a 4.4.172 kernel and nfs-utils 1.30. With these versions
when a client tried to mount an exported dataset, rpc.mountd spiked to
100% for several minutes, the kernel produced a bug and a trace
output, and the client never finished.

I have built a 4.19.56 kernel, libevent 2.1.10, util-linux 2.34 (for
libblkid), and nfs-utils 2.4.1. With this setup rpc.mountd does spike
to 100%, but at least a mount finishes, but it takes about 5 minutes.

nfs-utils was configured with:
./configure --disable-tirpc  --disable-nfsv4 --disable-nfsv41
--disable-gss --disable-ipv6

Stracing the new rpc.mountd it appears all the time is spent reading
the mtab.

Below is some of the output from:
/sbin/rpc.mountd --foreground --debug all

rpc.mountd: nfsd_fh: found 0x6173d50 path /
rpc.mountd: auth_unix_ip: inbuf 'nfsd 10.222.33.24'
rpc.mountd: auth_unix_ip: client 0x1d5bbb0 '10.222.33.0/24'
rpc.mountd: auth_unix_ip: inbuf 'nfsd 10.222.33.254'
rpc.mountd: auth_unix_ip: client 0x1d5bbb0 '10.222.33.0/24'
rpc.mountd: nfsd_export: inbuf '10.222.33.0/24 /nfsexport'
rpc.mountd: nfsd_export: found 0x6174260 path /nfsexport
rpc.mountd: nfsd_fh: inbuf '10.222.33.0/24 7
\x43000a00000000001ce354a654a34fd4a09f9b59f6aebb11'
rpc.mountd: nfsd_fh: found 0x6174270 path /nfsexport
rpc.mountd: nfsd_export: inbuf '10.222.33.0/24 /nfsexport/home'
rpc.mountd: nfsd_export: found 0x4cf8bc0 path /nfsexport/home
rpc.mountd: Received NULL request from 10.222.33.254
rpc.mountd: Received NULL request from 10.222.33.254
rpc.mountd: Received MNT3(/nfsexport/home/timmy) request from 10.222.33.254
rpc.mountd: authenticated mount request from 10.222.33.254:694 for
/nfsexport/home/timmy (/nfsexport/home/timmy)
rpc.mountd: nfsd_fh: inbuf '10.222.33.0/24 6 \x947e3e1400c9c79b0000000000000000'
rpc.mountd: nfsd_fh: found 0x4e54390 path /nfsexport/home/timmy

As you can see it searches for /, then /nfsexport, then /nfsexport/home,
and finally /nfsexport/home/timmy

But when zfs populates the mtab, the top level of the datasets
( /nfsexport ) is at the bottom of the mtab, 3500 lines down.
The next level is also at the bottom. So getmntent has to
read the mtab stream through several times. Actually:
open("/etc/mtab", O_RDONLY|O_CLOEXEC)   = 10
is called 50000 times during this one mount attempt.

Are they any suggestions anyone can make to help out?

More extensive output can be made available.

Thanks,
John