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

[Måns Rullgård]

Julian Margetson <runaway@xxxxxxxx> 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@xxxxxxxxx> wrote:
>>> Julian Margetson <runaway@xxxxxxxx> writes:
>>>
>>>> On 12/18/2015 6:33 PM, Måns Rullgård wrote:
>>>>> Julian Margetson <runaway@xxxxxxxx> writes:
>>>>>
>>>>>> On 12/18/2015 1:18 PM, Måns Rullgård wrote:
>>>>>>> Julian Margetson <runaway@xxxxxxxx> writes:
>>>>>>>
>>>>>>>> On 12/18/2015 8:49 AM, Måns Rullgård wrote:
>>>>>>>>> Andy Shevchenko <andriy.shevchenko@xxxxxxxxxxxxxxx> 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<---