Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S1752322AbbKBT5n (ORCPT <rfc822;w@1wt.eu>);
	Mon, 2 Nov 2015 14:57:43 -0500
Received: from mail-io0-f181.google.com ([209.85.223.181]:35149 "EHLO
	mail-io0-f181.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1752140AbbKBT5l (ORCPT
	<rfc822;linux-kernel@vger.kernel.org>);
	Mon, 2 Nov 2015 14:57:41 -0500
MIME-Version: 1.0
Date: Mon, 2 Nov 2015 11:57:40 -0800
Message-ID: <CALAqxLW30-dXBPKYEawvdZPaBotQHv2KGjMKHQVo8Q9r_ayWHg@mail.gmail.com>
Subject: MMC/regulator boot hang in -next
From: John Stultz <john.stultz@linaro.org>
To: Sascha Hauer <s.hauer@pengutronix.de>
Cc: Mark Brown <broonie@linaro.org>, Ulf Hansson <ulf.hansson@linaro.org>,
        Bjorn Andersson <bjorn.andersson@sonymobile.com>,
        lkml <linux-kernel@vger.kernel.org>
Content-Type: text/plain; charset=UTF-8
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 11959
Lines: 256

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@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/