From owner-freebsd-arm@FreeBSD.ORG Sat Sep 22 17:07:53 2012 Return-Path: Delivered-To: arm@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 3DAD4106566B for ; Sat, 22 Sep 2012 17:07:53 +0000 (UTC) (envelope-from freebsd@damnhippie.dyndns.org) Received: from duck.symmetricom.us (duck.symmetricom.us [206.168.13.214]) by mx1.freebsd.org (Postfix) with ESMTP id E052C8FC12 for ; Sat, 22 Sep 2012 17:07:52 +0000 (UTC) Received: from damnhippie.dyndns.org (daffy.symmetricom.us [206.168.13.218]) by duck.symmetricom.us (8.14.5/8.14.5) with ESMTP id q8MH7kE5012243 for ; Sat, 22 Sep 2012 11:07:46 -0600 (MDT) (envelope-from freebsd@damnhippie.dyndns.org) Received: from [172.22.42.240] (revolution.hippie.lan [172.22.42.240]) by damnhippie.dyndns.org (8.14.3/8.14.3) with ESMTP id q8MH7hrR062152; Sat, 22 Sep 2012 11:07:43 -0600 (MDT) (envelope-from freebsd@damnhippie.dyndns.org) From: Ian Lepore To: Alan Cox In-Reply-To: <505DE03D.7050101@rice.edu> References: <1345315508.27688.260.camel@revolution.hippie.lan> <503D12AE.1050705@rice.edu> <1346350374.1140.525.camel@revolution.hippie.lan> <5045351F.6060201@rice.edu> <1346723041.1140.602.camel@revolution.hippie.lan> <504B85BE.3030101@rice.edu> <1347316458.1137.41.camel@revolution.hippie.lan> <504F8BAC.4040902@rice.edu> <20120915045040.GZ58312@funkthat.com> <5054D69B.40209@rice.edu> <20120917033308.GB58312@funkthat.com> <505DE03D.7050101@rice.edu> Content-Type: text/plain; charset="us-ascii" Date: Sat, 22 Sep 2012 11:07:43 -0600 Message-ID: <1348333663.5548.24.camel@revolution.hippie.lan> Mime-Version: 1.0 X-Mailer: Evolution 2.32.1 FreeBSD GNOME Team Port Content-Transfer-Encoding: 7bit Cc: "arm@freebsd.org" Subject: Re: arm pmap locking X-BeenThere: freebsd-arm@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Porting FreeBSD to the StrongARM Processor List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 22 Sep 2012 17:07:53 -0000 On Sat, 2012-09-22 at 10:58 -0500, Alan Cox wrote: > On 09/16/2012 22:33, John-Mark Gurney wrote: > > Alan Cox wrote this message on Sat, Sep 15, 2012 at 14:27 -0500: > >> On 09/14/2012 23:50, John-Mark Gurney wrote: > >>> I figure since you've been looking at arm's pmap, that I should report > >>> to you a LOR that I observered recently on my armv6 board: > >>> lock order reversal: > >>> 1st 0xc1cf70b0 pmap (pmap) @ /usr/src.HEAD/sys/arm/arm/pmap-v6.c:673 > >>> 2nd 0xc091e608 PV ENTRY (UMA zone) @ /usr/src.HEAD/sys/vm/uma_core.c:2084 > >>> KDB: stack backtrace: > >>> db_trace_self() at db_trace_self+0xc > >>> scp=0xc05a294c rlv=0xc025b298 (X_db_sym_numargs+0x1bc) > >>> rsp=0xc9d1a8fc rfp=0xc9d1aa18 > >>> X_db_sym_numargs() at X_db_sym_numargs+0x194 > >>> scp=0xc025b270 rlv=0xc0398340 (kdb_backtrace+0x3c) > >>> rsp=0xc9d1aa1c rfp=0xc9d1aa2c > >>> r4=0xc06bda44 > >>> kdb_backtrace() at kdb_backtrace+0xc > >>> scp=0xc0398310 rlv=0xc03ad3f8 (witness_display_spinlock+0x80) > >>> rsp=0xc9d1aa30 rfp=0xc9d1aa44 > >>> r4=0x00000001 > >>> witness_display_spinlock() at witness_display_spinlock+0x5c > >>> scp=0xc03ad3d4 rlv=0xc03ae6d8 (witness_checkorder+0x884) > >>> rsp=0xc9d1aa48 rfp=0xc9d1aa98 > >>> r5=0xc1cf70b0 r4=0xc06263d4 > >>> witness_checkorder() at witness_checkorder+0xc > >>> scp=0xc03ade60 rlv=0xc0355b9c (_mtx_lock_flags+0xcc) > >>> rsp=0xc9d1aa9c rfp=0xc9d1aabc > >>> r10=0xc1cf70b0 r9=0x00000000 > >>> r8=0xc091d6e0 r7=0xc0620730 r6=0x00000824 r5=0x00000000 > >>> r4=0xc091e608 > >>> _mtx_lock_flags() at _mtx_lock_flags+0xc > >>> scp=0xc0355adc rlv=0xc057d290 (uma_zalloc_arg+0x1a8) > >>> rsp=0xc9d1aac0 rfp=0xc9d1aafc > >>> r7=0xc091d748 r6=0x00000000 > >>> r5=0xc08fc0b8 r4=0xc0620730 > >>> uma_zalloc_arg() at uma_zalloc_arg+0xc > >>> scp=0xc057d0f4 rlv=0xc05abb04 (pmap_growkernel+0xf20) > >>> rsp=0xc9d1ab00 rfp=0xc9d1ab70 > >>> r10=0xc1cf70b0 r9=0x00000000 > >>> r8=0x00000000 r7=0x8122e032 r6=0x00000000 r5=0xc08fc0b8 > >>> r4=0x00000001 > >>> pmap_growkernel() at pmap_growkernel+0x3fc > >>> scp=0xc05aafe0 rlv=0xc05ac14c (pmap_enter+0x70) > >>> rsp=0xc9d1ab74 rfp=0xc9d1aba0 > >>> r10=0x00000007 r9=0x00000000 > >>> r8=0xc09885a8 r7=0xbffff000 r6=0xc08278c0 r5=0xc1cf70b0 > >>> r4=0xc06261e0 > >>> pmap_enter() at pmap_enter+0xc > >>> scp=0xc05ac0e8 rlv=0xc057ff44 (vm_fault_hold+0x1638) > >>> rsp=0xc9d1aba4 rfp=0xc9d1ad14 > >>> r10=0xc9d1ade4 r8=0x00000000 > >>> r7=0x00000002 r6=0x00000000 r5=0xc1cf7000 r4=0xc09885a8 > >>> vm_fault_hold() at vm_fault_hold+0xc > >>> scp=0xc057e918 rlv=0xc058054c (vm_fault+0x8c) > >>> rsp=0xc9d1ad18 rfp=0xc9d1ad3c > >>> r10=0xc9d1ade4 r9=0x00000002 > >>> r8=0x00000000 r7=0x00000002 r6=0xbffff000 r5=0xc1cf7000 > >>> r4=0xc1cf5000 > >>> vm_fault() at vm_fault+0xc > >>> scp=0xc05804cc rlv=0xc05b0ac8 (data_abort_handler+0x35c) > >>> rsp=0xc9d1ad40 rfp=0xc9d1ade0 > >>> r8=0xbffff000 r7=0xc1cf5000 > >>> r6=0x00000000 r5=0xc0626844 r4=0xc1cf3088 > >>> data_abort_handler() at data_abort_handler+0xc > >>> scp=0xc05b0778 rlv=0xc05a4150 (address_exception_entry+0x50) > >>> rsp=0xc9d1ade4 rfp=0xc9d1ae84 > >>> r10=0xc0682bde r9=0xc1cf3000 > >>> r8=0xc9d1aeac r7=0xc0682bde r6=0xc0682bd4 r5=0xc05f1648 > >>> r4=0xbfffffff > >>> exec_shell_imgact() at exec_shell_imgact+0x75c > >>> scp=0xc031d348 rlv=0xc033b68c (fork_exit+0x94) > >>> rsp=0xc9d1ae88 rfp=0xc9d1aea8 > >>> r10=0x00000000 r9=0x00000000 > >>> r8=0xc9d1aeac r7=0x00000000 r6=0xc031d33c r5=0xc1cf3000 > >>> r4=0xc1cf5000 > >>> fork_exit() at fork_exit+0xc > >>> scp=0xc033b604 rlv=0xc05afe44 (fork_trampoline+0x14) > >>> rsp=0xc9d1aeac rfp=0x00000000 > >>> r8=0x00000000 r7=0x8ffbf8ef > >>> r6=0xf5f7f4a9 r5=0x00000000 r4=0xc031d33c > >>> > >>> FreeBSD beaglebone 10.0-CURRENT FreeBSD 10.0-CURRENT #1 r240480: Thu Nov > >>> 3 14:57:01 PDT 2011 > >>> jmg@pcbsd-779:/usr/obj/arm.armv6/usr/src.HEAD/sys/helium arm > >>> > >>> Do you need any more information? > >> I'm not sure what to make of this stack trace. In particular, > >> pmap_enter() does not directly call pmap_growkernel(). In fact, the > >> only caller to pmap_growkernel() in the entire kernel is > >> vm_map_insert(), which doesn't appear in this stack trace. Moreover, > >> this appears to be a legitimate page fault within the kernel address > >> space. (The image activator touches pageable kernel memory.) However, > >> such page faults should never need to grow the kernel page table. The > >> necessary page table pages should have been allocated during > >> initialization when the various kernel map submaps were created. The > >> bottom line is that I don't have an immediate answer. I'm going to need > >> to think about this. In general, I'm a bit uncomfortable with the way > >> that the l2 and l2 table zones are created. > > Still getting the LOR.. It always right after boot.. after trying > > to mount root and warning about no time-of-day clock, but before setting > > hostuuid.. > > I should be able to spend some time looking into this LOR today and/or > tomorrow. > > >> In the meantime, my next patch is attached. This applies to both the > >> original pmap and the new v6 pmap. Can some folks here please test > >> this? Here is the description: > > I just tried it on my armv6 BEAGLEBONE... It boots find to multiuser > > mode... Ran a few programs and worked fine... This only tests the > > pmap-v6.c patch, not the other pmap patch... > > Can someone here please try the following one-line patch to the v6 > pmap? Knowing that this works will help me to rule out some possible > explanations for the strange stack trace and LOR above. > > Alan There has been a boot-time LOR involving the same locks, but with a different backtrace, for a long time. In case it helps, the following is from freebsd 8.2 (the latest I can test with right now), the pmap.c in question is r205956 according to the __FBSDID() in the code. There are actually two LORs below, the first involves the same locks as above, the second one is different. Trying to mount root from ufs:/dev/mmcsd0s1a warning: no time-of-day clock registered, system time will not be set accurately lock order reversal: 1st 0xc0a8a0b0 pmap (pmap) @ /usr/src/sys/arm/arm/pmap.c:971 2nd 0xc055b608 PV ENTRY (UMA zone) @ /usr/src/sys/vm/uma_core.c:2055 KDB: stack backtrace: db_trace_thread() at db_trace_thread+0x10 scp=0xc0215d64 rlv=0xc0215f68 (db_trace_self+0x1c) rsp=0xc2e9d950 rfp=0xc2e9d95c r10=0x00000000 r9=0xc0a4c4b8 r8=0xc040aec4 r7=0xffffffff r6=0xc0a4c6c0 r5=0xc023a1fc r4=0xc2e9d968 db_trace_self() at db_trace_self+0x10 scp=0xc0215f5c rlv=0xc001ee0c (db_trace_self_wrapper+0x30) rsp=0xc2e9d960 rfp=0xc2e9da7c db_trace_self_wrapper() at db_trace_self_wrapper+0x10 scp=0xc001edec rlv=0xc00ef4f8 (kdb_backtrace+0x3c) rsp=0xc2e9da80 rfp=0xc2e9da90 r4=0xc02dbf44 kdb_backtrace() at kdb_backtrace+0x10 scp=0xc00ef4cc rlv=0xc0102c38 (_witness_debugger+0x2c) rsp=0xc2e9da94 rfp=0xc2e9daa8 r4=0x00000001 _witness_debugger() at _witness_debugger+0x10 scp=0xc0102c1c rlv=0xc0103458 (witness_checkorder+0x7e8) rsp=0xc2e9daac rfp=0xc2e9daf8 r5=0x00000000 r4=0xc055b608 witness_checkorder() at witness_checkorder+0x10 scp=0xc0102c80 rlv=0xc00b37fc (_mtx_lock_flags+0xa4) rsp=0xc2e9dafc rfp=0xc2e9db20 r10=0x00000000 r9=0xc043c5ac r8=0x00000000 r7=0x00000807 r6=0xc026e694 r5=0x00000000 r4=0xc055b608 _mtx_lock_flags() at _mtx_lock_flags+0x10 scp=0xc00b3768 rlv=0xc01f4ccc (uma_zalloc_arg+0x1a8) rsp=0xc2e9db24 rfp=0xc2e9db60 r8=0xc055a6e0 r7=0xc055a740 r6=0xc0272f64 r5=0xc05370b8 r4=0xc026e694 uma_zalloc_arg() at uma_zalloc_arg+0x10 scp=0xc01f4b34 rlv=0xc021b4b8 (pmap_get_pv_entry+0x40) rsp=0xc2e9db64 rfp=0xc2e9db70 r10=0x00000000 r9=0xc043c5ac r8=0x2078d55e r7=0xc0a8a0b0 r6=0xc0272f64 r5=0xc05370b8 r4=0x00000000 pmap_get_pv_entry() at pmap_get_pv_entry+0x10 scp=0xc021b488 rlv=0xc0220184 (pmap_enter_locked+0xcfc) rsp=0xc2e9db74 rfp=0xc2e9dbf0 pmap_enter_locked() at pmap_enter_locked+0x10 scp=0xc021f498 rlv=0xc02206e8 (pmap_enter+0x74) rsp=0xc2e9dbf4 rfp=0xc2e9dc20 r10=0x00000007 r9=0xc2e9dde4 r8=0xc056de50 r7=0xbffff000 r6=0xc043a07c r5=0xc0a8a0b0 r4=0xc0272f64 pmap_enter() at pmap_enter+0x10 scp=0xc0220684 rlv=0xc01f80c8 (vm_fault+0x1688) rsp=0xc2e9dc24 rfp=0xc2e9dd3c r10=0x00000002 r8=0xbffff000 r7=0xc0a88000 r6=0x00000000 r5=0xc0273400 r4=0xc056de50 vm_fault() at vm_fault+0x10 scp=0xc01f6a50 rlv=0xc0224058 (data_abort_handler+0x360) rsp=0xc2e9dd40 rfp=0xc2e9dde0 r10=0x00000002 r9=0xc2e9dde4 r8=0xbffff000 r7=0xc0a88000 r6=0x00000000 r5=0xc0273400 r4=0xc0a86088 data_abort_handler() at data_abort_handler+0x10 scp=0xc0223d08 rlv=0xc021776c (exception_exit) rsp=0xc2e9dde4 rfp=0xc2e9de84 r10=0xc02b7cea r9=0xc0a86000 r8=0xc2e9deac r7=0xc02b7cea r6=0xc02b7ce0 r5=0xffff1004 r4=0xffffffff start_init() at start_init+0x10 scp=0xc0082244 rlv=0xc009c460 (fork_exit+0x84) rsp=0xc2e9de88 rfp=0xc2e9dea8 r10=0x00000000 r9=0x00000000 r8=0xc2e9deac r7=0x00000000 r6=0xc0082234 r5=0xc0a86000 r4=0xc0a88000 fork_exit() at fork_exit+0x10 scp=0xc009c3ec rlv=0xc022352c (fork_trampoline+0x14) rsp=0xc2e9deac rfp=0x00000000 r8=0x00000000 r7=0x6c6c6568 r6=0x735f6365 r5=0x00000000 r4=0xc0082234 lock order reversal: 1st 0xc0a8a0b0 pmap (pmap) @ /usr/src/sys/arm/arm/pmap.c:971 2nd 0xc043a07c vm page queue mutex (vm page queue mutex) @ /usr/src/sys/arm/arm/pmap.c:1667 KDB: stack backtrace: db_trace_thread() at db_trace_thread+0x10 scp=0xc0215d64 rlv=0xc0215f68 (db_trace_self+0x1c) rsp=0xc2e9d7e4 rfp=0xc2e9d7f0 r10=0x00000000 r9=0xc0a4c4b8 r8=0xc040b3ec r7=0xffffffff r6=0xc0a4c178 r5=0xc023a1fc r4=0xc2e9d7fc db_trace_self() at db_trace_self+0x10 scp=0xc0215f5c rlv=0xc001ee0c (db_trace_self_wrapper+0x30) rsp=0xc2e9d7f4 rfp=0xc2e9d910 db_trace_self_wrapper() at db_trace_self_wrapper+0x10 scp=0xc001edec rlv=0xc00ef4f8 (kdb_backtrace+0x3c) rsp=0xc2e9d914 rfp=0xc2e9d924 r4=0xc02dbf44 kdb_backtrace() at kdb_backtrace+0x10 scp=0xc00ef4cc rlv=0xc0102c38 (_witness_debugger+0x2c) rsp=0xc2e9d928 rfp=0xc2e9d93c r4=0x00000001 _witness_debugger() at _witness_debugger+0x10 scp=0xc0102c1c rlv=0xc0103458 (witness_checkorder+0x7e8) rsp=0xc2e9d940 rfp=0xc2e9d98c r5=0x00000000 r4=0xc043a07c witness_checkorder() at witness_checkorder+0x10 scp=0xc0102c80 rlv=0xc00b37fc (_mtx_lock_flags+0xa4) rsp=0xc2e9d990 rfp=0xc2e9d9b4 r10=0x00008000 r9=0x00000012 r8=0x00000000 r7=0x00000683 r6=0xc0272f64 r5=0x00000000 r4=0xc043a07c _mtx_lock_flags() at _mtx_lock_flags+0x10 scp=0xc00b3768 rlv=0xc021b618 (pmap_enter_pv+0x150) rsp=0xc2e9d9b8 rfp=0xc2e9d9e0 r8=0xc0272f64 r7=0x00000000 r6=0xc0a8a0b0 r5=0xc056e120 r4=0xc0689054 pmap_enter_pv() at pmap_enter_pv+0x10 scp=0xc021b4d8 rlv=0xc0220260 (pmap_enter_locked+0xdd8) rsp=0xc2e9d9e4 rfp=0xc2e9da60 r10=0x00000000 r9=0x00000000 r8=0x2079600e r7=0xc0a8a0b0 r6=0xc0272f64 r5=0xc0538e90 r4=0x00000000 pmap_enter_locked() at pmap_enter_locked+0x10 scp=0xc021f498 rlv=0xc0220618 (pmap_enter_object+0x8c) rsp=0xc2e9da64 rfp=0xc2e9da9c r10=0x00008000 r9=0xc0a8a0b0 r8=0xc056e120 r7=0x00000000 r6=0x00000099 r5=0xc056e120 r4=0x0000000f pmap_enter_object() at pmap_enter_object+0x10 scp=0xc022059c rlv=0xc01fba6c (vm_map_pmap_enter+0x2a8) rsp=0xc2e9daa0 rfp=0xc2e9dae4 r10=0xc056e120 r9=0x00000001 r8=0x00000000 r7=0x00000099 r6=0x00000000 r5=0x00000000 r4=0x0000000f vm_map_pmap_enter() at vm_map_pmap_enter+0x10 scp=0xc01fb7d4 rlv=0xc01fc268 (vm_map_insert+0x474) rsp=0xc2e9dae8 rfp=0xc2e9db3c r10=0x00008000 r9=0x00000000 r8=0x00000000 r7=0x0000040c r6=0xc0548550 r5=0xc0a8a000 r4=0x00000000 vm_map_insert() at vm_map_insert+0x10 scp=0xc01fbe04 rlv=0xc00800c4 (elf32_map_insert+0x234) rsp=0xc2e9db40 rfp=0xc2e9db88 r10=0x000a1000 r9=0xfffff000 r8=0x00098d64 r7=0x00000000 r6=0x00000000 r5=0x00000005 r4=0xc02503d0 elf32_map_insert() at elf32_map_insert+0x10 scp=0xc007fea0 rlv=0xc0080210 (elf32_load_section+0x100) rsp=0xc2e9db8c rfp=0xc2e9dbcc r10=0x00000005 r9=0xfffff000 r8=0x00098d64 r7=0xc0548550 r6=0x00000000 r5=0x00098d64 r4=0x00008000 elf32_load_section() at elf32_load_section+0x10 scp=0xc0080120 rlv=0xc0081634 (exec_elf32_imgact+0x580) rsp=0xc2e9dbd0 rfp=0xc2e9dc68 r10=0xc02ceba8 r9=0xc2ea1034 r8=0xc2e9dd5c r7=0xc2ea1000 r6=0x00000000 r5=0xc0548550 r4=0x00008000 exec_elf32_imgact() at exec_elf32_imgact+0x10 scp=0xc00810c4 rlv=0xc009927c (kern_execve+0x2f8) rsp=0xc2e9dc6c rfp=0xc2e9dde8 r10=0xc0a88000 r9=0xc0a86000 r8=0xc2e9ddf4 r7=0x00000000 r6=0x00000000 r5=0x00000000 r4=0x00000001 kern_execve() at kern_execve+0x10 scp=0xc0098f94 rlv=0xc0099d4c (execve+0x4c) rsp=0xc2e9ddec rfp=0xc2e9de2c r10=0xc02b7cea r9=0xc0a86000 r8=0xbffffffd r7=0xc02b7cea r6=0xc02b7ce0 r5=0xc2e9ddf4 r4=0xc0a88000 execve() at execve+0x10 scp=0xc0099d10 rlv=0xc008244c (start_init+0x218) rsp=0xc2e9de30 rfp=0xc2e9de84 r5=0xbffffff2 r4=0xbfffffe4 start_init() at start_init+0x10 scp=0xc0082244 rlv=0xc009c460 (fork_exit+0x84) rsp=0xc2e9de88 rfp=0xc2e9dea8 r10=0x00000000 r9=0x00000000 r8=0xc2e9deac r7=0x00000000 r6=0xc0082234 r5=0xc0a86000 r4=0xc0a88000 fork_exit() at fork_exit+0x10 scp=0xc009c3ec rlv=0xc022352c (fork_trampoline+0x14) rsp=0xc2e9deac rfp=0x00000000 r8=0x00000000 r7=0x6c6c6568 r6=0x735f6365 r5=0x00000000 r4=0xc0082234 -- Ian