Date: Thu, 24 Apr 2014 00:32:13 GMT From: Winston Smith <smith.winston.101@gmail.com> To: freebsd-gnats-submit@FreeBSD.org Subject: arm/188933: lock order reversal: backtrace while writing to SD/eMMC Message-ID: <201404240032.s3O0WDaH011684@cgiserv.freebsd.org> Resent-Message-ID: <201404240040.s3O0e0qP068693@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 188933
>Category: arm
>Synopsis: lock order reversal: backtrace while writing to SD/eMMC
>Confidential: no
>Severity: non-critical
>Priority: low
>Responsible: freebsd-arm
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Thu Apr 24 00:40:00 UTC 2014
>Closed-Date:
>Last-Modified:
>Originator: Winston Smith
>Release: 10.0-STABLE
>Organization:
>Environment:
FreeBSD beaglebone 10.0-STABLE FreeBSD 10.0-STABLE #0 r264836: Wed Apr 23 18:52:04 EDT 2014 root@freebsd:/root/Work/crochet-freebsd/work/obj/arm.armv6/usr/src/FreeBSD-stable-10/sys/BEAGLEBONE arm
>Description:
I used crotchet-freebsd to build an ARM version of FreeBSD 10.0-STABLE r264836 for the BeagleBone Black. I booted a BeagleBone from the SD card. NOT the eMMC (although I have also seen this in FreeBSD-CURRENT booted from the eMMC). Next, I copied over bash-4.3.src.tgz to build and while unpacking it with `tar xf`, I see the following on the console:
lock order reversal:
1st 0xcd182f70 bufwait (bufwait) @ /usr/src/FreeBSD-stable-10/sys/kern/vfs_bio.c:3050
2nd 0xc29c6a00 dirhash (dirhash) @ /usr/src/FreeBSD-stable-10/sys/ufs/ufs/ufs_dirhash.c:284
KDB: stack backtrace:
db_trace_self() at db_trace_self
pc = 0xc0540880 lr = 0xc0230328 (db_trace_self_wrapper+0x30)
sp = 0xdeafa7e8 fp = 0xdeafa900
r10 = 0xc29c6a00
db_trace_self_wrapper() at db_trace_self_wrapper+0x30
pc = 0xc0230328 lr = 0xc0398c90 (kdb_backtrace+0x38)
sp = 0xdeafa908 fp = 0xdeafa910
r4 = 0xc067e3a4 r5 = 0xc05a5545
r6 = 0xc05c1009 r7 = 0xc05aaab5
kdb_backtrace() at kdb_backtrace+0x38
pc = 0xc0398c90 lr = 0xc03b367c (witness_checkorder+0xe48)
sp = 0xdeafa918 fp = 0xdeafa968
r4 = 0xc05c13cd
witness_checkorder() at witness_checkorder+0xe48
pc = 0xc03b367c lr = 0xc0368dec (_sx_xlock+0x84)
sp = 0xdeafa970 fp = 0xdeafa998
r4 = 0x0000011c r5 = 0xc05c1006
r6 = 0xc29c6a10 r7 = 0xc29c6a00
r8 = 0x00000000 r9 = 0xc2ef27e0
r10 = 0x00000000
_sx_xlock() at _sx_xlock+0x84
pc = 0xc0368dec lr = 0xc04fc83c (ufsdirhash_add+0x34)
sp = 0xdeafa9a0 fp = 0xdeafa9b8
r4 = 0xc29c6a00 r5 = 0x00000818
r6 = 0xc2eee180 r7 = 0xdeafaa50
r8 = 0xdeafaa50
ufsdirhash_add() at ufsdirhash_add+0x34
pc = 0xc04fc83c lr = 0xc04ff350 (ufs_direnter+0x63c)
sp = 0xdeafa9c0 fp = 0xdeafaa28
r4 = 0xc2eee180 r5 = 0x00000018
r6 = 0xcd39b818 r7 = 0xdeafaa50
r8 = 0xc2c41c80 r9 = 0xc2ef27e0
ufs_direnter() at ufs_direnter+0x63c
pc = 0xc04ff350 lr = 0xc05087f4 (ufs_makeinode+0x3ec)
sp = 0xdeafaa30 fp = 0xdeafab90
r4 = 0x00000000 r5 = 0xdeafad30
r6 = 0xdeafaa50 r7 = 0x00000000
r8 = 0xdeafad48 r9 = 0xc2ef27e0
r10 = 0xc2f33b80
ufs_makeinode() at ufs_makeinode+0x3ec
pc = 0xc05087f4 lr = 0xc0504bdc (ufs_create+0x24)
sp = 0xdeafab98 fp = 0xdeafab98
r4 = 0xdeafac68 r5 = 0xc06629d0
r6 = 0x00000000 r7 = 0x00100a02
r8 = 0x00000000 r9 = 0xdeafad50
r10 = 0xdeafad30
ufs_create() at ufs_create+0x24
pc = 0xc0504bdc lr = 0xc0563fc4 (VOP_CREATE_APV+0xd0)
sp = 0xdeafaba0 fp = 0xdeafabb0
VOP_CREATE_APV() at VOP_CREATE_APV+0xd0
pc = 0xc0563fc4 lr = 0xc04143ac (vn_open_cred+0x274)
sp = 0xdeafabb8 fp = 0xdeafac98
r4 = 0xdeaface0 r5 = 0xdeafad30
r6 = 0xc2ef27e0
vn_open_cred() at vn_open_cred+0x274
pc = 0xc04143ac lr = 0xc0414130 (vn_open+0x24)
sp = 0xdeafaca0 fp = 0xdeafaca8
r4 = 0xc2c41c80 r5 = 0x000500cf
r6 = 0x00000012 r7 = 0xdeaface0
r8 = 0x00000000 r9 = 0x20c4a380
r10 = 0xdeafacd0
vn_open() at vn_open+0x24
pc = 0xc0414130 lr = 0xc040d668 (kern_openat+0x248)
sp = 0xdeafacb0 fp = 0xdeafada8
kern_openat() at kern_openat+0x248
pc = 0xc040d668 lr = 0xc040d3b0 (sys_open+0x28)
sp = 0xdeafadb0 fp = 0xdeafadb8
r4 = 0xc2c41c80 r5 = 0xc29da640
r6 = 0x00000000 r7 = 0x00000000
r8 = 0x00000001 r9 = 0xdeafae10
r10 = 0x20c42080
sys_open() at sys_open+0x28
pc = 0xc040d3b0 lr = 0xc0552a7c (swi_handler+0x284)
sp = 0xdeafadc0 fp = 0xdeafae58
swi_handler() at swi_handler+0x284
pc = 0xc0552a7c lr = 0xc05421ac (swi_entry+0x2c)
sp = 0xdeafae60 fp = 0xbffffa28
r4 = 0x20c09200 r5 = 0x000001a4
r6 = 0x20c4a39b r7 = 0x00000005
r8 = 0x00000001 r9 = 0x20c09364
swi_entry() at swi_entry+0x2c
pc = 0xc05421ac lr = 0xc05421ac (swi_entry+0x2c)
sp = 0xdeafae60 fp = 0xbffffa28
Unable to unwind further
Filesystem mounts are as follows:
/dev/ufs/sdfreebsd1 on / (ufs, local, noatime, journaled soft-updates, nfsv4acls)
devfs on /dev (devfs, local)
/dev/msdosfs/SDBOOT on /boot/msdos (msdosfs, local, noatime)
/dev/md0 on /tmp (ufs, local, noatime, soft-updates)
/dev/md1 on /var/log (ufs, local, noatime, soft-updates)
/dev/md2 on /var/tmp (ufs, local, noatime, soft-updates)
And here's the dmesg output:
KDB: debugger backends: ddb
KDB: current backend: ddb
Copyright (c) 1992-2014 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 10.0-STABLE #0 r264836: Wed Apr 23 18:52:04 EDT 2014
root@freebsd:/usr/home/davem/Work/crochet-freebsd/work/obj/arm.armv6/usr/src/FreeBSD-stable-10/sys/BEAGLEBONE arm
FreeBSD clang version 3.4 (tags/RELEASE_34/final 197956) 20140216
WARNING: WITNESS option enabled, expect reduced performance.
CPU: Cortex A8-r3 rev 2 (Cortex-A core)
Supported features: ARM_ISA THUMB2 JAZELLE THUMBEE ARMv4 Security_Ext
WB disabled EABT branch prediction enabled
LoUU:2 LoC:2 LoUIS:1
Cache level 1:
32KB/64B 4-way data cache WT WB Read-Alloc
32KB/64B 4-way instruction cache Read-Alloc
Cache level 2:
256KB/64B 8-way unified cache WT WB Read-Alloc Write-Alloc
real memory = 536870912 (512 MB)
avail memory = 515538944 (491 MB)
Texas Instruments AM3358 Processor, Revision ES1.1
random: <Software, Yarrow> initialized
simplebus0: <Flattened device tree simple bus> on fdtbus0
aintc0: <TI AINTC Interrupt Controller> mem 0x48200000-0x48200fff on simplebus0
aintc0: Revision 5.0
ti_scm0: <TI Control Module> mem 0x44e10000-0x44e11fff on simplebus0
am335x_prcm0: <AM335x Power and Clock Management> mem 0x44e00000-0x44e012ff on simplebus0
am335x_prcm0: Clocks: System 24.0 MHz, CPU 550 MHz
am335x_dmtimer0: <AM335x DMTimer> mem 0x44e05000-0x44e05fff,0x44e31000-0x44e31fff,0x48040000-0x48040fff,0x48042000-0x48042fff,0x48044000-0x48044fff,0x48046000-0x48046fff,0x48048000-0x48048fff,0x4804a000-0x4804afff irq 66,67,68,69,92,93,94,95 on simplebus0
Timecounter "AM335x Timecounter" frequency 24000000 Hz quality 1000
Event timer "AM335x Eventtimer0" frequency 24000000 Hz quality 1000
gpio0: <TI General Purpose I/O (GPIO)> mem 0x44e07000-0x44e07fff,0x4804c000-0x4804cfff,0x481ac000-0x481acfff,0x481ae000-0x481aefff irq 96,97,98,99,32,33,62,63 on simplebus0
gpioc0: <GPIO controller> on gpio0
gpiobus0: <GPIO bus> on gpio0
uart0: <TI UART (16550 compatible)> mem 0x44e09000-0x44e09fff irq 72 on simplebus0
uart0: console (115384,n,8,1)
ti_edma30: <TI EDMA Controller> mem 0x49000000-0x490fffff,0x49800000-0x498fffff,0x49900000-0x499fffff,0x49a00000-0x49afffff irq 12,13,14 on simplebus0
ti_edma30: EDMA revision 40014c00
sdhci_ti0: <TI MMCHS (SDHCI 2.0)> mem 0x48060000-0x48060fff irq 64 on simplebus0
mmc0: <MMC/SD bus> on sdhci_ti0
sdhci_ti1: <TI MMCHS (SDHCI 2.0)> mem 0x481d8000-0x481d8fff irq 28 on simplebus0
mmc1: <MMC/SD bus> on sdhci_ti1
cpsw0: <3-port Switch Ethernet Subsystem> mem 0x4a100000-0x4a103fff irq 40,41,42,43 on simplebus0
cpsw0: CPSW SS Version 1.12 (0)
cpsw0: Initial queue size TX=128 RX=384
cpsw0: Ethernet address: 90:59:af:7c:14:f7
miibus0: <MII bus> on cpsw0
smscphy0: <SMC LAN8710A 10/100 interface> PHY 0 on miibus0
smscphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
iichb0: <TI I2C Controller> mem 0x44e0b000-0x44e0bfff irq 70 on simplebus0
iichb0: I2C revision 4.0
iicbus0: <OFW I2C bus> on iichb0
iic0: <I2C generic I/O> on iicbus0
am335x_pmic0: <TI TPS65217 Power Management IC> at addr 0x24 on iicbus0
am335x_pwm0: <AM335x PWM> mem 0x48300000-0x483000ff,0x48300100-0x4830017f,0x48300180-0x483001ff,0x48300200-0x4830025f irq 86,58 on simplebus0
am335x_pwm1: <AM335x PWM> mem 0x48302000-0x483020ff,0x48302100-0x4830217f,0x48302180-0x483021ff,0x48302200-0x4830225f irq 87,59 on simplebus0
am335x_pwm2: <AM335x PWM> mem 0x48304000-0x483040ff,0x48304100-0x4830417f,0x48304180-0x483041ff,0x48304200-0x4830425f irq 88,60 on simplebus0
musbotg0: <TI AM33xx integrated USB OTG controller> mem 0x47400000-0x47400fff,0x47401000-0x474012ff,0x47401300-0x474013ff,0x47401400-0x474017ff,0x47401800-0x47401aff,0x47401b00-0x47401bff,0x47401c00-0x47401fff irq 17,18,19 on simplebus0
musbotg0: TI AM335X USBSS v0.0.13
usbus0: Dynamic FIFO sizing detected, assuming 16Kbytes of FIFO RAM
usbus0 on musbotg0
usbus1: Dynamic FIFO sizing detected, assuming 16Kbytes of FIFO RAM
usbus1 on musbotg0
Timecounters tick every 10.000 msec
usbus0: 480Mbps High Speed USB v2.0
usbus1: 480Mbps High Speed USB v2.0
ugen0.1: <Mentor Graphics> at usbus0
uhub0: <Mentor Graphics OTG Root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus0
ugen1.1: <Mentor Graphics> at usbus1
uhub1: <Mentor Graphics OTG Root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
mmcsd0: 4GB <SDHC SA04G 1.0 SN 628739603 MFG 09/2011 by 2 TM> at mmc0 48.0MHz/4bit/65535-block
uhub0: 1 port with 1 removable, self powered
uhub1: 1 port with 1 removable, self powered
mmcsd1: 2GB <MMC MMC02G 3.10 SN 2440249566 MFG 08/1997 by 254 0x004e> at mmc1 48.0MHz/8bit/65535-block
am335x_pmic0: TPS65217C ver 1.2 powered by AC
random: unblocking device.
WARNING: WITNESS option enabled, expect reduced performance.
Trying to mount root from ufs:/dev/ufs/sdfreebsd1 [rw,noatime]...
warning: no time-of-day clock registered, system time will not be set accurately
>How-To-Repeat:
Happens on a fairly regular bases when accessing the SD card or eMMC devices. I've also seen it when umounting filesystems as well as during /sbin/halt.
>Fix:
>Release-Note:
>Audit-Trail:
>Unformatted:
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201404240032.s3O0WDaH011684>