Date: Wed, 6 Mar 2024 15:00:10 -0800 From: Rick Macklem <rick.macklem@gmail.com> To: "Matthew L. Dailey" <Matthew.L.Dailey@dartmouth.edu> Cc: "freebsd-current@freebsd.org" <freebsd-current@freebsd.org> Subject: Re: FreeBSD panics possibly caused by nfs clients Message-ID: <CAM5tNy63BkTWy=3C8hCDqcXKh_O9yjGjYcF7jCGurm==01Zd_Q@mail.gmail.com> In-Reply-To: <d98398d2-bda3-4160-9805-fe137e7ef125@dartmouth.edu> References: <c5d44484-8660-4b8b-a379-79423cb208f6@dartmouth.edu> <d98398d2-bda3-4160-9805-fe137e7ef125@dartmouth.edu>
next in thread | previous in thread | raw e-mail | index | archive | help
On Wed, Mar 6, 2024 at 10:56=E2=80=AFAM Matthew L. Dailey <Matthew.L.Dailey@dartmouth.edu> wrote: > > Posting a few updates on this issue. > > I was able to induce a panic on a CURRENT kernel (20240215), built with > GENERIC-KASAN and running kern.kstack_pages=3D6 (default) after ~189 > hours. The panic message and backtrace are below - please reach out > directly if you'd like to have a look at the core. I'm specifically not > increasing kstack_pages to see what effect this has on the panics. > > I have another system running CURRENT (20240215) without any debugging. > I'm able to regularly panic this (7 panics over two weeks with average > uptime of ~42 hours) with kstack_pages=3D4. I set kstack_pages=3D6, and h= ave > also induced several panics. Oddly, this seems to happen more quickly (4 > panics over 2 days with average uptime of ~10.5 hours). > > Another system running CURRENT (20240208), built with GENERIC-KASAN and > running kern.kstack_pages=3D8 has now been running with our hdf5 workload > non-stop since February 10th with no panics or issues. > > From all this, it seems like increasing kstack_pages to 8 eliminates > the panics, but obviously doesn't fix the underlying cause of the > issues. So, although this is an obvious workaround for our production > system, it would be better to find and fix the underlying cause of the > panics. > > I'm going to continue testing to try to generate more cores with > kstack_pages<8 on the system with the debug kernel. > > Any other ideas to try to narrow down the cause are welcome. You might try increasing KSTACK_GUARD_PAGES. I've never done this, but I think it must be done by editting/rebuilding fr= om patched sources. It is in /usr/src/sys/amd64/include/param.h. Typically, when KSTACK_GUARD_PAGES is 1, when the stack grows down into the guard page, a double fault occurs. For your case, it looks like something might be modifying a location that is a ways below (but within the 8 pages) of where the stack is. Increasing KSTACK_GUARD_PAGES to something like 4 and then using the default kstack_pages, it might get the double faults when the wild poin= ter first occurs? Another approach would be to get rid of everything else configured in these test systems, to see if they are involved in the crashes. (I vaguely rememb= er you mentioning packet filtering as one example.) > > Thanks, > Matt > > [680940] Kernel page fault with the following non-sleepable locks held: > [680940] exclusive sleep mutex nfs_state_mutex (nfs_state_mutex) r =3D 0 > (0xffffffff830498e0) locked @ /usr/src/sys/fs/nfsserver/nfs_nfsdstate.c:6= 652 > [680940] stack backtrace: > [680940] #0 0xffffffff8127958f at witness_debugger+0x13f > [680940] #1 0xffffffff8127b114 at witness_warn+0x674 > [680940] #2 0xffffffff81aba0a6 at trap_pfault+0x116 > [680940] #3 0xffffffff81ab901c at trap+0x54c > [680940] #4 0xffffffff81a75988 at calltrap+0x8 > [680940] #5 0xffffffff80fb4bfa at nfsrv_freestateid+0x23a > [680940] #6 0xffffffff80fd5e3f at nfsrvd_freestateid+0x1df > [680940] #7 0xffffffff80f98d35 at nfsrvd_dorpc+0x2585 > [680940] #8 0xffffffff80fbf588 at nfssvc_program+0x1078 > [680940] #9 0xffffffff8173fce6 at svc_run_internal+0x1706 > [680940] #10 0xffffffff8174094b at svc_thread_start+0xb > [680940] #11 0xffffffff811137a3 at fork_exit+0xa3 > [680940] #12 0xffffffff81a769ee at fork_trampoline+0xe > [680940] > [680940] > [680940] Fatal trap 12: page fault while in kernel mode > [680940] cpuid =3D 3; apic id =3D 06 > [680940] fault virtual address =3D 0x7 > [680940] fault code =3D supervisor read data, page not presen= t > [680940] instruction pointer =3D 0x20:0xffffffff80fafd67 > [680940] stack pointer =3D 0x28:0xfffffe0153ba2de0 > [680940] frame pointer =3D 0x28:0xfffffe0153ba2eb0 > [680940] code segment =3D base 0x0, limit 0xfffff, type 0x1b > [680940] =3D DPL 0, pres 1, long 1, def32 0, gran = 1 > [680940] processor eflags =3D interrupt enabled, resume, IOPL =3D 0 > [680940] current process =3D 55202 (nfsd: service) > [680940] rdi: 0000000000000007 rsi: 0000000000000000 rdx: dffff7c00000000= 0 > [680940] rcx: fffffe001b9ec1e8 r8: 0012c43500000002 r9: 0012c4350000000= 2 > [680940] rax: fffffe001b9ec1e8 rbx: ffffffffffffffff rbp: fffffe0153ba2eb= 0 > [680940] r10: 0000000000000004 r11: 0000000000000006 r12: 000000000000000= 7 > [680940] r13: fffffe019cd75700 r14: 0000000000001a1a r15: fffffe019cd7570= 8 > [680940] trap number =3D 12 > [680940] panic: page fault > [680940] cpuid =3D 3 > [680940] time =3D 1709646178 > [680940] KDB: stack backtrace: > [680940] db_trace_self_wrapper() at db_trace_self_wrapper+0xa5/frame > 0xfffffe0153ba2550 > [680940] kdb_backtrace() at kdb_backtrace+0xc6/frame 0xfffffe0153ba26b0 > [680940] vpanic() at vpanic+0x210/frame 0xfffffe0153ba2850 > [680940] panic() at panic+0xb5/frame 0xfffffe0153ba2910 > [680940] trap_fatal() at trap_fatal+0x65b/frame 0xfffffe0153ba2a10 > [680940] trap_pfault() at trap_pfault+0x12b/frame 0xfffffe0153ba2b30 > [680940] trap() at trap+0x54c/frame 0xfffffe0153ba2d10 > [680940] calltrap() at calltrap+0x8/frame 0xfffffe0153ba2d10 > [680940] --- trap 0xc, rip =3D 0xffffffff80fafd67, rsp =3D > 0xfffffe0153ba2de0, rbp =3D 0xfffffe0153ba2eb0 --- > [680940] nfsrv_freelockowner() at nfsrv_freelockowner+0x97/frame This seems to indicate that a list pointer (the one called ls_list in the nfsstateid structure is bogus). However the other list in the same structur= e (called ls_hash) seems ok, since it would not have gotten here otherwise. Both these lists are set to-gether with the structure is added, so it doesn= 't make sense that one would be bogus, unless some wild pointer overwrote that location, I think? rick > 0xfffffe0153ba2eb0 > [680940] nfsrv_freestateid() at nfsrv_freestateid+0x23a/frame > 0xfffffe0153ba2f70 > [680940] nfsrvd_freestateid() at nfsrvd_freestateid+0x1df/frame > 0xfffffe0153ba3030 > [680940] nfsrvd_dorpc() at nfsrvd_dorpc+0x2585/frame 0xfffffe0153ba3570 > [680940] nfssvc_program() at nfssvc_program+0x1078/frame 0xfffffe0153ba39= 70 > [680940] svc_run_internal() at svc_run_internal+0x1706/frame > 0xfffffe0153ba3ee0 > [680940] svc_thread_start() at svc_thread_start+0xb/frame 0xfffffe0153ba3= ef0 > [680940] fork_exit() at fork_exit+0xa3/frame 0xfffffe0153ba3f30 > [680940] fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe0153ba3f3= 0 > [680940] --- trap 0xc, rip =3D 0x3b4ff896f0da, rsp =3D 0x3b4ff6a500e8, rb= p =3D > 0x3b4ff6a50380 --- > [680940] KDB: enter: panic > > #0 __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:57 > #1 doadump (textdump=3Dtextdump@entry=3D0) > at /usr/src/sys/kern/kern_shutdown.c:403 > #2 0xffffffff805a52f6 in db_dump (dummy=3D<optimized out>, > dummy2=3D<optimized out>, dummy3=3D<optimized out>, dummy4=3D<optimi= zed out>) > at /usr/src/sys/ddb/db_command.c:590 > #3 0xffffffff805a512b in db_command (last_cmdp=3D<optimized out>, > cmd_table=3D<optimized out>, dopager=3Dtrue) > at /usr/src/sys/ddb/db_command.c:503 > #4 0xffffffff805a4b3d in db_command_loop () > at /usr/src/sys/ddb/db_command.c:550 > #5 0xffffffff805aa209 in db_trap (type=3D<optimized out>, code=3D<optimi= zed > out>) > at /usr/src/sys/ddb/db_main.c:267 > #6 0xffffffff81239f25 in kdb_trap (type=3D3, code=3Dcode@entry=3D0, > tf=3Dtf@entry=3D0xfffffe0153ba25f0) at /usr/src/sys/kern/subr_kdb.c:= 790 > #7 0xffffffff81ab8f88 in trap (frame=3D0xfffffe0153ba25f0) > at /usr/src/sys/amd64/amd64/trap.c:606 > #8 <signal handler called> > #9 kdb_enter (why=3D<optimized out>, msg=3D<optimized out>) > at /usr/src/sys/kern/subr_kdb.c:556 > #10 0xffffffff8118fdf1 in vpanic (fmt=3Dfmt@entry=3D0xffffffff82491d20 <s= tr> > "%s", > ap=3Dap@entry=3D0xfffffe0153ba28c0) at > /usr/src/sys/kern/kern_shutdown.c:961 > #11 0xffffffff8118fba5 in panic (fmt=3D0xffffffff82491d20 <str> "%s") > at /usr/src/sys/kern/kern_shutdown.c:889 > #12 0xffffffff81ab9f8b in trap_fatal (frame=3D0xfffffe0153ba2d20, eva=3D7= ) > at /usr/src/sys/amd64/amd64/trap.c:950 > #13 0xffffffff81aba0bb in trap_pfault (frame=3Dframe@entry=3D0xfffffe0153= ba2d20, > usermode=3Dfalse, signo=3Dsigno@entry=3D0x0, ucode=3Ducode@entry=3D0= x0) > at /usr/src/sys/amd64/amd64/trap.c:761 > #14 0xffffffff81ab901c in trap (frame=3D0xfffffe0153ba2d20) > at /usr/src/sys/amd64/amd64/trap.c:440 > #15 <signal handler called> > #16 0xffffffff80fafd67 in nfsrv_freelockowner ( > stp=3Dstp@entry=3D0xfffffe019cd75700, vp=3Dvp@entry=3D0x0, > cansleep=3Dcansleep@entry=3D0, p=3Dp@entry=3D0xfffffe0153e2c740) > at /usr/src/sys/fs/nfsserver/nfs_nfsdstate.c:1550 > #17 0xffffffff80fb4bfa in nfsrv_freestateid (nd=3Dnd@entry=3D0xfffffe0153= ba3710, > stateidp=3Dstateidp@entry=3D0xfffffe0153ba2fc0, > p=3Dp@entry=3D0xfffffe0153e2c740) > at /usr/src/sys/fs/nfsserver/nfs_nfsdstate.c:6681 > #18 0xffffffff80fd5e3f in nfsrvd_freestateid (nd=3D0xfffffe0153ba3710, > isdgram=3D<optimized out>, vp=3D<optimized out>, exp=3D<optimized ou= t>) > at /usr/src/sys/fs/nfsserver/nfs_nfsdserv.c:4764 > #19 0xffffffff80f98d35 in nfsrvd_compound (nd=3D0xfffffe0153ba3710, isdgr= am=3D0, > tag=3D<optimized out>, taglen=3D0, minorvers=3D<optimized out>) > at /usr/src/sys/fs/nfsserver/nfs_nfsdsocket.c:1338 > #20 nfsrvd_dorpc (nd=3Dnd@entry=3D0xfffffe0153ba3710, isdgram=3Disdgram@e= ntry=3D0, > tag=3Dtag@entry=3D0xfffffe0153ba3670 "", taglen=3Dtaglen@entry=3D0, > minorvers=3D<optimized out>) > at /usr/src/sys/fs/nfsserver/nfs_nfsdsocket.c:633 > #21 0xffffffff80fbf588 in nfs_proc (xid=3D<optimized out>, > xprt=3D0xfffffe0199f0c600, nd=3D<optimized out>, rpp=3D<optimized ou= t>) > at /usr/src/sys/fs/nfsserver/nfs_nfsdkrpc.c:464 > #22 nfssvc_program (rqst=3D0xfffffe00f3c07000, xprt=3D0xfffffe0199f0c600) > at /usr/src/sys/fs/nfsserver/nfs_nfsdkrpc.c:348 > #23 0xffffffff8173fce6 in svc_executereq (rqstp=3D0xfffffe00f3c07000) > at /usr/src/sys/rpc/svc.c:1032 > #24 svc_run_internal (grp=3Dgrp@entry=3D0xfffffe00f04ec100, > ismaster=3Dismaster@entry=3D0) at /usr/src/sys/rpc/svc.c:1308 > #25 0xffffffff8174094b in svc_thread_start (arg=3D0x7, > arg@entry=3D0xfffffe00f04ec100) at /usr/src/sys/rpc/svc.c:1336 > #26 0xffffffff811137a3 in fork_exit ( > callout=3D0xffffffff81740940 <svc_thread_start>, arg=3D0xfffffe00f04= ec100, > frame=3D0xfffffe0153ba3f40) at /usr/src/sys/kern/kern_fork.c:1157 > #27 <signal handler called> > #28 0x00003b4ff896f0da in ?? ()
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAM5tNy63BkTWy=3C8hCDqcXKh_O9yjGjYcF7jCGurm==01Zd_Q>