#11514 NORM Not Tri: Locking issue on mmc resume on XO 1.75 C1/SKU202
Zarro Boogs per Child
bugtracker at laptop.org
Thu Dec 1 20:03:12 EST 2011
#11514: Locking issue on mmc resume on XO 1.75 C1/SKU202
-----------------------+----------------------------------------------------
Reporter: greenfeld | Owner:
Type: defect | Status: new
Priority: normal | Milestone: Not Triaged
Component: kernel | Version: not specified
Keywords: | Next_action: diagnose
Verified: 0 | Deployment_affected:
Blockedby: | Blocking:
-----------------------+----------------------------------------------------
Using the locking debug kernel RPM 3.0.0_xo1.75-20111201.1013.olpc.8ab3406
and 11.3.1 os15, the following MMC resume locking warning seems to be
easily reproduced.
To cause it, do a power button-based suspend & resume as the first suspend
cycle after booting or rebooting the XO, using a kernel capable of
debugging locks.
{{{
[ 696.433938] dcon_freeze_store: 0
[ 696.437932] dcon_source_switch to CPU
[ 696.486000] olpc-dcon: The CPU has control
[ 708.016097] dcon_freeze_store: 1
[ 708.029582] dcon_source_switch to DCON
[ 708.057312] olpc-dcon: The DCON has control
[ 708.218048] dcon_freeze_store: 1
[ 708.318936] dcon_freeze_store: 0
[ 708.326534] dcon_source_switch to CPU
[ 708.358171] olpc-dcon: The CPU has control
[ 716.373266] PM: Syncing filesystems ... done.
[ 716.390739] Freezing user space processes ... (elapsed 0.02 seconds)
done.
[ 716.419010] Freezing remaining freezable tasks ... (elapsed 0.01
seconds) done.
[ 716.438999] Suspending console(s) (use no_console_suspend to debug)
[ 716.457998] xehci_bus_resume: ehci:ef7ced0c, ehci->regs: f5828140
[ 716.458945] RAYDIUM_i2c_suspend, disable i2c irq
[ 716.461583] libertas_sdio mmc1:0001:1: mmc1:0001:1: suspend: PM flags =
0x3
[ 716.461744] libertas_sdio mmc1:0001:1: Suspend without wake params --
powering down card
[ 716.469201] xehci_bus_resume: ehci:ef7ced0c, ehci->regs: f5828140
[ 716.499123] mmc1: card 0001 removed
[ 716.500220] [galcore]: gpu_suspend, 1358
[ 716.500277] >>>>>>[_gpu_off]@1127
[ 716.509037] <<<<<<[_gpu_off]@1145
[ 716.569660] u2o_phy_clk_disable
[ 716.570243] PM: suspend of devices complete after 121.298 msecs
[ 716.572124] PM: late suspend of devices complete after 1.729 msecs
[ 716.574619] PM: early resume of devices complete after 0.528 msecs
[ 716.574628] mmp2_pm_finish
[ 716.576342] ehci:ef7cec00, ehci->regs: 00000001
[ 716.590029] u2o_phy_clk_enable
[ 716.591218] [galcore]: gpu_resume, 1369
[ 716.591218] >>>>>>[_gpu_on]@1153
[ 716.591718] xehci_bus_resume: ehci:ef7ced0c, ehci->regs: f5828140
[ 716.600001] <<<<<<[_gpu_on]@1173
[ 716.610017] xehci_bus_resume: ehci:ef7ced0c, ehci->regs: f5828140
[ 716.774420] PM: resume of devices complete after 198.965 msecs
[ 716.881201] Restarting tasks ...
[ 716.885461] usb 1-1: USB disconnect, device number 2
[ 716.908930]
[ 716.909124] =================================
[ 716.914933] [ INFO: inconsistent lock state ]
[ 716.919260] 3.0.0_xo1.75-20111201.1013.olpc.8ab3406 #1
[ 716.919260] ---------------------------------
[ 716.924356] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[ 716.934650] mmcqd/2/50 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 716.934650] (&(&host->lock)->rlock){?.-...}, at: [<c0264424>]
sdhci_execute_tuning+0x24/0x4d0
[ 716.939661] {IN-HARDIRQ-W} state was registered at:
[ 716.948257] [<c00722d0>] __lock_acquire+0x5e8/0x18e0
[ 716.953098] [<c0073a84>] lock_acquire+0x60/0x74
[ 716.958206] [<c0385928>] _raw_spin_lock+0x40/0x50
[ 716.962884] [<c0264f38>] sdhci_irq+0x1c/0x8cc
[ 716.967735] [<c008e2e0>] handle_irq_event_percpu+0x30/0x178
[ 716.972241] [<c008e464>] handle_irq_event+0x3c/0x5c
[ 716.977953] [<c0090074>] handle_level_irq+0xb8/0xe8
[ 716.982967] [<c008de98>] generic_handle_irq+0x20/0x30
[ 716.987990] [<c002c060>] asm_do_IRQ+0x60/0x84
[ 716.993185] [<c0031be0>] __irq_svc+0x60/0xac
[ 716.997699] [<c0386270>] _raw_spin_unlock+0x18/0x4c
[ 717.007141] [<c037e1a0>] klist_next+0x94/0xb4
[ 717.007141] [<c01cd100>] next_device+0x8/0x14
[ 717.011648] [<c01cd398>] bus_for_each_dev+0x58/0x78
[ 717.021184] [<c01cdb00>] bus_add_driver+0xbc/0x248
[ 717.026120] [<c01cea28>] driver_register+0xa8/0x12c
[ 717.031144] [<c002c4c8>] do_one_initcall+0x9c/0x170
[ 717.031144] [<c00089a8>] kernel_init+0x74/0x118
[ 717.036166] [<c0032fb8>] kernel_thread_exit+0x0/0x8
[ 717.045869] irq event stamp: 260604
[ 717.049324] hardirqs last enabled at (260604): [<c0386228>]
_raw_spin_unlock_irqrestore+0x3c/0x6c
[ 717.049324] hardirqs last disabled at (260603): [<c0385a1c>]
_raw_spin_lock_irqsave+0x18/0x64
[ 717.058233] softirqs last enabled at (259457): [<c004d4b4>]
irq_exit+0x54/0xbc
[ 717.066711] softirqs last disabled at (259444): [<c004d4b4>]
irq_exit+0x54/0xbc
[ 717.081252]
[ 717.081252] other info that might help us debug this:
[ 717.081257] Possible unsafe locking scenario:
[ 717.087738]
[ 717.087738] CPU0
[ 717.093606] ----
[ 717.096028] lock(&(&host->lock)->rlock);
[ 717.098448] <Interrupt>
[ 717.102522] lock(&(&host->lock)->rlock);
[ 717.105115]
[ 717.109364] *** DEADLOCK ***
[ 717.109368]
[ 717.109374] no locks held by mmcqd/2/50.
[ 717.115241]
[ 717.119133] stack backtrace:
[ 717.119137] [<c0037ab8>] (unwind_backtrace+0x0/0x120) from [<c0071680>]
(print_usage_bug+0x234/0x298)
[ 717.123474] [<c0071680>] (print_usage_bug+0x234/0x298) from
[<c0071a28>] (mark_lock+0x344/0x604)
[ 717.141364] [<c0071a28>] (mark_lock+0x344/0x604) from [<c0072364>]
(__lock_acquire+0x67c/0x18e0)
[ 717.141364] [<c0072364>] (__lock_acquire+0x67c/0x18e0) from
[<c0073a84>] (lock_acquire+0x60/0x74)
[ 717.150090] [<c0073a84>] (lock_acquire+0x60/0x74) from [<c0385928>]
(_raw_spin_lock+0x40/0x50)
[ 717.158904] [<c0385928>] (_raw_spin_lock+0x40/0x50) from [<c0264424>]
(sdhci_execute_tuning+0x24/0x4d0)
[ 717.167461] [<c0264424>] (sdhci_execute_tuning+0x24/0x4d0) from
[<c0264a74>] (sdhci_request+0x1a4/0x1f0)
[ 717.176800] [<c0264a74>] (sdhci_request+0x1a4/0x1f0) from [<c025158c>]
(mmc_wait_for_req+0x23c/0x278)
[ 717.186229] [<c025158c>] (mmc_wait_for_req+0x23c/0x278) from
[<c025b8c0>] (mmc_blk_issue_rw_rq+0x2b4/0x610)
[ 717.205075] [<c025b8c0>] (mmc_blk_issue_rw_rq+0x2b4/0x610) from
[<c025be90>] (mmc_blk_issue_rq+0x274/0x28c)
[ 717.214757] [<c025be90>] (mmc_blk_issue_rq+0x274/0x28c) from
[<c025c814>] (mmc_queue_thread+0xc0/0xc4)
[ 717.224004] [<c025c814>] (mmc_queue_thread+0xc0/0xc4) from [<c0060acc>]
(kthread+0x80/0x88)
[ 717.232309] [<c0060acc>] (kthread+0x80/0x88) from [<c0032fb8>]
(kernel_thread_exit+0x0/0x8)
[ 717.248463] done.
}}}
--
Ticket URL: <http://dev.laptop.org/ticket/11514>
One Laptop Per Child <http://laptop.org/>
OLPC bug tracking system
More information about the Bugs
mailing list