From patchwork Wed Jul 27 08:23:31 2011 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Guennadi Liakhovetski X-Patchwork-Id: 1010962 Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by demeter2.kernel.org (8.14.4/8.14.4) with ESMTP id p6R8Nf53024154 for ; Wed, 27 Jul 2011 08:23:41 GMT Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752900Ab1G0IXk (ORCPT ); Wed, 27 Jul 2011 04:23:40 -0400 Received: from moutng.kundenserver.de ([212.227.17.9]:51399 "EHLO moutng.kundenserver.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752252Ab1G0IXh (ORCPT ); Wed, 27 Jul 2011 04:23:37 -0400 Received: from axis700.grange (dslb-178-001-227-093.pools.arcor-ip.net [178.1.227.93]) by mrelayeu.kundenserver.de (node=mreu4) with ESMTP (Nemesis) id 0LbCQQ-1R9Wak0l7y-00kvS9; Wed, 27 Jul 2011 10:23:32 +0200 Received: by axis700.grange (Postfix, from userid 1000) id A1EEA189B6E; Wed, 27 Jul 2011 10:23:31 +0200 (CEST) Received: from localhost (localhost [127.0.0.1]) by axis700.grange (Postfix) with ESMTP id 9A0B3189B6D; Wed, 27 Jul 2011 10:23:31 +0200 (CEST) Date: Wed, 27 Jul 2011 10:23:31 +0200 (CEST) From: Guennadi Liakhovetski X-X-Sender: lyakh@axis700.grange To: Yoshii Takashi cc: linux-sh@vger.kernel.org, linux-mmc@vger.kernel.org Subject: Re: shdma: (or tmio_mmc?) inconsistent lock state detected on ag5evm In-Reply-To: <4E2D3733.6080607@renesas.com> Message-ID: References: <4E2D3733.6080607@renesas.com> MIME-Version: 1.0 X-Provags-ID: V02:K0:byzR89eqlbK71T2/MmDTn124P1fYLiuvqklKFqJsfH4 7Vwiz7M/x1L+K3psM8s6KSoYS3029inv3MP01SmYtdBHd8G+GW 1pE7puLo9UasZQJ56Mgin2dM9/Cuc3WLVxdeNqzsV3JP7bzf59 +4vw69O/GrVh6qlNBvRd/dmD9+gLu1VeM2F0dOtXzDdSzmUv80 J0TNOVPYfF9xUUmAi20QrIQTshh7kUFEB8q7YV956c= Sender: linux-sh-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-sh@vger.kernel.org X-Greylist: IP, sender and recipient auto-whitelisted, not delayed by milter-greylist-4.2.6 (demeter2.kernel.org [140.211.167.43]); Wed, 27 Jul 2011 08:23:41 +0000 (UTC) Hello Yoshii-san On Mon, 25 Jul 2011, Yoshii Takashi wrote: > Hello, Guennadi. > This was started as an evaluation of your patch > [PATCH v2] mmc: tmio: fix recursive spinlock, don't schedule with interrupts disabled > But now I don't know where exactly the issue is. So, let me begin new thread. > > On ag5evm(the board under arch/arm/mach-shmobile, that is SMP), both > tag v3.0 + patch above, and > tag v3.0 + cjb/mmc-next > with CONFIG_PROVE_LOCKING=y, inconsistent lock state is detected as text attached at > the bottom. > Function itself(mount/read/write/umount) seems working without problem, so far. > > As it happens on the spinlock at sh_dmae_interrupt(), it seems to have been there since > 2dc66667 dmaengine: shdma: fix locking > which introduced the lock there. Thanks for the report! It is interesting. From your backtrace it looks like the spin_lock_bh() in sh_dmae_alloc_chan_resources() gets interrupted by an interrupt on the same channel! I do not understand this, because, normally no interrupts on DMAC channels occur until data transfers begin over them. So, a simple fix would be to replace calls to spin_(un)lock_bh() with spin_(un)lock_irq() in sh_dmae_alloc_chan_resources(), but I would like to understand, what kind of interrupts are occurring at that time and why. Could you please apply the attached below debugging patch and send me the resulting complete dmesg output? Alternatively, you can choose to wait until a detailed SMP testing of the SDHI driver takes place, hopefully, in approximately a week or a bit more. Thanks Guennadi > > I found deleting the spin_lock/unlock there makes it quiet. But that lock must be the > important part of the patch. Actually, deleting it brings another locking issue on > tmio_mmc, and it confuses me. I wonder what is the correct solution. I'm afraid I can't > tell what is the critical object to be protected in shdma and tmio_mmc source code... > > Any suggestions are appreciated. > /yoshii > > ================================= > [ INFO: inconsistent lock state ] > 3.0.0-00100-g82258ef-dirty #3643 > --------------------------------- > inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. > swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes: > (&(&new_sh_chan->desc_lock)->rlock){?.-...}, at: [] sh_dmae_interrupt+0x14/0x78 > {HARDIRQ-ON-W} state was registered at: > [] __lock_acquire+0x5c4/0xbb4 > [] lock_acquire+0x60/0x74 > [] _raw_spin_lock_bh+0x3c/0x4c > [] sh_dmae_alloc_chan_resources+0x1b0/0x298 > [] dma_chan_get+0xd8/0x17c > [] __dma_request_channel+0x140/0x1e4 > [] tmio_mmc_request_dma+0x74/0x10c > [] tmio_mmc_host_probe+0x208/0x284 > [] sh_mobile_sdhi_probe+0x168/0x28c > [] platform_drv_probe+0x18/0x1c > [] driver_probe_device+0x7c/0x178 > [] __driver_attach+0x94/0x98 > [] bus_for_each_dev+0x60/0x8c > [] bus_add_driver+0xa8/0x2a4 > [] driver_register+0x78/0x18c > [] do_one_initcall+0x34/0x184 > [] kernel_init+0xa8/0x134 > [] kernel_thread_exit+0x0/0x8 > irq event stamp: 17556 > hardirqs last enabled at (17553): [] default_idle+0x24/0x2c > hardirqs last disabled at (17554): [] __irq_svc+0x34/0xa0 > softirqs last enabled at (17556): [] irq_enter+0x78/0x7c > softirqs last disabled at (17555): [] irq_enter+0x6c/0x7c > > other info that might help us debug this: > Possible unsafe locking scenario: > > CPU0 > ---- > lock(&(&new_sh_chan->desc_lock)->rlock); > > lock(&(&new_sh_chan->desc_lock)->rlock); > > *** DEADLOCK *** > > no locks held by swapper/0. > > stack backtrace: > [] (unwind_backtrace+0x0/0xfc) from [] (print_usage_bug+0x21c/0x2bc) > [] (print_usage_bug+0x21c/0x2bc) from [] (mark_lock+0x510/0x740) > [] (mark_lock+0x510/0x740) from [] (__lock_acquire+0x638/0xbb4) > [] (__lock_acquire+0x638/0xbb4) from [] (lock_acquire+0x60/0x74) > [] (lock_acquire+0x60/0x74) from [] (_raw_spin_lock+0x34/0x44) > [] (_raw_spin_lock+0x34/0x44) from [] (sh_dmae_interrupt+0x14/0x78) > [] (sh_dmae_interrupt+0x14/0x78) from [] (handle_irq_event_percpu+0x54/0x184) > [] (handle_irq_event_percpu+0x54/0x184) from [] (handle_irq_event+0x3c/0x5c) > [] (handle_irq_event+0x3c/0x5c) from [] (handle_fasteoi_irq+0x9c/0x104) > [] (handle_fasteoi_irq+0x9c/0x104) from [] (generic_handle_irq+0x28/0x30) > [] (generic_handle_irq+0x28/0x30) from [] (asm_do_IRQ+0x58/0xb8) > [] (asm_do_IRQ+0x58/0xb8) from [] (shmobile_handle_irq_gic+0xc/0x80) > Exception stack(0xc0951f70 to 0xc0951fb8) > 1f60: 00000001 00004491 00000000 c0951fa8 > 1f80: c0950000 c0977604 c088f9c4 c0955b40 4000406a 412fc098 00000000 00000000 > 1fa0: 00000001 c0951fb8 00004490 c063a650 20000013 ffffffff > [] (shmobile_handle_irq_gic+0xc/0x80) from [<00004491>] (0x4491) > mmc0: new high speed SD card at address b368 > mmcblk0: mmc0:b368 SDC 489 MiB > mmcblk0: p1 > --- Guennadi Liakhovetski, Ph.D. Freelance Open-Source Software Developer http://www.open-technology.de/ -- To unsubscribe from this list: send the line "unsubscribe linux-sh" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html diff --git a/drivers/dma/shdma.c b/drivers/dma/shdma.c index 0283300..2c6dde6 100644 --- a/drivers/dma/shdma.c +++ b/drivers/dma/shdma.c @@ -848,6 +848,10 @@ static irqreturn_t sh_dmae_interrupt(int irq, void *data) chcr = sh_dmae_readl(sh_chan, CHCR); + if (list_empty(&sh_chan->ld_queue)) + dev_warn(sh_chan->dev, "Spurious interrupt 0x%x on %s\n", + chcr, dma_chan_name(&sh_chan->common)); + if (chcr & CHCR_TE) { /* DMA stop */ dmae_halt(sh_chan);