Re: nfs client's OpenOwner count increases without bounds

Alan Somers <asomers@freebsd.org> wrote:
> On Thu, May 5, 2022 at 8:49 AM Rick Macklem <rmacklem@uoguelph.ca> wrote:
> >
> > Alan Somers <asomers@freebsd.org> wrote:
> > > On Wed, May 4, 2022 at 6:56 PM Rick Macklem <rmacklem@uoguelph.ca> wrote:
> > > >
> > > > Alan Somers <asomers@freebsd.org> wrote:
> > > > > On Wed, May 4, 2022 at 5:23 PM Rick Macklem <rmacklem@uoguelph.ca> wrote:
> > > > > >
> > > > > > Alan Somers <asomers@freebsd.org> wrote:
> > > > > > > I have a FreeBSD 13 (tested on both 13.0-RELEASE and 13.1-RC5) desktop
> > > > > > > mounting /usr/home over NFS 4.2 from an 13.0-RELEASE server.  It
> > > > > > > worked fine until a few weeks ago.  Now, the desktop's performance
> > > > > > > slowly degrades.  It becomes less and less responsive until I restart
> > > > > > > X after 2-3 days.  /var/log/Xorg.0.log shows plenty of entries like
> > > > > > > "AT keyboard: client bug: event processing lagging behind by 112ms,
> > > > > > > your system is too slow".  "top -S" shows that the busiest process is
> > > > > > > nfscl.  A dtrace profile shows that nfscl is spending most of its time
> > > > > > > in nfscl_cleanup_common, in the loop over all nfsclowner objects.
> > > > > > > Running "nfsdumpstate" on the server shows thousands of OpenOwners for
> > > > > > > that client, and < 10 for any other NFS client.  The OpenOwners
> > > > > > > increases by about 3000 per day.  And yet, "fstat" shows only a couple
> > > > > > > hundred open files on the NFS file system.  Why are OpenOwners so
> > > > > > > high?  Killing most of my desktop processes doesn't seem to make a
> > > > > > > difference.  Restarting X does improve the perceived responsiveness,
> > > > > > > though it does not change the number of OpenOwners.
> > > > > > >
> > > > > > > How can I figure out which process(es) are responsible for the
> > > > > > > excessive OpenOwners?
> > > > > > An OpenOwner represents a process on the client. The OpenOwner
> > > > > > name is an encoding of pid + process startup time.
> > > > > > However, I can't think of an easy way to get at the OpenOwner name.
> > > > > >
> > > > > > Now, why aren't they going away, hmm..
> > > > > >
> > > > > > I'm assuming the # of Opens is not large?
> > > > > > (Openowners cannot go away until all associated opens
> > > > > >  are closed.)
> > > > >
> > > > > Oh, I didn't mention that yes the number of Opens is large.  Right
> > > > > now, for example, I have 7950 OpenOwner and 8277 Open.
> > > > Well, the openowners cannot go away until the opens go away,
> > > > so the problem is that the opens are not getting closed.
> > > >
> > > > Close happens when the v_usecount on the vnode goes to zero.
> > > > Something is retaining the v_usecount. One possibility is that most
> > > > of the opens are for the same file, but with different openowners.
> > > > If that is the case, the "oneopenown" mount option will deal with it.
> > > >
> > > > Another possibility is that something is retaining a v_usecount
> > > > reference on a lot of the vnodes. (This used to happen when a nullfs
> > > > mount with caching enabled was on top of the nfs mount.)
> > > > I don't know what other things might do that?
> > >
> > > Yeah, I remember the nullfs problem.  But I'm not using nullfs on this
> > > computer anymore.  Is there any debugging facility that can list
> > > vnodes?  All I know of is "fstat", and that doesn't show anywhere near
> > > the number of NFS Opens.
> > Don't ask me. My debugging technology consists of printf()s.
> >
> > An NFSv4 Open is for a <clientid, openowner (represents a process on the
> > client), file>. It is probably opening the same file by many different
> > processes. The "oneopenown" option makes the client use the same
> > openowner for all opens, so that there is one open per file.
> >
> > > >
> > > > > >
> > > > > > Commit 1cedb4ea1a79 in main changed the semantics of this
> > > > > > a little, to avoid a use-after-free bug. However, it is dated
> > > > > > Feb. 25, 2022 and is not in 13.0, so I don't think it could
> > > > > > be the culprit.
> > > > > >
> > > > > > Essentially, the function called nfscl_cleanupkext() should call
> > > > > > nfscl_procdoesntexist(), which returns true after the process has
> > > > > > exited and when that is the case, calls nfscl_cleanup_common().
> > > > > > --> nfscl_cleanup_common() will either get rid of the openowner or,
> > > > > >       if there are still children with open file descriptors, mark it "defunct"
> > > > > >       so it can be free'd once the children close the file.
> > > > > >
> > > > > > It could be that X is now somehow creating a long chain of processes
> > > > > > where the children inherit a file descriptor and that delays the cleanup
> > > > > > indefinitely?
> > > > > > Even then, everything should get cleaned up once you kill off X?
> > > > > > (It might take a couple of seconds after killing all the processes off.)
> > > > > >
> > > > > > Another possibility is that the "nfscl" thread is wedged somehow.
> > > > > > It is the one that will call nfscl_cleanupkext() once/sec. If it never
> > > > > > gets called, the openowners will never go away.
> > > > > >
> > > > > > Being old fashioned, I'd probably try to figure this out by adding
> > > > > > some printf()s to nfscl_cleanupkext() and nfscl_cleanup_common().
> > > > >
> > > > > dtrace shows that nfscl_cleanupkext() is getting called at about 0.6 hz.
> > > > That sounds ok. Since there are a lot of opens/openowners, it probably
> > > > is getting behind.
> > > >
> > > > > >
> > > > > > To avoid the problem, you can probably just use the "oneopenown"
> > > > > > mount option. With that option, only one openowner is used for
> > > > > > all opens. (Having separate openowners for each process was needed
> > > > > > for NFSv4.0, but not NFSv4.1/4.2.)
> > > > > >
> > > > > > > Or is it just a red herring and I shouldn't
> > > > > > > worry?
> > > > > > Well, you can probably avoid the problem by using the "oneopenown"
> > > > > > mount option.
> > > > >
> > > > > Ok, I'm trying that now.  After unmounting and remounting NFS,
> > > > > "nfsstat -cE" reports 1 OpenOwner and 11 Opens".  But on the server,
> > > > > "nfsdumpstate" still reports thousands.  Will those go away
> > > > > eventually?
> > > > If the opens are gone then, yes, they will go away. They are retained for
> > > > a little while so that another Open against the openowner does not need
> > > > to recreate the openowner (which also implied an extra RPC to confirm
> > > > the openowner in NFSv4.0).
> > > >
> > > > I think they go away after a few minutes, if I recall correctly.
> > > > If the server thinks there are still Opens, then they will not go away.
> > >
> > > Uh, they aren't going away.  It's been a few hours now, and the NFS
> > > server still reports the same number of opens and openowners.
> > Yes, the openowners won't go away until the opens go away and the
> > opens don't go away until the client closes them. (Once the opens are
> > closed, the openowners go away after something like 5minutes.)
> >
> > For NFSv4.0, the unmount does a SetclientID/SetclientIDconfirm, which
> > gets rid of all opens at the server. However, NFSv4.1/4.2 does not have
> > this. It has a DestroyClient, but it is required to return NFSERR_CLIENTBUSY
> > if there are outstanding opens (servers are not supposed to "forget" opens,
> > except when they crash. Even then, if they have something like non-volatile
> > ram, they can remember opens through a reboot. (FreeBSD does forget them
> > upon reboot.)
> > Maybe for 4.1/4.2 the client should try and close any outstanding opens.
> > (Normally, they should all be closed once all files are POSIX closed. I
> >  suspect that it didn't happen because the "nfscl" thread was killed off
> >  during unmount before it got around to doing all of them.)
> > I'll look at this.
> >
> > How to get rid of them now...
> > - I think a nfsrevoke(8) on the clientid will do so. However, if the same
> >    clientid is in use for your current mount, you'll need to unmount before
> >    doing so.
> >
> > Otherwise, I think they'll be there until a server reboot (or kldunload/kldload
> > of the nfsd, if it is not built into the kernel. Even a restart of the nfsd daemon
> > does not get rid of them, since the "server should never forget opens" rule
> > is applied.
>
> As it turns out, the excessive opens disappeared from the serve
> sometime overnight.  They disappeared eventually, but it took hours
> rather than minutes.
Heck, I just wrote the code. I have no idea what it really does;-)
(Although meant to be "tongue in cheek", it is true. Blame old age or the
 simple fact that this code was written in dibs and drabs over 20+ years.)
The lease would have expired, but since the FreeBSD server is what they
call a "courtesy server", it does not throw away state until the lease has
expired and a conflicting lock request is made (not happening for opens
from FreeBSD or Linux clients) or the server's resource limits are exceeded.
I think the resource limit would be something like 90% of 500000, which is
a lot more opens/openowners than you reported, unless other clients pushed
the number to that level overnight?

There is something called NFSRV_MOULDYLEASE which gets rid of the state,
but that is set to 1 week at the moment.

So, why did they go away in hours? Unless you had close to 500000 opens +
openowners, I haven't a clue. But it worked, so I guess we are happy?

> And using oneopenowner on the client, there are now only a modest
> number of opens (133), and exactly one openowner.  So I think it will
> certainly work for my use case.
The entry for "oneopenown" in "man mount_nfs" tries to explain this.
Feel free to come up with better words. I've never been good at doc.

rick

-Alan