Re: Consistent crash of BeagleBone kernel

On Sun, Aug 09, 2015 at 05:24:13PM -0700, Tim Kientzle wrote:
> 
> > On Aug 9, 2015, at 11:10 AM, Konstantin Belousov <kostikbel_at_gmail.com> wrote:
> > 
> > On Sun, Aug 09, 2015 at 10:53:20AM -0700, Tim Kientzle wrote:
> >> 
> >> I suspect the LOR is new.
> >> 
> >> It looks like the panic is occurring when WITNESS tries to print the backtrace for the LOR.  I???m not familiar with that code; does it use the kernel linker?
> >> 
> > 
> > It indeed locks the linker lock to resolve symbols. So it seems to be
> > even more useful to make the linker lock recursive locally, then you
> > should be able to see the backtrace for LOR.
> 
> Changing the kld_sx lock to recursive, I now see a backtrace for the ufs/kernel linker LOR.  Full trace pasted below.
> 
> This is displayed just before the network interfaces; I suspect it???s being triggered when my startup initializes the urtwn wireless adapter (which does indeed load a number of kernel modules).
> 
> lock order reversal:
>  1st 0xc083ef40 kernel linker (kernel linker) _at_ /Users/tim/projects/crochet/src-head/sys/kern/kern_linker.c:1030
>  2nd 0xc2d63c94 ufs (ufs) _at_ /Users/tim/projects/crochet/src-head/sys/kern/vfs_lookup.c:529
The order, for which witness complained, is in fact the right order.
The linker_load_module() function calls LINKER_LOAD_FILE() with the
kld_sx locked, and linker itself locks module vnode.

So there was something in your system which exposed the reversed order
vnode->kld_sx before the action.  To catch it, keep the modification to
mark kld_sx as recursive, but also add an item to the order_lists in
the sys/kern/subr_witness.c like this:
	{"kernel linker", &lock_class_sx},
	{"ufs", &lock_class_lockmgr},
	{NULL, NULL}
and watch were would it fire.

> KDB: stack backtrace:
> db_trace_self() at db_trace_self
> 	 pc = 0xc0627ec0  lr = 0xc023fd34 (db_trace_self_wrapper+0x30)
> 	 sp = 0xde2be720  fp = 0xde2be838
> 	r10 = 0xc069f42b
> db_trace_self_wrapper() at db_trace_self_wrapper+0x30
> 	 pc = 0xc023fd34  lr = 0xc03eb0ec (witness_checkorder+0xf30)
> 	 sp = 0xde2be840  fp = 0xde2be888
> 	 r4 = 0xc2725be8  r5 = 0xc2d63c94
> 	 r6 = 0xc06ba387  r7 = 0xc069f42b
> witness_checkorder() at witness_checkorder+0xf30
> 	 pc = 0xc03eb0ec  lr = 0xc0375bcc (__lockmgr_args+0x24c)
> 	 sp = 0xde2be890  fp = 0xde2be8e8
> 	 r4 = 0xc2d63cb4  r5 = 0x00202400
> 	 r6 = 0x00000211  r7 = 0x00000000
> 	 r8 = 0xc2d63c94  r9 = 0x00000000
> 	r10 = 0xc06ba387
> __lockmgr_args() at __lockmgr_args+0x24c
> 	 pc = 0xc0375bcc  lr = 0xc05db328 (ffs_lock+0x80)
> 	 sp = 0xde2be8f0  fp = 0xde2be920
> 	 r4 = 0xde2be948  r5 = 0x00202400
> 	 r6 = 0xc2d63c60  r7 = 0xc2d63c94
> 	 r8 = 0xc2d63cb4  r9 = 0x00000000
> 	r10 = 0x00000008
> ffs_lock() at ffs_lock+0x80
> 	 pc = 0xc05db328  lr = 0xc06609ec (VOP_LOCK1_APV+0x128)
> 	 sp = 0xde2be928  fp = 0xde2be940
> 	 r4 = 0xde2be948  r5 = 0xc07a9630
> 	 r6 = 0x00000000  r7 = 0x00202400
> 	 r8 = 0xde2be948  r9 = 0x00000211
> 	r10 = 0xde2bed38
> VOP_LOCK1_APV() at VOP_LOCK1_APV+0x128
> 	 pc = 0xc06609ec  lr = 0xc044dcac (_vn_lock+0x48)
> 	 sp = 0xde2be948  fp = 0xde2be978
> 	 r4 = 0xc2d63c60  r5 = 0xde2bece0
> 	 r6 = 0xc06ba387 r10 = 0xde2bed38
> _vn_lock() at _vn_lock+0x48
> 	 pc = 0xc044dcac  lr = 0xc0433900 (lookup+0xf8)
> 	 sp = 0xde2be980  fp = 0xde2be9c8
> 	 r4 = 0xc2d63c60  r5 = 0xde2bece0
> 	 r6 = 0xde2bed50  r7 = 0x00000000
> 	 r8 = 0xde2bed50  r9 = 0xc306e448
> 	r10 = 0xde2bed38
> lookup() at lookup+0xf8
> 	 pc = 0xc0433900  lr = 0xc0433448 (namei+0x3e8)
> 	 sp = 0xde2be9d0  fp = 0xde2bea48
> 	 r4 = 0xde2bece0  r5 = 0x00000000
> 	 r6 = 0xde2bed50  r7 = 0x00000000
> 	 r8 = 0xc2e526a0  r9 = 0xc306e448
> 	r10 = 0xde2bed38
> namei() at namei+0x3e8
> 	 pc = 0xc0433448  lr = 0xc044d4b8 (vn_open_cred+0x1cc)
> 	 sp = 0xde2bea50  fp = 0xde2beb38
> 	 r4 = 0xde2bece0  r5 = 0x00000000
> 	 r6 = 0xc069f42d  r7 = 0x00000001
> 	 r8 = 0x00000000  r9 = 0x00000000
> 	r10 = 0xde2bed50
> vn_open_cred() at vn_open_cred+0x1cc
> 	 pc = 0xc044d4b8  lr = 0xc044d2e4 (vn_open+0x24)
> 	 sp = 0xde2beb40  fp = 0xde2beb48
> 	 r4 = 0xde2bece0  r5 = 0xc2d0d3c0
> 	 r6 = 0xc069f42d  r7 = 0x0000001a
> 	 r8 = 0x00000000  r9 = 0xc2e526a0
> 	r10 = 0xc078d6f8
> vn_open() at vn_open+0x24
> 	 pc = 0xc044d2e4  lr = 0xc0371390 (linker_load_module+0x634)
> 	 sp = 0xde2beb50  fp = 0xde2beda8
> linker_load_module() at linker_load_module+0x634
> 	 pc = 0xc0371390  lr = 0xc0372ff4 (kern_kldload+0xc8)
> 	 sp = 0xde2bedb0  fp = 0xde2bedc8
> 	 r4 = 0xde2bedd4  r5 = 0xc083ef40
> 	 r6 = 0xc2e75000  r7 = 0x00000000
> 	 r8 = 0xde2bee00  r9 = 0xc306b380
> 	r10 = 0xbfbff5fc
> kern_kldload() at kern_kldload+0xc8
> 	 pc = 0xc0372ff4  lr = 0xc03730bc (sys_kldload+0x64)
> 	 sp = 0xde2bedd0  fp = 0xde2bede8
> 	 r4 = 0xc2e526a0  r5 = 0xc2e75000
> 	 r6 = 0x00000000  r7 = 0x00000000
> sys_kldload() at sys_kldload+0x64
> 	 pc = 0xc03730bc  lr = 0xc063e010 (swi_handler+0x2d4)
> 	 sp = 0xde2bedf0  fp = 0xde2bee50
> 	 r4 = 0xc2e526a0  r5 = 0x00000000
> 	 r6 = 0xc08b3d20 r10 = 0xbfbff5fc
> swi_handler() at swi_handler+0x2d4
> 	 pc = 0xc063e010  lr = 0xc06294d8 (swi_exit)
> 	 sp = 0xde2bee58  fp = 0xbfbff648
> 	 r4 = 0x00000000  r5 = 0xbfbff600
> 	 r6 = 0xbfbff600  r7 = 0x00000130
> 	 r8 = 0xbfbff5e9  r9 = 0xbfbff5d9
> 	r10 = 0xbfbff5fc
>