Re: bt full - included... kgdb 'script' output vmcore.8

From: John Baldwin <jhb_at_freebsd.org>
Date: Tue, 04 Apr 2017 08:49:43 -0700
On Saturday, March 25, 2017 01:24:06 PM Jeffrey Bouquet wrote:
> I asked the var to bt full
> it laid the symbols down
> I asked it current, list, the cymbals.
> not newly newbie, clown
> 
> And xclip pasted, below, the rhyme
> the symbollish list stuff
> And I send it off to list-wise men
> to make Xorg not so gruff.
> 
> ...........................................
> ...........................................
> 
> 
> Script started on Sat Mar 25 13:11:34 2017
> Command: kgdb7121 /boot/test/kernel /var/crash/VMCORE.8
> GNU gdb (GDB) 7.12.1 [GDB v7.12.1 for FreeBSD]
> Copyright (C) 2017 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
> and "show warranty" for details.
> This GDB was configured as "i386-portbld-freebsd12.0".
> Type "show configuration" for configuration details.
> For bug reporting instructions, please see:
> <http://www.gnu.org/software/gdb/bugs/>.
> Find the GDB manual and other documentation resources online at:
> <http://www.gnu.org/software/gdb/documentation/>.
> For help, type "help".
> Type "apropos word" to search for commands related to "word"...
> Reading symbols from /boot/test/kernel...Reading symbols from /usr/lib/debug//boot/test/kernel.debug...done.
> done.
> 
> Unread portion of the kernel message buffer:
> Waiting (max 60 seconds) for system process `vnlru' to stop... done
> Waiting (max 60 seconds) for system process `bufdaemon' to stop... done
> Waiting (max 60 seconds) for system process `syncer' to stop... 
> Syncing disks, vnodes remaining... 5 1 0 0 done
> All buffers synced.
> lock order reversal:
>  1st 0xbf8ce26c ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1277
>  2nd 0xbfb90150 syncer (syncer) _at_ /usr/src/sys/kern/vfs_subr.c:2762
> stack backtrace:
> #0 0xb5c22421 at witness_debugger+0x81
> #1 0xb5c22342 at witness_checkorder+0xd12
> #2 0xb5b9b5d4 at __lockmgr_args+0xa64
> #3 0xb5c784ad at vop_stdlock+0x4d
> #4 0xb618e7f7 at VOP_LOCK1_APV+0xd7
> #5 0xb5c9c137 at _vn_lock+0xb7
> #6 0xb5c8b00a at vputx+0x16a
> #7 0xb5c8286c at dounmount+0x5dc
> #8 0xb5c8c8e8 at vfs_unmountall+0x68
> #9 0xb5c68333 at bufshutdown+0x3f3
> #10 0xb5bbfca7 at kern_reboot+0x1b7
> #11 0xb5bbfa88 at sys_reboot+0x3e8
> #12 0xb6155fa5 at syscall+0x3b5
> #13 0xb6140ede at Xint0x80_syscall+0x2e
> lock order reversal:
>  1st 0xbf8ce26c ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1277
>  2nd 0xbfa28034 devfs (devfs) _at_ /usr/src/sys/ufs/ffs/ffs_vfsops.c:1404
> stack backtrace:
> #0 0xb5c22421 at witness_debugger+0x81
> #1 0xb5c22342 at witness_checkorder+0xd12
> #2 0xb5b9b5d4 at __lockmgr_args+0xa64
> #3 0xb5c784ad at vop_stdlock+0x4d
> #4 0xb618e7f7 at VOP_LOCK1_APV+0xd7
> #5 0xb5c9c137 at _vn_lock+0xb7
> #6 0xb5eb9617 at ffs_flushfiles+0x157
> #7 0xb5e9d9aa at softdep_flushfiles+0x17a
> #8 0xb5ebc04c at ffs_unmount+0x7c
> #9 0xb5c8299b at dounmount+0x70b
> #10 0xb5c8c8e8 at vfs_unmountall+0x68
> #11 0xb5c68333 at bufshutdown+0x3f3
> #12 0xb5bbfca7 at kern_reboot+0x1b7
> #13 0xb5bbfa88 at sys_reboot+0x3e8
> #14 0xb6155fa5 at syscall+0x3b5
> #15 0xb6140ede at Xint0x80_syscall+0x2e
> lock order reversal:
>  1st 0xbf69ab4c ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1277
>  2nd 0xb6b6f8b0 allproc (allproc) _at_ /usr/src/sys/kern/kern_descrip.c:3104
> stack backtrace:
> #0 0xb5c22421 at witness_debugger+0x81
> #1 0xb5c22342 at witness_checkorder+0xd12
> #2 0xb5bc976a at _sx_slock+0x5a
> #3 0xb5b743f1 at mountcheckdirs+0x41
> #4 0xb5c828ea at dounmount+0x65a
> #5 0xb5c8c93b at vfs_unmountall+0xbb
> #6 0xb5c68333 at bufshutdown+0x3f3
> #7 0xb5bbfca7 at kern_reboot+0x1b7
> #8 0xb5bbfa88 at sys_reboot+0x3e8
> #9 0xb6155fa5 at syscall+0x3b5
> #10 0xb6140ede at Xint0x80_syscall+0x2e
> Uptime: 3h49m18s
> GEOM_SCHED: Modevent 2.
> uhub11: detached
> uhub9: detached
> uhub10: detached
> ums0: detached
> <5>ue0: link state changed to DOWN
> <5>Accounting disabled
> panic: vm_fault: fault on nofault entry, addr: deadc000
> cpuid = 2
> KDB: stack backtrace:
> db_trace_self_wrapper(b632dee0,b65ec9b0,0,b63057cc,20c,...) at db_trace_self_wrapper+0x2a/frame 0xeaa10428
> kdb_backtrace(b653d063,2,b6378ae5,eaa104e4,fb,...) at kdb_backtrace+0x2d/frame 0xeaa10490
> vpanic(b6378ae5,eaa104e4,eaa104e4,eaa105c0,b5edffb1,...) at vpanic+0x115/frame 0xeaa104c4
> panic(b6378ae5,deadc000,1,eaa1052c,eaa1051c,...) at panic+0x1b/frame 0xeaa104d8
> vm_fault_hold(b8172000,deadc000,1,0,0,...) at vm_fault_hold+0x2051/frame 0xeaa105c0
> vm_fault(b8172000,deadc000,1,0,c2d0bfa8,...) at vm_fault+0x88/frame 0xeaa105e8
> trap_pfault(deadc348,b6ae70ec,b6600504,bdda8d00,b6ae70f0,...) at trap_pfault+0x116/frame 0xeaa10630
> trap(eaa10778) at trap+0x2d6/frame 0xeaa1076c
> calltrap() at calltrap+0x6/frame 0xeaa1076c
> --- trap 0xc, eip = 0xb5bbaf19, esp = 0xeaa107b8, ebp = 0xeaa10828 ---
> __rw_wlock_hard(c2d42ab4,deadc0de,be269000,b63585e2,139,...) at __rw_wlock_hard+0xe9/frame 0xeaa10828
> _rw_wlock_cookie(c2d42ab4,b63585e2,139,136,0,...) at _rw_wlock_cookie+0xd8/frame 0xeaa10858
> ip_output(c3acf400,0,0,0,0,...) at ip_output+0x4aa/frame 0xeaa10934
> check_dyn_rules(1,1,b632a786,eaa109c8,b5bce8a2,...) at check_dyn_rules+0x6a8/frame 0xeaa10994
> ipfw_dyn_tick(0,0,b632a786,2b1,eaa10a00,...) at ipfw_dyn_tick+0x55/frame 0xeaa109c8
> softclock_call_cc(0,0,b632a786,360,0,...) at softclock_call_cc+0x17c/frame 0xeaa10a68
> softclock(b6b6fa80,9,0,560,be2d4048,...) at softclock+0x40/frame 0xeaa10a88
> intr_event_execute_handlers(b6aa7e10,be2d4000,b6320f1d,560,b6320b58,...) at intr_event_execute_handlers+0x8e/frame 0xeaa10ab0
> ithread_loop(be2d7000,eaa10b28,b6320b58,406,0,...) at ithread_loop+0x90/frame 0xeaa10aec
> fork_exit(b5b8a3c0,be2d7000,eaa10b28) at fork_exit+0x7e/frame 0xeaa10b14
> fork_trampoline() at fork_trampoline+0x8/frame 0xeaa10b14
> --- trap 0, eip = 0, esp = 0xeaa10b60, ebp = 0 ---
> KDB: enter: panic
> 
> Reading symbols from /boot/test/geom_journal.ko...Reading symbols from /usr/lib/debug//boot/test/geom_journal.ko.debug...done.
> done.
> Reading symbols from /boot/test/geom_label.ko...Reading symbols from /usr/lib/debug//boot/test/geom_label.ko.debug...done.
> done.
> Reading symbols from /boot/modules/nvidia-modeset.ko...(no debugging symbols found)...done.
> Reading symbols from /boot/modules/nvidia.ko...(no debugging symbols found)...done.
> Reading symbols from /boot/test/ehci.ko...Reading symbols from /usr/lib/debug//boot/test/ehci.ko.debug...done.
> done.
> Reading symbols from /boot/test/geom_sched.ko...Reading symbols from /usr/lib/debug//boot/test/geom_sched.ko.debug...done.
> done.
> Reading symbols from /boot/test/gsched_rr.ko...Reading symbols from /usr/lib/debug//boot/test/gsched_rr.ko.debug...done.
> done.
> Reading symbols from /boot/test/pf.ko...Reading symbols from /usr/lib/debug//boot/test/pf.ko.debug...done.
> done.
> Reading symbols from /boot/test/snd_csa.ko...Reading symbols from /usr/lib/debug//boot/test/snd_csa.ko.debug...done.
> done.
> __curthread () at ./machine/pcpu.h:225
> 225		__asm("movl %%fs:%1,%0" : "=r" (td)
> (kgdb) bt full
> #0  __curthread () at ./machine/pcpu.h:225
>         td = <optimized out>
> #1  doadump (textdump=0) at /usr/src/sys/kern/kern_shutdown.c:318
>         error = <error reading variable error (Cannot access memory at address 0x0)>
>         coredump = <optimized out>
> #2  0xb555a40e in db_dump (dummy=-1245695404, 
>     dummy2=<error reading variable: access outside bounds of object referenced via synthetic pointer>, 
>     dummy3=-1, dummy4=0xeaa101d4 "") at /usr/src/sys/ddb/db_command.c:546
>         error = <optimized out>
> #3  0xb555a1fa in db_command (last_cmdp=<optimized out>, cmd_table=<optimized out>, dopager=<optimized out>)
>     at /usr/src/sys/ddb/db_command.c:453
>         modif = "\000\263\261\266\000\000\000\000\004\312^\266\000\060A\276\f\002\241\352]\240\212\211\270Fe\266\377\377\377\377\377\377\377\377,\002\241\352\061\317U\265\177o8\266_at_\317U\265\030\002\241\352\020\000\000\000\070\002\241\352\070\002\241\352,\002\241\352_at_\201\266\265\000\000\000\000\377\377\377\377\270Fe\266L\002\241\352\321\300U\265\270Fe\266\034_at_e\266x\000\000\000\000\000\000\000\210\002\241\352D\004\241\352"
>         have_addr = <error reading variable have_addr (Cannot access memory at address 0x0)>
>         t = <optimized out>
>         result = <optimized out>
>         cmd = 0xb6565df0 <db_cmds+240>
>         addr = <unavailable>
>         count = <optimized out>
> #4  0xb5559f50 in db_command_loop () at /usr/src/sys/ddb/db_command.c:506
> No locals.
> #5  0xb555cdfa in db_trap (type=<optimized out>, code=<optimized out>) at /usr/src/sys/ddb/db_main.c:248
>         jb = {{_jb = {-358546364, -358546836, -358546752, 0, -358546808, -1252668039, -1235852540, -358546768, 
>               -1245614478, -1235301696, -358546752, -1246330736}}}
>         watchpt = <optimized out>
>         bkpt = <optimized out>
>         prev_jb = 0x0
>         why = <optimized out>
> #6  0xb5c03997 in kdb_trap (type=<optimized out>, code=<optimized out>, tf=<optimized out>)
>     at /usr/src/sys/kern/subr_kdb.c:654
>         be = <optimized out>
>         intr = <optimized out>
>         handled = <optimized out>
> #7  0xb615530f in trap (frame=<optimized out>) at /usr/src/sys/i386/i386/trap.c:683
>         td = 0xbe269000
>         addr = <optimized out>
>         ucode = <optimized out>
>         i = <optimized out>
>         p = 0xbe267354
>         type = <optimized out>
>         eva = <optimized out>
> ---Type <return> to continue, or q <return> to quit---
>         regs = <optimized out>
>         dr6 = <unavailable>
> #8  <signal handler called>
> No locals.
> #9  0xb5c03254 in kdb_enter (why=0xb6328738 "panic", msg=<optimized out>) at /usr/src/sys/kern/subr_kdb.c:444
> No locals.
> #10 0xb5bc03f2 in vpanic (fmt=<optimized out>, ap=<optimized out>) at /usr/src/sys/kern/kern_shutdown.c:772
>         buf = "vm_fault: fault on nofault entry, addr: deadc000", '\000' <repeats 207 times>
>         td = 0xbe269000
>         newpanic = <error reading variable newpanic (Cannot access memory at address 0x1)>
>         bootopt = <error reading variable bootopt (Cannot access memory at address 0x100)>
> #11 0xb5bc042b in panic (fmt=0xb6378ae5 "vm_fault: fault on nofault entry, addr: %lx")
>     at /usr/src/sys/kern/kern_shutdown.c:710
>         ap = 0x80 <error: Cannot access memory at address 0x80>
> #12 0xb5edffb1 in vm_fault_hold (map=<optimized out>, vaddr=<optimized out>, fault_type=<optimized out>, 
>     fault_flags=<optimized out>, m_hold=<optimized out>) at /usr/src/sys/vm/vm_fault.c:531
>         hardfault = <error reading variable hardfault (Cannot access memory at address 0x1)>
>         nera = <error reading variable nera (Cannot access memory at address 0x1f)>
>         faultcount = <optimized out>
>         wired = <optimized out>
>         prot = <optimized out>
>         result = 0
>         next_object = <optimized out>
>         alloc_req = <optimized out>
>         era = <optimized out>
>         behavior = <optimized out>
>         fs = <optimized out>
>         e_start = <optimized out>
>         e_end = <optimized out>
>         vp = <optimized out>
>         locked = <optimized out>
>         error = <optimized out>
>         ahead = <optimized out>
>         behind = <optimized out>
>         rv = <optimized out>
>         cluster_offset = <optimized out>
>         is_first_object_locked = <optimized out>
>         retry_prot = <optimized out>
>         retry_object = <optimized out>
> #13 0xb5eddf28 in vm_fault (map=0xb8172000, vaddr=<optimized out>, fault_type=<optimized out>, 
>     fault_flags=<optimized out>) at /usr/src/sys/vm/vm_fault.c:474
>         td = 0xbe269000
>         result = <optimized out>
> ---Type <return> to continue, or q <return> to quit---
> #14 0xb61558c6 in trap_pfault (frame=0xeaa10778, usermode=<optimized out>, eva=<optimized out>)
>     at /usr/src/sys/i386/i386/trap.c:868
>         rv = <error reading variable rv (Cannot access memory at address 0x0)>
>         td = 0xbe269000
>         p = <optimized out>
>         va = 128
>         map = <optimized out>
> #15 0xb6154d06 in trap (frame=<optimized out>) at /usr/src/sys/i386/i386/trap.c:512
>         td = 0xbe269000
>         addr = <optimized out>
>         ucode = <error reading variable ucode (Cannot access memory at address 0x0)>
>         i = <error reading variable i (Cannot access memory at address 0x0)>
>         p = 0xbe267354
>         type = 12
>         eva = <optimized out>
>         regs = <optimized out>
>         dr6 = <optimized out>
> #16 <signal handler called>
> No locals.
> #17 __rw_wlock_hard (c=<optimized out>, v=<optimized out>, tid=<optimized out>, file=0x0, line=0)
>     at /usr/src/sys/kern/kern_rwlock.c:892
>         spintries = <error reading variable spintries (Cannot access memory at address 0x0)>
>         sleep_cnt = <error reading variable sleep_cnt (Cannot access memory at address 0x0)>
>         ts = <optimized out>
>         owner = 0xdeadc0c0
>         i = <optimized out>
>         x = <optimized out>
> #18 0xb5bbada8 in _rw_wlock_cookie (c=<optimized out>, file=<optimized out>, line=<optimized out>)
>     at /usr/src/sys/kern/kern_rwlock.c:285
>         tid = 3190198272
>         v = 0
> #19 0xb5d5303a in ip_output (m=<optimized out>, opt=<optimized out>, ro=<optimized out>, flags=<optimized out>, 
>     imo=<optimized out>, inp=<optimized out>) at /usr/src/sys/netinet/ip_output.c:313
>         error = <error reading variable error (Cannot access memory at address 0x0)>
>         hlen = <optimized out>
>         ip = <optimized out>
>         ip_len = <optimized out>
>         fibnum = <optimized out>
>         rte = <optimized out>
>         have_ia_ref = <optimized out>
>         ifp = <optimized out>
>         ia = <optimized out>
>         isbroadcast = <optimized out>
> ---Type <return> to continue, or q <return> to quit---
>         gw = <optimized out>

The panic is in the LLE_FREE() here:

	/*
	 * If there is a cached route,
	 * check that it is to the same destination
	 * and is still up.  If not, free it and try again.
	 * The address family should also be checked in case of sharing the
	 * cache with IPv6.
	 * Also check whether routing cache needs invalidation.
	 */
	rte = ro->ro_rt;
	if (rte && ((rte->rt_flags & RTF_UP) == 0 ||
		    rte->rt_ifp == NULL ||
		    !RT_LINK_IS_UP(rte->rt_ifp) ||
			  dst->sin_family != AF_INET ||
			  dst->sin_addr.s_addr != ip->ip_dst.s_addr)) {
		RTFREE(rte);
		rte = ro->ro_rt = (struct rtentry *)NULL;
		if (ro->ro_lle)
			LLE_FREE(ro->ro_lle);	/* zeros ro_lle */
		ro->ro_lle = (struct llentry *)NULL;
	}

(In particular the LLE_WLOCK() in LLE_FREE() is what panics).  From the
panic it seems as if the memory containing the lock has been free'd and
replaced with 0xdeadc0de.  You should probably try updating to at least
r315956, but if you still get panics after that, Mike Karels (cc'd) has
worked in this area and might have an idea.

-- 
John Baldwin
Received on Tue Apr 04 2017 - 15:19:02 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:41:11 UTC