MMC/regulator boot hang in -next

From: John Stultz
Date: Mon Nov 02 2015 - 14:57:47 EST


Trying to move my nexus7 work to -next, I started seeing boot time
hangs. Enabling some debug options provided with a lockdep spew.

Reverting "regulator: core: Propagate voltage changes to supply
regulators" - fc42112c0eaa avoids the hang, but I still see lockdep
noise.

Full log of -next based tree without any reverts follows:

thanks
-john

[ 2.458139] =============================================
[ 2.459709] [ INFO: possible recursive locking detected ]
[ 2.463873] input: Elan Touchscreen as
/devices/platform/soc/16200000.gsbi/16280000.i2c/i2c-1/1-0010/input/input0
[ 2.470412] 4.3.0-rc7-next-20151102-00022-gb347b1e #660 Not tainted
[ 2.475393] elants_i2c 1-0010: unknown packet ff ff ff ff
[ 2.486706] ---------------------------------------------
[ 2.492265] swapper/0/1 is trying to acquire lock:
[ 2.497642] ([ 2.501146] mmc0: new high speed MMC card at address 0001

[ 2.503979] &rdev->mutex[ 2.504689] mmcblk0: mmc0:0001 016GE2 14.6 GiB
[ 2.506461] mmcblk0boot0: mmc0:0001 016GE2 partition 1 4.00 MiB
[ 2.507983] mmcblk0boot1: mmc0:0001 016GE2 partition 2 4.00 MiB
[ 2.509745] mmcblk0rpmb: mmc0:0001 016GE2 partition 3 4.00 MiB
[ 2.518637] mmcblk0: p1 p2 p3 p4 p5 p6 p7 p8 p9 p10 p11 p12 p13
p14 p15 p16 p17 p18 p19 p20 p21 p22 p23 p24 p25 p260
[ 2.533857] ){+.+.+.}, at: [<c04edfc0>] regulator_get_voltage+0x18/0x38
[ 2.548423]
[ 2.548423] but task is already holding lock:
[ 2.552415] (&rdev->mutex){+.+.+.}, at: [<c04ef080>]
regulator_set_voltage+0x2c/0x78
[ 2.562051]
[ 2.562051] other info that might help us debug this:
[ 2.566051] Possible unsafe locking scenario:
[ 2.566051]
[ 2.572470] CPU0
[ 2.578278] ----
[ 2.580706] lock(&rdev->mutex);
[ 2.586083] lock(&rdev->mutex);
[ 2.589384]
[ 2.589384] *** DEADLOCK ***
[ 2.589384]
[ 2.589745] May be due to missing lock nesting notation
[ 2.589745]
[ 2.595655] 4 locks held by swapper/0/1:
[ 2.602585] #0: (&dev->mutex){......}, at: [<c0520db0>]
__driver_attach+0x48/0x98
[ 2.610662] #1: (&dev->mutex){......}, at: [<c0520dc0>]
__driver_attach+0x58/0x98
[ 2.618297] #2: (&rdev->mutex){+.+.+.}, at: [<c04ef080>]
regulator_set_voltage+0x2c/0x78
[ 2.626025] #3: (&rdev->mutex/1){+.+...}, at: [<c04ef080>]
regulator_set_voltage+0x2c/0x78
[ 2.634446]
[ 2.634446] stack backtrace:
[ 2.638458] CPU: 2 PID: 1 Comm: swapper/0 Not tainted
4.3.0-rc7-next-20151102-00022-gb347b1e #660
[ 2.642795] Hardware name: Qualcomm (Flattened Device Tree)
[ 2.651699] [<c0216f90>] (unwind_backtrace) from [<c0213c18>]
(show_stack+0x10/0x14)
[ 2.657062] [<c0213c18>] (show_stack) from [<c04a3c98>]
(dump_stack+0x70/0xbc)
[ 2.665046] [<c04a3c98>] (dump_stack) from [<c0273018>]
(__lock_acquire+0xe28/0x1af8)
[ 2.672071] [<c0273018>] (__lock_acquire) from [<c0274b50>]
(lock_acquire+0xf8/0x250)
[ 2.679986] [<c0274b50>] (lock_acquire) from [<c087db54>]
(mutex_lock_nested+0x54/0x44c)
[ 2.687796] [<c087db54>] (mutex_lock_nested) from [<c04edfc0>]
(regulator_get_voltage+0x18/0x38)
[ 2.695953] [<c04edfc0>] (regulator_get_voltage) from [<c04ee084>]
(_regulator_get_voltage+0xa4/0xb0)
[ 2.704720] [<c04ee084>] (_regulator_get_voltage) from [<c04eef44>]
(regulator_set_voltage_unlocked+0x10c/0x21c)
[ 2.713837] [<c04eef44>] (regulator_set_voltage_unlocked) from
[<c04ef0a0>] (regulator_set_voltage+0x4c/0x78)
[ 2.724094] [<c04ef0a0>] (regulator_set_voltage) from [<c0643c18>]
(mmci_sig_volt_switch+0x4c/0xe8)
[ 2.733894] [<c0643c18>] (mmci_sig_volt_switch) from [<c063285c>]
(mmc_power_up+0x6c/0x210)
[ 2.742740] [<c063285c>] (mmc_power_up) from [<c0633c08>]
(mmc_start_host+0x50/0x80)
[ 2.751071] [<c0633c08>] (mmc_start_host) from [<c063509c>]
(mmc_add_host+0x44/0x68)
[ 2.759057] [<c063509c>] (mmc_add_host) from [<c06444cc>]
(mmci_probe+0x5b8/0x8dc)
[ 2.766793] [<c06444cc>] (mmci_probe) from [<c04e6f78>]
(amba_probe+0xcc/0x148)
[ 2.774161] [<c04e6f78>] (amba_probe) from [<c0520b20>]
(driver_probe_device+0x1e4/0x42c)
[ 2.781364] [<c0520b20>] (driver_probe_device) from [<c0520dfc>]
(__driver_attach+0x94/0x98)
[ 2.789697] [<c0520dfc>] (__driver_attach) from [<c051ef7c>]
(bus_for_each_dev+0x54/0x88)
[ 2.798200] [<c051ef7c>] (bus_for_each_dev) from [<c051f838>]
(bus_add_driver+0x170/0x24c)
[ 2.806277] [<c051f838>] (bus_add_driver) from [<c0521b2c>]
(driver_register+0x78/0xf4)
[ 2.814444] [<c0521b2c>] (driver_register) from [<c0a7cdbc>]
(do_one_initcall+0x10c/0x1ec)
[ 2.822341] [<c0a7cdbc>] (do_one_initcall) from [<c0a7cfb8>]
(kernel_init_freeable+0x11c/0x1ec)
[ 2.830667] [<c0a7cfb8>] (kernel_init_freeable) from [<c087a030>]
(kernel_init+0x8/0xec)
[ 2.839262] [<c087a030>] (kernel_init) from [<c02100d0>]
(ret_from_fork+0x14/0x24)

[long stall here before hung task detection triggers]

[ 240.371648] INFO: task swapper/0:1 blocked for more than 120 seconds.
[ 240.371719] Not tainted 4.3.0-rc7-next-20151102-00022-gb347b1e #660
[ 240.377101] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 240.384021] swapper/0 D c087c620 0 1 0 0x00000000
[ 240.395358] [<c087c620>] (__schedule) from [<c087cea8>] (schedule+0x40/0xac)
[ 240.397970] [<c087cea8>] (schedule) from [<c087cf28>]
(schedule_preempt_disabled+0x14/0x20)
[ 240.405326] [<c087cf28>] (schedule_preempt_disabled) from
[<c087dcac>] (mutex_lock_nested+0x1ac/0x44c)
[ 240.413383] [<c087dcac>] (mutex_lock_nested) from [<c04edfc0>]
(regulator_get_voltage+0x18/0x38)
[ 240.422750] [<c04edfc0>] (regulator_get_voltage) from [<c04ee084>]
(_regulator_get_voltage+0xa4/0xb0)
[ 240.431692] [<c04ee084>] (_regulator_get_voltage) from [<c04eef44>]
(regulator_set_voltage_unlocked+0x10c/0x21c)
[ 240.440686] [<c04eef44>] (regulator_set_voltage_unlocked) from
[<c04ef0a0>] (regulator_set_voltage+0x4c/0x78)
[ 240.451074] [<c04ef0a0>] (regulator_set_voltage) from [<c0643c18>]
(mmci_sig_volt_switch+0x4c/0xe8)
[ 240.460869] [<c0643c18>] (mmci_sig_volt_switch) from [<c063285c>]
(mmc_power_up+0x6c/0x210)
[ 240.469712] [<c063285c>] (mmc_power_up) from [<c0633c08>]
(mmc_start_host+0x50/0x80)
[ 240.478045] [<c0633c08>] (mmc_start_host) from [<c063509c>]
(mmc_add_host+0x44/0x68)
[ 240.486044] [<c063509c>] (mmc_add_host) from [<c06444cc>]
(mmci_probe+0x5b8/0x8dc)
[ 240.493767] [<c06444cc>] (mmci_probe) from [<c04e6f78>]
(amba_probe+0xcc/0x148)
[ 240.501010] [<c04e6f78>] (amba_probe) from [<c0520b20>]
(driver_probe_device+0x1e4/0x42c)
[ 240.508348] [<c0520b20>] (driver_probe_device) from [<c0520dfc>]
(__driver_attach+0x94/0x98)
[ 240.516677] [<c0520dfc>] (__driver_attach) from [<c051ef7c>]
(bus_for_each_dev+0x54/0x88)
[ 240.525190] [<c051ef7c>] (bus_for_each_dev) from [<c051f838>]
(bus_add_driver+0x170/0x24c)
[ 240.533248] [<c051f838>] (bus_add_driver) from [<c0521b2c>]
(driver_register+0x78/0xf4)
[ 240.541285] [<c0521b2c>] (driver_register) from [<c0a7cdbc>]
(do_one_initcall+0x10c/0x1ec)
[ 240.549187] [<c0a7cdbc>] (do_one_initcall) from [<c0a7cfb8>]
(kernel_init_freeable+0x11c/0x1ec)
[ 240.557660] [<c0a7cfb8>] (kernel_init_freeable) from [<c087a030>]
(kernel_init+0x8/0xec)
[ 240.566236] [<c087a030>] (kernel_init) from [<c02100d0>]
(ret_from_fork+0x14/0x24)
[ 240.574539] INFO: lockdep is turned off.
[ 240.581926] Sending NMI to all CPUs:
[ 250.592662] Kernel panic - not syncing: hung_task: blocked tasks
[ 250.592731] CPU: 1 PID: 29 Comm: khungtaskd Not tainted
4.3.0-rc7-next-20151102-00022-gb347b1e #660
[ 250.597766] Hardware name: Qualcomm (Flattened Device Tree)
[ 250.606566] [<c0216f90>] (unwind_backtrace) from [<c0213c18>]
(show_stack+0x10/0x14)
[ 250.612117] [<c0213c18>] (show_stack) from [<c04a3c98>]
(dump_stack+0x70/0xbc)
[ 250.620117] [<c04a3c98>] (dump_stack) from [<c02f1bac>] (panic+0x94/0x220)
[ 250.627143] [<c02f1bac>] (panic) from [<c02c4e74>] (watchdog+0x418/0x654)
[ 250.633998] [<c02c4e74>] (watchdog) from [<c0245e90>] (kthread+0xd8/0xf4)
[ 250.640852] [<c0245e90>] (kthread) from [<c02100d0>]
(ret_from_fork+0x14/0x24)
[ 250.647620] CPU2: stopping
[ 250.654707] CPU: 2 PID: 0 Comm: swapper/2 Not tainted
4.3.0-rc7-next-20151102-00022-gb347b1e #660
[ 250.657402] Hardware name: Qualcomm (Flattened Device Tree)
[ 250.666376] [<c0216f90>] (unwind_backtrace) from [<c0213c18>]
(show_stack+0x10/0x14)
[ 250.671755] [<c0213c18>] (show_stack) from [<c04a3c98>]
(dump_stack+0x70/0xbc)
[ 250.679732] [<c04a3c98>] (dump_stack) from [<c0215f8c>]
(handle_IPI+0x1c0/0x388)
[ 250.686770] [<c0215f8c>] (handle_IPI) from [<c02094c0>]
(gic_handle_irq+0x7c/0x88)
[ 250.694318] [<c02094c0>] (gic_handle_irq) from [<c0214738>]
(__irq_svc+0x58/0x98)
[ 250.701677] Exception stack(0xe8cedf88 to 0xe8cedfd0)
[ 250.709253] df80: c0210b10 00000000 e8cedfd8
00000000 c0ae4728 c0b61d6c
[ 250.714304] dfa0: c0884a44 00000000 00000000 c0adf848 c0b60b3e
c0ae4730 00000001 e8cedfd8
[ 250.722443] dfc0: c0210b10 c0210b14 60000013 ffffffff
[ 250.730601] [<c0214738>] (__irq_svc) from [<c0210b14>]
(arch_cpu_idle+0x20/0x3c)
[ 250.735660] [<c0210b14>] (arch_cpu_idle) from [<c026bbc4>]
(cpu_startup_entry+0x214/0x464)
[ 250.743107] [<c026bbc4>] (cpu_startup_entry) from [<8020956c>] (0x8020956c)
[ 250.751147] CPU0: stopping
[ 250.757992] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
4.3.0-rc7-next-20151102-00022-gb347b1e #660
[ 250.760775] Hardware name: Qualcomm (Flattened Device Tree)
[ 250.769731] [<c0216f90>] (unwind_backtrace) from [<c0213c18>]
(show_stack+0x10/0x14)
[ 250.775108] [<c0213c18>] (show_stack) from [<c04a3c98>]
(dump_stack+0x70/0xbc)
[ 250.783092] [<c04a3c98>] (dump_stack) from [<c0215f8c>]
(handle_IPI+0x1c0/0x388)
[ 250.790122] [<c0215f8c>] (handle_IPI) from [<c02094c0>]
(gic_handle_irq+0x7c/0x88)
[ 250.797672] [<c02094c0>] (gic_handle_irq) from [<c0214738>]
(__irq_svc+0x58/0x98)
[ 250.805043] Exception stack(0xc0ae3f50 to 0xc0ae3f98)
[ 250.812605] 3f40: c0210b10
00000000 c0ae3fa0 00000000
[ 250.817658] 3f60: c0ae4728 c0b61d6c c0884a44 00000000 00000000
c0adf848 c0b60b3e c0ae4730
[ 250.825813] 3f80: 00000001 c0ae3fa0 c0210b10 c0210b14 60000113 ffffffff
[ 250.833961] [<c0214738>] (__irq_svc) from [<c0210b14>]
(arch_cpu_idle+0x20/0x3c)
[ 250.840388] [<c0210b14>] (arch_cpu_idle) from [<c026bbc4>]
(cpu_startup_entry+0x214/0x464)
[ 250.848028] [<c026bbc4>] (cpu_startup_entry) from [<c0a7cc48>]
(start_kernel+0x374/0x3dc)
[ 250.856094] [<c0a7cc48>] (start_kernel) from [<8020807c>] (0x8020807c)
[ 250.864339] CPU3: stopping
[ 250.870772] CPU: 3 PID: 0 Comm: swapper/3 Not tainted
4.3.0-rc7-next-20151102-00022-gb347b1e #660
[ 250.873461] Hardware name: Qualcomm (Flattened Device Tree)
[ 250.882435] [<c0216f90>] (unwind_backtrace) from [<c0213c18>]
(show_stack+0x10/0x14)
[ 250.887811] [<c0213c18>] (show_stack) from [<c04a3c98>]
(dump_stack+0x70/0xbc)
[ 250.895792] [<c04a3c98>] (dump_stack) from [<c0215f8c>]
(handle_IPI+0x1c0/0x388)
[ 250.902825] [<c0215f8c>] (handle_IPI) from [<c02094c0>]
(gic_handle_irq+0x7c/0x88)
[ 250.910374] [<c02094c0>] (gic_handle_irq) from [<c0214738>]
(__irq_svc+0x58/0x98)
[ 250.917731] Exception stack(0xe8ceff88 to 0xe8ceffd0)
[ 250.925316] ff80: c0210b10 00000000 e8ceffd8
00000000 c0ae4728 c0b61d6c
[ 250.930369] ffa0: c0884a44 00000000 00000000 c0adf848 c0b60b3e
c0ae4730 00000001 e8ceffd8
[ 250.938505] ffc0: c0210b10 c0210b14 60000013 ffffffff
[ 250.946659] [<c0214738>] (__irq_svc) from [<c0210b14>]
(arch_cpu_idle+0x20/0x3c)
[ 250.951709] [<c0210b14>] (arch_cpu_idle) from [<c026bbc4>]
(cpu_startup_entry+0x214/0x464)
[ 250.959164] [<c026bbc4>] (cpu_startup_entry) from [<8020956c>] (0x8020956c)
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/