Re: [PATCH 1/3] ata: sata_dwc_460ex: use "dmas" DT property to find dma channel

["Måns Rullgård" <mans@mansr.com>]

Julian Margetson <runaway@candw.ms> writes:

> On 12/18/2015 10:34 PM, Andy Shevchenko wrote:
>> On Sat, Dec 19, 2015 at 1:16 AM, Måns Rullgård <mans@mansr.com> wrote:
>>> Julian Margetson <runaway@candw.ms> writes:
>>>
>>>> On 12/18/2015 6:33 PM, Måns Rullgård wrote:
>>>>> Julian Margetson <runaway@candw.ms> writes:
>>>>>
>>>>>> On 12/18/2015 1:18 PM, Måns Rullgård wrote:
>>>>>>> Julian Margetson <runaway@candw.ms> writes:
>>>>>>>
>>>>>>>> On 12/18/2015 8:49 AM, Måns Rullgård wrote:
>>>>>>>>> Andy Shevchenko <andriy.shevchenko@linux.intel.com> writes:
>>>>>>>>>
>>>>>>>>>>>> [    5.206125] Unable to handle kernel paging request for data at
>>>>>>>>>>>> address 0x00000000
>>>>>>>>>>>> [    5.228546] Faulting instruction address: 0xc043a2c8
>>>>>>>>>>>> [    5.248577] Vector: 300 (Data Access) at [eddafae0]
>>>>>>>>>>>> [    5.268658]     pc: c043a2c8: sata_dwc_qc_issue+0xb8/0x204
>>>>>>>>>>> Well, that's not good.  Can you translate that address to a line of
>>>>>>>>>>> code?
>>>>>>>>>> Besides that, can you enable DYNAMIC_DEBUG in the config and append
>>>>>>>>>> 'dw_dmac_core.dyndbg dw_dmac.dyndbg' to the kernel cmdline?
>>>>>>>>> Enabling debug messages in the sata_dwc driver might also be informative.
>>>>>>>>>
>>>>>>>> Changed the sata-dwc to a module .
>>>>>>>>
>>>>>>>> [   18.475140] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>>>>>> [   18.535698] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>>>>> That's strange.  The only way that can happen is if
>>>>>>> dmaengine_prep_slave_sg() return NULL, and that really shouldn't be
>>>>>>> happening.  Did you turn on debug messages in dw_dma?  You can enable
>>>>>>> some extra debug messages by adding "#define VERBOSE_DEBUG" at the top
>>>>>>> of drivers/dma/dw/core.c
>>>>>>>
>>>>>> [   17.526173] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>>>> [   17.600124] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>>>> [   17.662978] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>>> Could you post the entire kernel log?  There might be important
>>>>> information before the errors start.
>>>>>
>>>>
>>>> =~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2015.12.18 15:01:48 =~=~=~=~=~=~=~=~=~=~=~=
>>>> [    0.000000] Using Canyonlands machine description
>>>> [    0.000000] Initializing cgroup subsys cpu
>>>> [    0.000000] Linux version 4.4.0-rc5-Sam460ex (root@julian-VirtualBox) (gcc version 4.8.2 (Ubuntu 4.8.2-16ubuntu3) ) #8 PREEMPT Fri Dec 18 13:36:34 AST 2015
>>>> [    0.000000] Zone ranges:
>>>> [    0.000000]   DMA      [mem 0x0000000000000000-0x000000002fffffff]
>>>> [    0.000000]   Normal   empty
>>>> [    0.000000]   HighMem  [mem 0x0000000030000000-0x000000007fffffff]
>>>> [    0.000000] Movable zone start for each node
>>>> [    0.000000] Early memory node ranges
>>>> [    0.000000]   node   0: [mem 0x0000000000000000-0x000000007fffffff]
>>>> [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff]
>>>> [    0.000000] MMU: Allocated 1088 bytes of context maps for 255 contexts
>>>> [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 522752
>>>> [    0.000000] Kernel command line: root=/dev/sda8 console=ttyS0,115200 console=tty0 dw_dmac_core.dyndbg dw_dmac.dyndbg
>> I would suggest to use console=tty1 instead of console=tty0.
>>
>>> [...]
>>>
>>>> [   13.643415] systemd[1]: Mounted Configuration File System.
>>>> [   17.526173] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>> [   17.600124] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>>> [   17.662978] sata-dwc 4bffd1000.sata: sata_dwc_qc_prep_by_tag: dma_dwc_xfer_setup returns NULL
>>> This log is weird.  The sata_dwc_probe() function prints several things
>>> (one using dev_notice()), for instance this:
>>>
>>>          /* Read the ID and Version Registers */
>>>          idr = in_le32(&hsdev->sata_dwc_regs->idr);
>>>          versionr = in_le32(&hsdev->sata_dwc_regs->versionr);
>>>          dev_notice(&ofdev->dev, "id %d, controller version %c.%c%c\n",
>>>                     idr, ver[0], ver[1], ver[2]);
>>>
>>> The dw_dma_probe() function also prints a line:
>>>
>>>          dev_info(chip->dev, "DesignWare DMA Controller, %d channels\n",
>>>                   pdata->nr_channels);
>>>
>>> These messages are nowhere to be seen in your log, nor are numerous
>>> others that really must appear before before sata_dwc_qc_prep_by_tag()
>>> can be called.
>>>
>> It would be better to add 'ignore_loglevel' to the cmdline as well.

OK, I've found something.  The dma setup errors are benign, caused by
the driver calling dmaengine_prep_slave_sg() even for non-dma
operations.  The real error is the lock recursion that's reported
later.  I wasn't seeing it since I was running a UP non-preempt kernel.
With lock debugging enabled, I get the same error.  This patch should
fix it.

---8<---
>From 94c4769d2171ce66079fd486a45e09dd64db62c0 Mon Sep 17 00:00:00 2001
From: Mans Rullgard <mans@mansr.com>
Date: Sat, 19 Dec 2015 15:26:23 +0000
Subject: [PATCH] ata: sata_dwc_460ex: remove incorrect locking

This lock is already taken in ata_scsi_queuecmd() a few levels up the
call stack so attempting to take it here is an error.  Moreover, it is
pointless in the first place since it only protects a single, atomic
assignment.

Signed-off-by: Mans Rullgard <mans@mansr.com>
---
 drivers/ata/sata_dwc_460ex.c | 4 +---
 1 file changed, 1 insertion(+), 3 deletions(-)

diff --git a/drivers/ata/sata_dwc_460ex.c b/drivers/ata/sata_dwc_460ex.c
index 799df86..5696f39 100644
--- a/drivers/ata/sata_dwc_460ex.c
+++ b/drivers/ata/sata_dwc_460ex.c
@@ -1001,16 +1001,14 @@ static void sata_dwc_exec_command_by_tag(struct ata_port *ap,
 					 struct ata_taskfile *tf,
 					 u8 tag, u32 cmd_issued)
 {
-	unsigned long flags;
 	struct sata_dwc_device_port *hsdevp = HSDEVP_FROM_AP(ap);
 	struct sata_dwc_device *hsdev = HSDEV_FROM_AP(ap);
 
 	dev_dbg(ap->dev, "%s cmd(0x%02x): %s tag=%d\n", __func__, tf->command,
 		ata_get_cmd_descript(tf->command), tag);
 
-	spin_lock_irqsave(&ap->host->lock, flags);
 	hsdevp->cmd_issued[tag] = cmd_issued;
-	spin_unlock_irqrestore(&ap->host->lock, flags);
+
 	/*
 	 * Clear SError before executing a new command.
 	 * sata_dwc_scr_write and read can not be used here. Clearing the PM
-- 
2.6.3

-- 
Måns Rullgård