Bug #4995

panic in nlm_prog_4

Added by Robert Mustacchi over 5 years ago. Updated over 5 years ago.

nfs - NFS server and client
Start date:
Due date:
% Done:


Estimated time:


While testing, we discovered the following panic:

> $C
ffffff00b9369a00 mutex_enter+0xb()
ffffff00b9369a40 nlm_fh_to_vhold+0x38(ffffff5a86459e18, ffffff00b9369b38)
ffffff00b9369ad0 nlm_do_share+0xd4(ffffff00b9369b20, ffffff00b9369b80, 
ffffff00b9369b00 nlm4_share_4_svc+0x19(ffffff00b9369b20, ffffff00b9369b80, 
ffffff00b9369c20 nlm_dispatch+0xe6(ffffff00b9369ca0, ffffff898626ae00, 
ffffff00b9369c40 nlm_prog_4+0x34(ffffff00b9369ca0, ffffff898626ae00)
ffffff00b9369d20 svc_getreq+0x1c1(ffffff898626ae00, ffffff1a005b2120)
ffffff00b9369d90 svc_run+0x146(ffffff9c291b76b0)
ffffff00b9369dd0 svc_do_run+0x8e(2)
ffffff00b9369ec0 nfssys+0xf1(e, fecf0fbc)
ffffff00b9369f10 _sys_sysenter_post_swapgs+0x149()

Looking at nlm_fh_to_vhold

nlm_fh_to_vhold:                pushq  %rbp
nlm_fh_to_vhold+1:              movq   %rsp,%rbp
nlm_fh_to_vhold+4:              subq   $0x30,%rsp
nlm_fh_to_vhold+8:              movq   %r12,-0x18(%rbp)
nlm_fh_to_vhold+0xc:            movq   %rdi,-0x8(%rbp)
nlm_fh_to_vhold+0x10:           movq   %rdi,%r12
nlm_fh_to_vhold+0x13:           movq   %rsi,%rdi
nlm_fh_to_vhold+0x16:           movq   %rbx,-0x20(%rbp)
nlm_fh_to_vhold+0x1a:           movq   %rsi,-0x10(%rbp)
nlm_fh_to_vhold+0x1e:           call   -0x53    <nlm_fh_to_vp>
nlm_fh_to_vhold+0x23:           movq   %rax,%rbx
nlm_fh_to_vhold+0x26:           xorl   %eax,%eax
nlm_fh_to_vhold+0x28:           testq  %rbx,%rbx
nlm_fh_to_vhold+0x2b:           je     +0x1b    <nlm_fh_to_vhold+0x48>
nlm_fh_to_vhold+0x2d:           movq   %rbx,%rsi              <-- arg1 vp 0000000000ffffff
nlm_fh_to_vhold+0x30:           movq   %r12,%rdi             <-- arg0 hostp
nlm_fh_to_vhold+0x33:           call   -0x6728  <nlm_vhold_get>
nlm_fh_to_vhold+0x38:           movq   %rbx,%rdi                <------ HERE
nlm_fh_to_vhold+0x3b:           movq   %rax,-0x28(%rbp)
nlm_fh_to_vhold+0x3f:           call   +0x3925bfc       <vn_rele>
nlm_fh_to_vhold+0x44:           movq   -0x28(%rbp),%rax
nlm_fh_to_vhold+0x48:           movq   -0x20(%rbp),%rbx
nlm_fh_to_vhold+0x4c:           movq   -0x18(%rbp),%r12
nlm_fh_to_vhold+0x50:           leave
nlm_fh_to_vhold+0x51:           ret

Before we call nlm_vhold_get we know that we called nlm_fh_to_vp and we know the code checks for the returned vp to be non-null. So, we can assume that we got a non-null vp out of nlm_fh_to_vp. This is how we got to the point where we called nlm_vhold_get. That code assumes the vp is valid.

If we look at the registers we see:

> $r
%rax = 0x0000000000000000                 %r9  = 0x0000000000000000 
%rbx = 0xffffff5a86459e18                 %r10 = 0xfffffffffb8540cc bzero+0x17c
%rcx = 0xffffffdbe03bc140                 %r11 = 0xffffff81dcce4000 
%rdx = 0xffffffdbe03bc140                 %r12 = 0x00000000ffffffff 
%rsi = 0x0000000000ffffff                 %r13 = 0xffffff81dcce4f68 
%rdi = 0x00000000ffffffff                 %r14 = 0x0000000000000000 
%r8  = 0xffffff81dcce4f68                 %r15 = 0xffffff81dd214cb8 

%rip = 0xfffffffffb85ed2b mutex_enter+0xb
%rbp = 0xffffff00b9369a00
%rsp = 0xffffff00b93699c8
%rflags = 0x00010246
  id=0 vip=0 vif=0 ac=0 vm=0 rf=1 nt=0 iopl=0x0

                        %cs = 0x0030    %ds = 0x0000    %es = 0x0000
%trapno = 0xe           %fs = 0x0000    %gs = 0x0000
   %err = 0x2

It appears that our vp may have been 0x00000000ffffffff, assuming it wasn't changed. However, this is consistent with the panic

> $<panicbuf
             cpu                6
          thread ffffffdbe03bc140
BAD TRAP: type=e (#pf Page fault) rp=ffffff00b93698d0 addr=ffffffff occurred in 
module "unix" due to an illegal access to a user address

What is hard to figure out is how nlm_fh_to_vp ever returned non-null. This code basically just trusts the fhandle it got from the RPC and sends it along to lm_fhtovp. That function first does a getvfs on the fsid contained in the fhandle.

Looking at the netobj we got in nlm_fh_to_vhold, and converting to an fhandle, we see:

> ffffff00b9369b38::print struct netobj 
    n_len = 0x24
    n_bytes = 0xffffff4a48c7a838 "4f469682-0dae-4bbe-8878-314b01329bdf" 
> ffffff4a48c7a838::print fhandle_t
    fh_fsid = {
        val = [ 0x36346634, 0x32383639 ]
    fh_len = 0x302d                   
    fh_data = [ "dae-4bbe-8" ]
    fh_xlen = 0x3738
    fh_xdata = [ "8-314b0132" ]

I ran the following and did not match any vfs's in the kernel, so I am not sure how getvfs ever returned a non-null vfsp in lm_fhtovp.

> ::fsinfo ! awk '{print $1}' | grep -v VFSP >/tmp/jj; ::cat /tmp/jj | ::print  vfs_t  vfs_fsid ! grep 36346634

Unwinding the stack a little by hand, we can see the stack frame when we're in nlm_fh_to_vhold

-30 ffffff00b9369a10:  309a36b9 00ffffff      ffffff00b9369a30 ?
-28 ffffff00b9369a18:  02099bfb ffffffff      fffffffffb9b0902 scratch for nvp
-20 ffffff00b9369a20:  189e4586 5affffff rbx  ffffff5a86459e18
-18 ffffff00b9369a28:  00c54cd7 19ffffff r12  ffffff19d74cc500
-10 ffffff00b9369a30:  389b36b9 00ffffff rsi  ffffff00b9369b38 arg1 fh
-8  ffffff00b9369a38:  189e4586 5affffff rdi  ffffff5a86459a18 arg0 hostp
rbp ffffff00b9369a40:  d09a36b9 00ffffff      ffffff00b9369ad0 old rbp, see $C
    ffffff00b9369a48:  14fa1ff8 ffffffff      fffffffff81ffa14 ret addr in caller

Everything is consistent here.

> fffffffff81fe408::whatis
fffffffff81fe408 is nlm_fh_to_vhold+0x38, in klmmod's text segment

Looking at the stack frame for the call to nlm_vhold_get, we see:

rsp ffffff00b93699c8:  b67d1ff8 ffffffff      fffffffff81f7db6 ret addr @ +0xd6
-30 ffffff00b93699d0:  ffffffff 00000000      00000000ffffffff
-28 ffffff00b93699d8:  189e4586 5affffff r12  ffffff5a86459e18  
-20 ffffff00b93699e0:  809b36b9 00ffffff r13  ffffff00b9369b80
-18 ffffff00b93699e8:  209b36b9 00ffffff r14  ffffff00b9369b20
-10 ffffff00b93699f0:  ffffffff 00000000 rsi  00000000ffffffff arg1 vp
-8  ffffff00b93699f8:  189e4586 5affffff rdi  ffffff5a86459e18 arg0 hostp
rbp ffffff00b9369a00:  409a36b9 00ffffff      ffffff00b9369a40 old rbp
    ffffff00b9369a08:  08e41ff8 ffffffff      fffffffff81fe408 ret addr @ +0x38

The return is for the mutex on the vp

> fffffffff81f7db6::whatis
fffffffff81f7db6 is nlm_vhold_get+0xd6, in klmmod's text segment

So we can confirm that we did put 00000000ffffffff as the vp parameter.

Given our fh_fsid: ffffff4a48c7a838 val = [ 0x36346634, 0x32383639 ]

Looking at getvfs, we can manually calculate that the dev for this is 0xd8d00006634 and the vhno hash index is 449 (0x1c1).

> ::sizeof rvfs_t
sizeof (rvfs_t) = 0x18

0x1c1 * 0x18 = 0x2a18

> rvfs_list/J
rvfs_list:      ffffff197b1d6000 

so our hash bucket should be ffffff197b1d6000 + 2a18 = ffffff197b1d8a18

> ffffff197b1d8a18::print rvfs_t
    rvfs_head = 0
    rvfs_lock = {
        _opaque = [ 0 ]
    rvfs_len = 0

This bucket is empty so that implies getvfs should have returned NULL.

In looking at the dump, I came to the same conclusion – that we somehow had loaded 0xffffffff into vp. I, too, was going out of my mind (this certainly doesn't appear to be possible from the source) so I looked at the disassembly for lm_fhtovp to see if it somehow differed from the source:

> lm_fhtovp::dis
lm_fhtovp:                      leaq   +0x359359(%rip),%rax     <lm_fhtovp_info>
lm_fhtovp+7:                    cmpl   $0x0,0x20(%rax)
lm_fhtovp+0xb:                  je     -0xbf1   <stubs_common_code>
lm_fhtovp+0x11:                 testb  $0x10,0x20(%rax)
lm_fhtovp+0x15:                 jne    -0xbfb   <stubs_common_code>
lm_fhtovp+0x1b:                 jmp    *0x18(%rax)

This of course differs drastically from the source – it's a stub! The module that provides the implementation of lm_fhtovp – nfssrv – is indeed not loaded:

> ::modinfo ! grep nfssrv
252                0        0   0 nfssrv (?)

And usr/src/uts/intel/ia32/ml/modstubs.s explains it:

 * Stubs for nfs server-only code.
        STUB(nfssrv,            lm_nfs3_fhtovp, nomod_minus_one);
        STUB(nfssrv,            lm_fhtovp,      nomod_minus_one);
        STUB(nfssrv,            exportfs,       nomod_minus_one);
        STUB(nfssrv,            nfs_getfh,      nomod_minus_one);
        STUB(nfssrv,            nfsl_flush,     nomod_minus_one);
        STUB(nfssrv,            rfs4_check_delegated, nomod_zero);
        STUB(nfssrv,            mountd_args,    nomod_minus_one);
        NO_UNLOAD_STUB(nfssrv,  rdma_start,     nomod_zero);
        NO_UNLOAD_STUB(nfssrv,  nfs_svc,        nomod_zero);

And here (of course) is the definition of nomod_minus_one():

        return (-1);

And just closing the loop, klmmod indeed does not have nfssrv as a dependency:

[root@headnode (coal) /kernel/misc/amd64]# dump -Lv klmmod 


[INDEX]    Tag         Value
[1]    NEEDED          strmod/rpcmod
[2]    NEEDED          fs/nfs
[3]    FLAGS           TEXTREL
[4]    FLAGS_1         0
[5]    SUNW_STRPAD     0x200
[6]    SUNW_LDMACH     EM_AMD64

So it appears that the problem is that klmmod needs to have a dependency on not (just) fs/nfs, but also misc/nfssrv. Untested diffs:

diff --git a/usr/src/uts/intel/klmmod/Makefile b/usr/src/uts/intel/klmmod/Makefi
index 43e24b2..ea4b874 100644
--- a/usr/src/uts/intel/klmmod/Makefile
+++ b/usr/src/uts/intel/klmmod/Makefile
@@ -58,7 +58,7 @@ INSTALL_TARGET        = $(BINARY) $(ROOTMODULE)
 #      Overrides.
-LDFLAGS                += -dy -Nstrmod/rpcmod -Nfs/nfs
+LDFLAGS                += -dy -Nstrmod/rpcmod -Nfs/nfs -Nmisc/nfssrv
 LDFLAGS                += -M $(UTSBASE)/common/klm/mapfile-mod

diff --git a/usr/src/uts/sparc/klmmod/Makefile b/usr/src/uts/sparc/klmmod/Makefi
index ed0ac4c..effb169 100644
--- a/usr/src/uts/sparc/klmmod/Makefile
+++ b/usr/src/uts/sparc/klmmod/Makefile
@@ -59,7 +59,7 @@ INSTALL_TARGET        = $(BINARY) $(ROOTMODULE)
 #      Overrides.
 CFLAGS         += $(CCVERBOSE)
-LDFLAGS                += -dy -Nstrmod/rpcmod -Nfs/nfs
+LDFLAGS                += -dy -Nstrmod/rpcmod -Nfs/nfs -Nmisc/nfssrv
 LDFLAGS                += -M $(UTSBASE)/common/klm/mapfile-mod

It looks like I can't do the above suggested fix since that creates a circular dependency and the modules don't load

nfssrv: unable to resolve dependency, cannot load module 'misc/klmmod'
/kernel/misc/amd64/nfssrv: undefined symbol 'lm_global_nlmid'
/kernel/misc/amd64/nfssrv: undefined symbol 'lm_remove_file_locks'
/kernel/misc/amd64/nfssrv: undefined symbol 'lm_set_nlmid_flk'
WARNING: mod_load: cannot load module 'nfssrv'
WARNING: nfssrv: unable to resolve dependency, module 'misc/klmmod' not found
klmmod: unable to resolve dependency, cannot load module 'misc/nfssrv'


# dump -Lv nfssrv 


[INDEX]    Tag         Value
[1]    NEEDED          strmod/rpcmod
[2]    NEEDED          fs/nfs
[3]    NEEDED          misc/rpcsec
[4]    NEEDED          misc/klmmod
[5]    FLAGS           TEXTREL
[6]    FLAGS_1         0
[7]    SUNW_STRPAD     0x200
[8]    SUNW_LDMACH     EM_AMD64

However, there seems to be no valid reason for lm_fhtovp to be a stub at all, so we can move that into the klm code. The lm_nfs3_fhtovp code also seems to be unused and it looks like it can be removed as part of this cleanup.



Updated by Electric Monk over 5 years ago

  • Status changed from New to Closed

git commit b4ecf764d8099c92d5c9c0f13a45514377f3d292

commit  b4ecf764d8099c92d5c9c0f13a45514377f3d292
Author: Jerry Jelinek <>
Date:   2014-07-16T17:37:30.000Z

    4995 panic in nlm_prog_4
    Reviewed by: Bryan Cantrill <>
    Reviewed by: Gordon Ross <>
    Reviewed by: Dan McDonald <>
    Reviewed by: Marcel Telka <>
    Approved by: Richard Lowe <>

Also available in: Atom PDF