Ping....
On Thu, Dec 26, 2013 at 3:58 PM, Dong Aisheng <dongas86@xxxxxxxxx> wrote:
> Hi Peter,
>
> On Mon, Dec 23, 2013 at 7:13 PM, Dong Aisheng <b29396@xxxxxxxxxxxxx> wrote:
>> The sdhci_execute_tuning routine gets lock separately by
>> disable_irq(host->irq);
>> spin_lock(&host->lock);
>> It will cause the following lockdep error message since the &host->lock
>> could also be got in irq context.
>> Use spin_lock_irqsave/spin_unlock_restore instead to get rid of
>> this error message.
>>
>> [ INFO: inconsistent lock state ]
>> 3.13.0-rc1+ #287 Not tainted
>> ---------------------------------
>> inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
>> kworker/u2:1/33 [HC0[0]:SC0[0]:HE1:SE1] takes:
>> (&(&host->lock)->rlock){?.-...}, at: [<8045f7f4>] sdhci_execute_tuning+0x4c/0x710
>> {IN-HARDIRQ-W} state was registered at:
>> [<8005f030>] mark_lock+0x140/0x6ac
>> [<80060760>] __lock_acquire+0xb30/0x1cbc
>> [<800620d0>] lock_acquire+0x70/0x84
>> [<8061d1c8>] _raw_spin_lock+0x30/0x40
>> [<804605cc>] sdhci_irq+0x24/0xa68
>> [<8006b1d4>] handle_irq_event_percpu+0x54/0x18c
>> [<8006b350>] handle_irq_event+0x44/0x64
>> [<8006e50c>] handle_fasteoi_irq+0xa0/0x170
>> [<8006a8f0>] generic_handle_irq+0x30/0x44
>> [<8000f238>] handle_IRQ+0x54/0xbc
>> [<8000864c>] gic_handle_irq+0x30/0x64
>> [<80013024>] __irq_svc+0x44/0x5c
>> [<80329bf4>] dev_vprintk_emit+0x50/0x58
>> [<80329c24>] dev_printk_emit+0x28/0x30
>> [<80329fec>] __dev_printk+0x4c/0x90
>> [<8032a180>] dev_err+0x3c/0x48
>> [<802dd4f0>] _regulator_get+0x158/0x1cc
>> [<802dd5b4>] regulator_get_optional+0x18/0x1c
>> [<80461df4>] sdhci_add_host+0x42c/0xbd8
>> [<80464820>] sdhci_esdhc_imx_probe+0x378/0x67c
>> [<8032ee88>] platform_drv_probe+0x20/0x50
>> [<8032d48c>] driver_probe_device+0x118/0x234
>> [<8032d690>] __driver_attach+0x9c/0xa0
>> [<8032b89c>] bus_for_each_dev+0x68/0x9c
>> [<8032cf44>] driver_attach+0x20/0x28
>> [<8032cbc8>] bus_add_driver+0x148/0x1f4
>> [<8032dce0>] driver_register+0x80/0x100
>> [<8032ee54>] __platform_driver_register+0x50/0x64
>> [<8084b094>] sdhci_esdhc_imx_driver_init+0x18/0x20
>> [<80008980>] do_one_initcall+0x108/0x16c
>> [<8081cca4>] kernel_init_freeable+0x10c/0x1d0
>> [<80611b28>] kernel_init+0x10/0x120
>> [<8000e9c8>] ret_from_fork+0x14/0x2c
>> irq event stamp: 805
>> hardirqs last enabled at (805): [<8061d43c>] _raw_spin_unlock_irqrestore+0x38/0x4c
>> hardirqs last disabled at (804): [<8061d2c8>] _raw_spin_lock_irqsave+0x24/0x54
>> softirqs last enabled at (570): [<8002b824>] __do_softirq+0x1c4/0x290
>> softirqs last disabled at (561): [<8002bcf4>] irq_exit+0xb4/0x10c
>>
>> other info that might help us debug this:
>> Possible unsafe locking scenario:
>>
>> CPU0
>> ----
>> lock(&(&host->lock)->rlock);
>> <Interrupt>
>> lock(&(&host->lock)->rlock);
>>
>> *** DEADLOCK ***
>>
>> 2 locks held by kworker/u2:1/33:
>> #0: (kmmcd){.+.+..}, at: [<8003db18>] process_one_work+0x128/0x468
>> #1: ((&(&host->detect)->work)){+.+...}, at: [<8003db18>] process_one_work+0x128/0x468
>>
>> stack backtrace:
>> CPU: 0 PID: 33 Comm: kworker/u2:1 Not tainted 3.13.0-rc1+ #287
>> Workqueue: kmmcd mmc_rescan
>> Backtrace:
>> [<80012160>] (dump_backtrace+0x0/0x10c) from [<80012438>] (show_stack+0x18/0x1c)
>> r6:bfad0900 r5:00000000 r4:8088ecc8 r3:bfad0900
>> [<80012420>] (show_stack+0x0/0x1c) from [<806169ec>] (dump_stack+0x84/0x9c)
>> [<80616968>] (dump_stack+0x0/0x9c) from [<806147b4>] (print_usage_bug+0x260/0x2d0)
>> r5:8076ba88 r4:80977410
>> [<80614554>] (print_usage_bug+0x0/0x2d0) from [<8005f0d0>] (mark_lock+0x1e0/0x6ac)
>> r9:8005e678 r8:00000000 r7:bfad0900 r6:00001015 r5:bfad0cd0
>> r4:00000002
>> [<8005eef0>] (mark_lock+0x0/0x6ac) from [<80060234>] (__lock_acquire+0x604/0x1cbc)
>> [<8005fc30>] (__lock_acquire+0x0/0x1cbc) from [<800620d0>] (lock_acquire+0x70/0x84)
>> [<80062060>] (lock_acquire+0x0/0x84) from [<8061d1c8>] (_raw_spin_lock+0x30/0x40)
>> r7:00000000 r6:bfb63000 r5:00000000 r4:bfb60568
>> [<8061d198>] (_raw_spin_lock+0x0/0x40) from [<8045f7f4>] (sdhci_execute_tuning+0x4c/0x710)
>> r4:bfb60000
>> [<8045f7a8>] (sdhci_execute_tuning+0x0/0x710) from [<80453454>] (mmc_sd_init_card+0x5f8/0x660)
>> [<80452e5c>] (mmc_sd_init_card+0x0/0x660) from [<80453748>] (mmc_attach_sd+0xb4/0x180)
>> r9:bf92d400 r8:8065f364 r7:00061a80 r6:bfb60000 r5:8065f358
>> r4:bfb60000
>> [<80453694>] (mmc_attach_sd+0x0/0x180) from [<8044d9f8>] (mmc_rescan+0x284/0x2f0)
>> r5:8065f358 r4:bfb602f8
>> [<8044d774>] (mmc_rescan+0x0/0x2f0) from [<8003db94>] (process_one_work+0x1a4/0x468)
>> r8:00000000 r7:bfb55eb0 r6:bf80dc00 r5:bfb602f8 r4:bfb35980
>> r3:8044d774
>> [<8003d9f0>] (process_one_work+0x0/0x468) from [<8003e850>] (worker_thread+0x118/0x3e0)
>> [<8003e738>] (worker_thread+0x0/0x3e0) from [<80044de0>] (kthread+0xd4/0xf0)
>> [<80044d0c>] (kthread+0x0/0xf0) from [<8000e9c8>] (ret_from_fork+0x14/0x2c)
>> r7:00000000 r6:00000000 r5:80044d0c r4:bfb37b40
>>
>> Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
>> Cc: Chris Ball <cjb@xxxxxxxxxx>
>> Cc: Shawn Guo <shawn.guo@xxxxxxxxxx>
>> Signed-off-by: Dong Aisheng <b29396@xxxxxxxxxxxxx>
>>
>> ---
>> It's strange that this issue did not happen on kernel 3.10.17 with the same
>> code. And looking at the code, before call spin_lock we already disable the mmc
>> controller irq, per on my understanding, the deadlock given by lockdep may not
>> be able to happen(pls fix me if wrong).
>> May the lockdep not track the specific irq disable?
>> Copy lockdep guy to comment.
>
> Any comments for it?
>
> Regards
> Dong Aisheng
>
>> ---
>> drivers/mmc/host/sdhci.c | 20 +++++++-------------
>> 1 files changed, 7 insertions(+), 13 deletions(-)
>>
>> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
>> index a104bb1..c5d5f53 100644
>> --- a/drivers/mmc/host/sdhci.c
>> +++ b/drivers/mmc/host/sdhci.c
>> @@ -1876,12 +1876,12 @@ static int sdhci_execute_tuning(struct mmc_host *mmc, u32 opcode)
>> unsigned long timeout;
>> int err = 0;
>> bool requires_tuning_nonuhs = false;
>> + unsigned long flags;
>>
>> host = mmc_priv(mmc);
>>
>> sdhci_runtime_pm_get(host);
>> - disable_irq(host->irq);
>> - spin_lock(&host->lock);
>> + spin_lock_irqsave(&host->lock, flags);
>>
>> ctrl = sdhci_readw(host, SDHCI_HOST_CONTROL2);
>>
>> @@ -1901,15 +1901,13 @@ static int sdhci_execute_tuning(struct mmc_host *mmc, u32 opcode)
>> requires_tuning_nonuhs)
>> ctrl |= SDHCI_CTRL_EXEC_TUNING;
>> else {
>> - spin_unlock(&host->lock);
>> - enable_irq(host->irq);
>> + spin_unlock_irqrestore(&host->lock, flags);
>> sdhci_runtime_pm_put(host);
>> return 0;
>> }
>>
>> if (host->ops->platform_execute_tuning) {
>> - spin_unlock(&host->lock);
>> - enable_irq(host->irq);
>> + spin_unlock_irqrestore(&host->lock, flags);
>> err = host->ops->platform_execute_tuning(host, opcode);
>> sdhci_runtime_pm_put(host);
>> return err;
>> @@ -1982,15 +1980,12 @@ static int sdhci_execute_tuning(struct mmc_host *mmc, u32 opcode)
>> host->cmd = NULL;
>> host->mrq = NULL;
>>
>> - spin_unlock(&host->lock);
>> - enable_irq(host->irq);
>> -
>> + spin_unlock_irqrestore(&host->lock, flags);
>> /* Wait for Buffer Read Ready interrupt */
>> wait_event_interruptible_timeout(host->buf_ready_int,
>> (host->tuning_done == 1),
>> msecs_to_jiffies(50));
>> - disable_irq(host->irq);
>> - spin_lock(&host->lock);
>> + spin_lock_irqsave(&host->lock, flags);
>>
>> if (!host->tuning_done) {
>> pr_info(DRIVER_NAME ": Timeout waiting for "
>> @@ -2065,8 +2060,7 @@ out:
>> err = 0;
>>
>> sdhci_clear_set_irqs(host, SDHCI_INT_DATA_AVAIL, ier);
>> - spin_unlock(&host->lock);
>> - enable_irq(host->irq);
>> + spin_unlock_irqrestore(&host->lock, flags);
>> sdhci_runtime_pm_put(host);
>>
>> return err;
>> --
>> 1.7.2.rc3
>>
>>
>>
>> _______________________________________________
>> linux-arm-kernel mailing list
>> linux-arm-kernel@xxxxxxxxxxxxxxxxxxx
>> http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
