From owner-freebsd-current@freebsd.org Mon Aug 10 07:39:53 2015 Return-Path: Delivered-To: freebsd-current@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id C29CC99E77A for ; Mon, 10 Aug 2015 07:39:53 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from kib.kiev.ua (kib.kiev.ua [IPv6:2001:470:d5e7:1::1]) (using TLSv1 with cipher DHE-RSA-CAMELLIA256-SHA (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 67E72845 for ; Mon, 10 Aug 2015 07:39:53 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from tom.home (kostik@localhost [127.0.0.1]) by kib.kiev.ua (8.15.2/8.15.2) with ESMTPS id t7A7dlwS003162 (version=TLSv1 cipher=DHE-RSA-CAMELLIA256-SHA bits=256 verify=NO); Mon, 10 Aug 2015 10:39:47 +0300 (EEST) (envelope-from kostikbel@gmail.com) DKIM-Filter: OpenDKIM Filter v2.10.3 kib.kiev.ua t7A7dlwS003162 Received: (from kostik@localhost) by tom.home (8.15.2/8.15.2/Submit) id t7A7dlZl003161; Mon, 10 Aug 2015 10:39:47 +0300 (EEST) (envelope-from kostikbel@gmail.com) X-Authentication-Warning: tom.home: kostik set sender to kostikbel@gmail.com using -f Date: Mon, 10 Aug 2015 10:39:47 +0300 From: Konstantin Belousov To: Tim Kientzle Cc: FreeBSD Current Subject: Re: Consistent crash of BeagleBone kernel Message-ID: <20150810073947.GN2072@kib.kiev.ua> References: <20150809064704.GH2072@kib.kiev.ua> <350C3412-910F-4B08-A903-A51D18474DAF@kientzle.com> <20150809181004.GK2072@kib.kiev.ua> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.5.23 (2014-03-12) X-Spam-Status: No, score=-2.0 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_ADSP_CUSTOM_MED,FREEMAIL_FROM,NML_ADSP_CUSTOM_MED autolearn=no autolearn_force=no version=3.4.1 X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28) on tom.home X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 10 Aug 2015 07:39:54 -0000 On Sun, Aug 09, 2015 at 05:24:13PM -0700, Tim Kientzle wrote: > > > On Aug 9, 2015, at 11:10 AM, Konstantin Belousov 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) @ /Users/tim/projects/crochet/src-head/sys/kern/kern_linker.c:1030 > 2nd 0xc2d63c94 ufs (ufs) @ /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 >