Re: GPMI iMX6ull timeout on DMA

Greg Ungerer
2019-08-12T04:04:48Z

On 12/8/19 12:50 pm, Greg Ungerer wrote:
> 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?

Looks like that is not the case...

...
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
gpmi-nand 1806000.gpmi-nand: DMA timeout, last DMA
gpmi-nand 1806000.gpmi-nand: Show GPMI registers :
gpmi-nand 1806000.gpmi-nand: offset 0x000 : 0x20830002
gpmi-nand 1806000.gpmi-nand: offset 0x010 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x020 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x030 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x040 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x050 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x060 : 0x01c6800c
gpmi-nand 1806000.gpmi-nand: offset 0x070 : 0x00010101
gpmi-nand 1806000.gpmi-nand: offset 0x080 : 0xe0000000
gpmi-nand 1806000.gpmi-nand: offset 0x090 : 0x23023336
gpmi-nand 1806000.gpmi-nand: offset 0x0a0 : 0x000001ee
gpmi-nand 1806000.gpmi-nand: offset 0x0b0 : 0xff000001
gpmi-nand 1806000.gpmi-nand: offset 0x0c0 : 0x00000100
gpmi-nand 1806000.gpmi-nand: offset 0x0d0 : 0x05020000
gpmi-nand 1806000.gpmi-nand: Show BCH registers :
gpmi-nand 1806000.gpmi-nand: offset 0x000 : 0x00000100
gpmi-nand 1806000.gpmi-nand: offset 0x010 : 0x00000010
gpmi-nand 1806000.gpmi-nand: offset 0x020 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x030 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x040 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x050 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x060 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x070 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x080 : 0x030a2080
gpmi-nand 1806000.gpmi-nand: offset 0x090 : 0x083e2080
gpmi-nand 1806000.gpmi-nand: offset 0x0a0 : 0x070a4080
gpmi-nand 1806000.gpmi-nand: offset 0x0b0 : 0x10da4080
gpmi-nand 1806000.gpmi-nand: offset 0x0c0 : 0x070a4080
gpmi-nand 1806000.gpmi-nand: offset 0x0d0 : 0x10da4080
gpmi-nand 1806000.gpmi-nand: offset 0x0e0 : 0x070a4080
gpmi-nand 1806000.gpmi-nand: offset 0x0f0 : 0x10da4080
gpmi-nand 1806000.gpmi-nand: offset 0x100 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x110 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x120 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x130 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x140 : 0x00000000
gpmi-nand 1806000.gpmi-nand: offset 0x150 : 0x20484342
gpmi-nand 1806000.gpmi-nand: offset 0x160 : 0x01000000
gpmi-nand 1806000.gpmi-nand: offset 0x170 : 0x00000000

Regards
Greg