Re: GPMI iMX6ull timeout on DMA

Greg Ungerer
2019-08-12T02:51:48Z

Hi Boris,

On 9/8/19 11:59 pm, Boris Brezillon wrote:
> On Fri, 9 Aug 2019 23:57:08 +1000
> Greg Ungerer <gerg@kernel.org> wrote:
>> On 9/8/19 5:32 pm, Boris Brezillon wrote:
>>> On Fri, 9 Aug 2019 16:55:22 +1000
>>> Greg Ungerer <gerg@kernel.org> wrote:
>>>> On 9/8/19 4:23 pm, Boris Brezillon wrote:
>>>>> On Fri, 9 Aug 2019 15:20:52 +1000
>>>>> Greg Ungerer <gerg@kernel.org> wrote:
>>>>>> On 9/8/19 2:36 am, Boris Brezillon wrote:
>>>>>>> On Mon, 5 Aug 2019 15:51:05 +1000
>>>>>>> Greg Ungerer <gerg@kernel.org> wrote:
>>>>>>>> On 2/8/19 10:51 pm, Boris Brezillon wrote:
>>>>>>>>> On Fri, 2 Aug 2019 22:34:57 +1000
>>>>>>>>> Greg Ungerer <gerg@kernel.org> wrote:
>>>>>>>>>> On 31/7/19 4:28 pm, Boris Brezillon wrote:
>>>>>>>>>>> On Wed, 31 Jul 2019 12:05:44 +1000
>>>>>>>>>>> Greg Ungerer <gerg@kernel.org> wrote:
>>>>>>>>>>>> On 30/7/19 6:38 pm, Miquel Raynal wrote:
>>>>>>>>>>>>> Greg Ungerer <gerg@kernel.org> wrote on Tue, 30 Jul 2019 16:06:55 +1000:
>>>>>>>>>>>>>> On 30/7/19 10:41 am, Greg Ungerer wrote:
>>>>>>>>>>>>>>> On 30/7/19 10:28 am, Greg Ungerer wrote:
>>>>>>>>>>>>>>>> On 29/7/19 10:47 pm, Miquel Raynal wrote:
>>>>>>>>>>>>>>>>> Greg Ungerer <gerg@kernel.org> wrote on Mon, 29 Jul 2019 22:33:56 +1000:
>>>>>>>>>>>>>>>>>> On 29/7/19 6:36 pm, Miquel Raynal wrote:
>>>>>>>>>>>>>>>>>>> Greg Ungerer <gerg@kernel.org> wrote on Mon, 29 Jul 2019 16:41:51 +1000:
>>>>>>>>>>>>>>> [snip]
>>>>>>>>>>>> Note that this was generated on a normal boot up (not failure).
>>>>>>>>>>>
>>>>>>>>>>> The values looks good. Can you try with the below diff applied?
>>>>>>>>>>> --->8---
>>>>>>>>>>> diff --git a/drivers/mtd/nand/raw/gpmi-nand/gpmi-nand.c b/drivers/mtd/nand/raw/gpmi-nand/gpmi-nand.c
>>>>>>>>>>> index 334fe3130285..9771f6a82abe 100644
>>>>>>>>>>> --- a/drivers/mtd/nand/raw/gpmi-nand/gpmi-nand.c
>>>>>>>>>>> +++ b/drivers/mtd/nand/raw/gpmi-nand/gpmi-nand.c
>>>>>>>>>>> @@ -721,12 +721,10 @@ static void gpmi_nfc_apply_timings(struct gpmi_nand_data *this)
>>>>>>>>>>> writel(hw->ctrl1n, gpmi_regs + HW_GPMI_CTRL1_SET);
>>>>>>>>>>>
>>>>>>>>>>> /* Wait 64 clock cycles before using the GPMI after enabling the DLL */
>>>>>>>>>>> - dll_wait_time_us = USEC_PER_SEC / hw->clk_rate * 64;
>>>>>>>>>>> - if (!dll_wait_time_us)
>>>>>>>>>>> - dll_wait_time_us = 1;
>>>>>>>>>>> + dll_wait_time_us = DIV_ROUND_UP(USEC_PER_SEC * 64, hw->clk_rate);
>>>>>>>>>>>
>>>>>>>>>>> /* Wait for the DLL to settle. */
>>>>>>>>>>> - udelay(dll_wait_time_us);
>>>>>>>>>>> + usleep_range(dll_wait_time_us, dll_wait_time_us * 10);
>>>>>>>>>>> }
>>>>>>>>>>>
>>>>>>>>>>> static int gpmi_setup_data_interface(struct nand_chip *chip, int chipnr,
>>>>>>>>>>
>>>>>>>>>> Eventually it failed, in the same way with with same errors.
>>>>>>>>>> Took quite a while, over 600 boot cycles.
>>>>>>>>>>
>>>>>>>>>> Note also that I had to hand merge the changes, since in 5.1.14 that
>>>>>>>>>> gpmi_nfc_apply_timings() is in gpmi-lib.c. But it was trivial to do.
>>>>>>>>>
>>>>>>>>> Oh well. I guess the next thing to do would be to dump the timing regs
>>>>>>>>> and clk rate that are set by the bootloader (before the driver override
>>>>>>>>> them) or those applied by an older kernel (one that didn't have that
>>>>>>>>> issue).
>>>>>>>>
>>>>>>>> Is this useful?
>>>>>>>
>>>>>>> Hm, looks like it's configured in mode 0, so no, it's not super useful.
>>>>>>> Can you try booting an older kernel (one that didn't have the
>>>>>>> ->setup_data_interface() hook implemented).
>>>>>>
>>>>>> Ok. I went back from 5.1 and the first kernel I could find that
>>>>>> returned no grep hits for "setup_data_interface" was 4.16.
>>>>>>
>>>>>> So I built for my target with that and added similar trace to dump
>>>>>> the hardware register settings for that. Debug output looks like
>>>>>> this now for it:
>>>>>>
>>>>>> ...
>>>>>> drivers/mtd/nand/gpmi-nand/gpmi-nand.c(807): gpmi_get_clks()
>>>>>> clk_get_rate(r->clock[0])=22000000
>>>>>> drivers/mtd/nand/gpmi-nand/gpmi-lib.c(1054): gpmi_begin()
>>>>>> HW_GPMI_TIMING0=0x00010203
>>>>>> HW_GPMI_TIMING1=0x05000000
>>>>>> nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xda
>>>>>> nand: Micron MT29F2G08ABAEAWP
>>>>>> nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
>>>>>> drivers/mtd/nand/gpmi-nand/gpmi-lib.c(966): enable_edo_mode()
>>>>>> clk_get_rate(r->clock[0])=99000000
>>>>>> gpmi-nand 1806000.gpmi-nand: enable the asynchronous EDO mode 5
>>>>>> drivers/mtd/nand/gpmi-nand/gpmi-lib.c(1054): gpmi_begin()
>>>>>> HW_GPMI_TIMING0=0x00010101
>>>>>
>>>>> TIMING0 match the one you have with 5.1 kernels.
>>>>>
>>>>>> HW_GPMI_TIMING1=0x90000000
>>>>>
>>>>> And we even have a bigger timeout value in 5.1 (0xe0000000), so we
>>>>> should be all safe WRT to timings in TIMING{0,1}.
>>>>>
>>>>> Can you dump CTRL1?
>>>>
>>>> drivers/mtd/nand/gpmi-nand/gpmi-lib.c(1054): gpmi_begin()
>>>> HW_GPMI_TIMING0=0x00010101
>>>> HW_GPMI_TIMING1=0x90000000
>>>> HW_GPMI_CTRL1_SET=0x01c4800c
>>>
>>> The read/write delay fields seem to match, but there are a few more
>>> fields set in this version:
>>> - DECOUPLE_CS
>>> - BCH_MODE
>>> - DEV_RESET
>>> - CTRL1_ATA_IRQRDY_POLARITY__ACTIVEHIGH
>>>
>>> Looks like those fields are not explicitly set in the gpmi_begin()
>>> patch, but maybe you dumped CTRL1. Would you mind sharing your patch?
>>
>> Attached.
>
> Hm, you should read CTRL1 instead of CTRL1_SET which I guess is WO.

Here is 2 sets of trace dumping the same set of registers.
This first is on the linux-4.16 kernel:

Linux version 4.16.0 (gerg@goober) (gcc version 4.8.3 (GCC)) #9 Mon Aug 12 10:46:25 AEST 2019
...
nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xda
nand: Micron MT29F2G08ABAEAWP
nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
gpmi-nand 1806000.gpmi-nand: use legacy bch geometry
gpmi-nand 1806000.gpmi-nand: enable the asynchronous EDO mode 5
drivers/mtd/nand/gpmi-nand/gpmi-lib.c(1110): gpmi_begin()
HW_GPMI_TIMING0=0x00010101
HW_GPMI_TIMING1=0x90000000
HW_GPMI_CTRL1=0x01c6800c
r->clock[0]=99000000
Scanning device for bad blocks
5 ofpart partitions found on MTD device gpmi-nand
Creating 5 MTD partitions on "gpmi-nand":
0x000000000000-0x000000500000 : "u-boot"
0x000000500000-0x000000600000 : "u-boot-env"
0x000000600000-0x000000800000 : "log"
0x000000800000-0x000010000000 : "flash"
0x000000000000-0x000010000000 : "all"
gpmi-nand 1806000.gpmi-nand: driver registered.
...

And then this is from the 5.1.14 kernel:

Linux version 5.1.14 (gerg@goober) (gcc version 4.8.3 (GCC)) #25 Mon Aug 12 10:49:21 AEST 2019
...
nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xda
nand: Micron MT29F2G08ABAEAWP
nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
drivers/mtd/nand/raw/gpmi-nand/gpmi-lib.c(510): gpmi_nfc_apply_timings()
HW_GPMI_TIMING0=0x00020101
HW_GPMI_TIMING1=0xb0000000
HW_GPMI_CTRL1=0x0104000c
r->clock[0]=22000000
drivers/mtd/nand/raw/gpmi-nand/gpmi-lib.c(510): gpmi_nfc_apply_timings()
HW_GPMI_TIMING0=0x00010101
HW_GPMI_TIMING1=0xe0000000
HW_GPMI_CTRL1=0x01c6800c
r->clock[0]=99000000
Scanning device for bad blocks
5 fixed-partitions partitions found on MTD device gpmi-nand
Creating 5 MTD partitions on "gpmi-nand":
0x000000000000-0x000000500000 : "u-boot"
0x000000500000-0x000000600000 : "u-boot-env"
0x000000600000-0x000000800000 : "log"
0x000000800000-0x000010000000 : "flash"
0x000000000000-0x000010000000 : "all"
gpmi-nand 1806000.gpmi-nand: driver registered.

Register settings read back from the registers themselves at the end
of the respective setting routines (so gpmi_begin() for 4.16 and
gpmi_nfc_apply_timings() for 5.1.14)

So something I notice here is that gpmi_nfc_apply_timings() is
being run multiple times. When I look back to the original
failure dumps the first error ("DMA timeout, last DMA") occurred
after the device type messages ("nand: 256 MiB, SLC,..."). Is it
happening with that higher clock rate still set?

Regards
Greg