Major issues with nfsv4

Rick Macklem rmacklem at
Mon Dec 14 00:24:18 UTC 2020

J David wrote:
[stuff snipped]
>The most common trace (91 times, or over 1/4 of all observed) is:
>__mtx_lock_sleep+0xf8 nfscl_nodeleg+0x207 nfs_lookup+0x314
>VOP_LOOKUP_APV+0x75 null_lookup+0x98 VOP_LOOKUP_APV+0x75 >lookup+0x451
>namei+0x414 kern_statat+0x72 freebsd11_stat+0x30 amd64_syscall+0x387
>This trace appears roughly uniformly (28/38/34) in 3 of the 4 processes.
nfscl_nodeleg() plus two others acquire the mutex to check for a delegation
for the file. Servers should only issue delegations when the callback
path is working and some never issue delegations.

So, if you are not running the nfscbd(8) daemon (there is no need
unless you are using delegations or pNFS) a trivial check for the
callback path being enabled should determine that no delegation
exists if it is not enabled. This avoids acquiring the mutex for this
common case.
--> You have no "Delegs" according to your "nfsstat -c -E".

So, if you set up a test system with the attached patch applied to the
kernel and you do not run nfscbd(8) (ie no nfscbd_enable="YES" in
your /etc/rc.conf) this patch might help.
--> It avoids acquiring the mutex for lookups and getattrs (stat calls).

The only reason I haven't done this before is a concern w.r.t. a broken
NFSv4 server that erroneously issues delegations when the callback
path is not working. (I don't know of such a server and, since you do not
have delegations, it should not be an issue for your case.)

Might be enough to alleviate your problem.

I will work on changing the single open linked list to a hash table of
linked lists, but that is probably weeks away from a test patch.

Let me know if you can try the patch and if it helps, rick

The full set of traces (sorted by uniq -c) is here:

(This message is already long enough!)

The characters stripped off the front of each line are consistently:

(pid) (uid) python3 -

It happens these were all Python-based jobs.  Python seems predisposed
to trigger this, but non-Python jobs trigger it as well.  Heavy use of
stat() does seem to be a common element regardless of job type.

Here's the output of "nfsstat -E -c" 60 seconds after running it with -z:

Client Info:
RPC Counts:
      Getattr      Setattr       Lookup     Readlink         Read        Write
         1667          111         6376            0           42          153
       Create       Remove       Rename         Link      Symlink        Mkdir
          111            7           14            0            0            0
        Rmdir      Readdir     RdirPlus       Access        Mknod       Fsstat
            0            0            0         2620            0          160
       FSinfo     pathConf       Commit      SetClId    SetClIdCf         Lock
            0            0          113            0            0           48
        LockT        LockU         Open      OpenCfr
            0           48          320            0
   OpenDownGr        Close
            0          402
    RelLckOwn  FreeStateID    PutRootFH     DelegRet       GetAcl       SetAcl
            0            3            0            0            0            0
   ExchangeId   CreateSess  DestroySess  DestroyClId    LayoutGet   GetDevInfo
            0            0            0            0            0            0
 LayoutCommit LayoutReturn ReclaimCompl    ReadDataS   WriteDataS  CommitDataS
            0            0            0            0            0            0
   OpenLayout CreateLayout
            0            0
    OpenOwner        Opens    LockOwner        Locks       Delegs     LocalOwn
        21175       130439           30            6            0            0
    LocalOpen    LocalLown    LocalLock
            0            0            0
Rpc Info:
     TimedOut      Invalid    X Replies      Retries     Requests
            0            0            0            0        12247
Cache Info:
    Attr Hits  Attr Misses    Lkup Hits  Lkup Misses
      1110054          858      1002829         6361
    BioR Hits  BioR Misses    BioW Hits  BioW Misses
         2000           54          292          153
   BioRL Hits BioRL Misses    BioD Hits  BioD Misses
         6911            0          208            0
    DirE Hits  DirE Misses
          104            0

This does reflect the whole machine, not just those four processes.

Finally, when I attempted to kill those four processes with ktrace
running on all of them, the system panicked:

Fatal trap 12: page fault while in kernel mode
cpuid = 2; apic id = 02
fault virtual address = 0x10
fault code = supervisor read data, page not present
instruction pointer = 0x20:0xffffffff8272d28f
stack pointer         = 0x28:0xfffffe008a5f24c0
frame pointer         = 0x28:0xfffffe008a5f25f0
code segment = base 0x0, limit 0xfffff, type 0x1b
= DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 5627 (node)
trap number = 12
panic: page fault
cpuid = 2
time = 1607845622
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe008a5f2180
vpanic() at vpanic+0x17b/frame 0xfffffe008a5f21d0
panic() at panic+0x43/frame 0xfffffe008a5f2230
trap_fatal() at trap_fatal+0x391/frame 0xfffffe008a5f2290
trap_pfault() at trap_pfault+0x4f/frame 0xfffffe008a5f22e0
trap() at trap+0x286/frame 0xfffffe008a5f23f0
calltrap() at calltrap+0x8/frame 0xfffffe008a5f23f0
--- trap 0xc, rip = 0xffffffff8272d28f, rsp = 0xfffffe008a5f24c0, rbp
= 0xfffffe008a5f25f0 ---
null_bypass() at null_bypass+0xaf/frame 0xfffffe008a5f25f0
VOP_ADVLOCK_APV() at VOP_ADVLOCK_APV+0x80/frame 0xfffffe008a5f2620
closef() at closef+0x8f/frame 0xfffffe008a5f26b0
fdescfree_fds() at fdescfree_fds+0x3c/frame 0xfffffe008a5f2700
fdescfree() at fdescfree+0x466/frame 0xfffffe008a5f27c0
exit1() at exit1+0x488/frame 0xfffffe008a5f2820
sigexit() at sigexit+0x159/frame 0xfffffe008a5f2b00
postsig() at postsig+0x2fd/frame 0xfffffe008a5f2bc0
ast() at ast+0x317/frame 0xfffffe008a5f2bf0
doreti_ast() at doreti_ast+0x1f/frame 0x7fffffff67a0

The fsck ate the ktrace.out file on reboot.  This system does not have
kernel debug symbols.  If there's a way to try to figure out what
null_bypass+0xaf corresponds to using the machine that built this
kernel, which has the kernel, objects, debug symbols, and source,
please let me know.  It's built from releng/12.2 r368515.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: clstate.patch
Type: application/octet-stream
Size: 912 bytes
Desc: clstate.patch
URL: <>

More information about the freebsd-fs mailing list