Re: [PATCH 13/17] mtd: rawnand: cafe: Add exec_op() support

Boris Brezillon <boris.brezillon@xxxxxxxxxxxxx> · Sun, 3 May 2020 09:26:04 +0200

On Sun, 3 May 2020 09:04:49 +0200
Boris Brezillon <boris.brezillon@xxxxxxxxxxxxx> wrote:

> On Sun, 3 May 2020 08:06:10 +0200
> Lubomir Rintel <lkundrak@xxxxx> wrote:
> 
> > On Sun, May 03, 2020 at 12:34:56AM +0200, Boris Brezillon wrote:  
> > > On Sat, 2 May 2020 21:18:43 +0200
> > > Lubomir Rintel <lkundrak@xxxxx> wrote:
> > >     
> > > > On Sat, May 02, 2020 at 03:18:11PM +0200, Boris Brezillon wrote:    
> > > > > On Sat,  2 May 2020 13:14:10 +0200
> > > > > Lubomir Rintel <lkundrak@xxxxx> wrote:
> > > > >       
> > > > > > Boris Brezillon wrote:      
> > > > > > > Implementing exec_op() will help us get rid of the legacy interface and
> > > > > > > should make drivers much cleaner too.
> > > > > > > 
> > > > > > > Signed-off-by: Boris Brezillon <boris.brezillon@xxxxxxxxxxxxx>
> > > > > > > ---
> > > > > > >  drivers/mtd/nand/raw/cafe_nand.c | 137 ++++++++++++++++++++++++++++++-
> > > > > > >  1 file changed, 136 insertions(+), 1 deletion(-)
> > > > > > > 
> > > > > > > diff --git a/drivers/mtd/nand/raw/cafe_nand.c b/drivers/mtd/nand/raw/cafe_nand.c
> > > > > > > index edf65197604b..ada9c8b06a41 100644
> > > > > > > --- a/drivers/mtd/nand/raw/cafe_nand.c
> > > > > > > +++ b/drivers/mtd/nand/raw/cafe_nand.c        
> > > > > > ...
> > > > > >       
> > > > > > > +	ret = readl_poll_timeout(cafe->mmio + CAFE_NAND_IRQ, status,
> > > > > > > +				 (status & wait) == wait, 1, USEC_PER_SEC);
> > > > > > > +	if (ret)
> > > > > > > +		return ret;
> > > > > > > +
> > > > > > > +	if (ctrl1 & CAFE_NAND_DMA_CTRL_DATA_IN)        
> > > > > >                     ^^^^^^^^^^^^^^^^^^^^^^^^^^
> > > > > > s/CAFE_NAND_DMA_CTRL_DATA_IN/CAFE_NAND_CTRL1_HAS_DATA_IN/ here please.
> > > > > > 
> > > > > >       
> > > > > > > +		cafe_read_buf(chip, data_instr->ctx.data.buf.in,
> > > > > > > +			      data_instr->ctx.data.len);
> > > > > > > +
> > > > > > > +	return 0;
> > > > > > > +}        
> > > > > > ...
> > > > > > 
> > > > > > Other than that, when DMA is in use, only CAFE_NAND_IRQ_DMA_DONE seem to pop
> > > > > > up in CAFE_NAND_IRQ when the command completes, not CAFE_NAND_IRQ_CMD_DONE.
> > > > > > I suppose you ought to do this or something equivalent:      
> > > > > 
> > > > > I suspect it has to do with the fact that you might have operations with
> > > > > DATA_IN() instructions only. I pushed an alternate fix [1] to my branch.
> > > > > Would you mind testing it?      
> > > > 
> > > > That sounded plausible, but it doesn't seem to be to be the case. With
> > > > the patch the operations doing DMA transfers still seem to time out (the
> > > > identification succeeded, because at that point DMA is turned off):
> > > > 
> > > >    CAFÉ NAND 0000:00:0c.0: enabling device (0000 -> 0002)
> > > >    nand: device found, Manufacturer ID: 0xad, Chip ID: 0xdc
> > > >    nand: Hynix NAND 512MiB 3,3V 8-bit
> > > >    nand: 512 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
> > > >    nand: 2 chips detected
> > > >    Bad block table not found for chip 0
> > > >    Bad block table not found for chip 0
> > > >    Scanning device for bad blocks
> > > >    nand_bbt: error while erasing BBT block -5
> > > >    nand_bbt: error -30 while marking block 8191 bad
> > > >    nand_bbt: error while erasing BBT block -5
> > > >    nand_bbt: error -30 while marking block 8190 bad
> > > >    nand_bbt: error while erasing BBT block -5
> > > >    nand_bbt: error -30 while marking block 8189 bad
> > > >    nand_bbt: error while erasing BBT block -5
> > > >    nand_bbt: error -30 while marking block 8188 bad
> > > >    No space left to write bad block table
> > > >    nand_bbt: error while writing bad block table -28
> > > > 
> > > > I've done this on top of your branch:
> > > > 
> > > > diff --git a/drivers/mtd/nand/raw/cafe_nand.c b/drivers/mtd/nand/raw/cafe_nand.c
> > > > index 761d103e438f..2a769033392e 100644
> > > > --- a/drivers/mtd/nand/raw/cafe_nand.c
> > > > +++ b/drivers/mtd/nand/raw/cafe_nand.c
> > > > @@ -642,6 +642,11 @@ static int cafe_nand_exec_subop(struct nand_chip *chip,
> > > >  
> > > >         ret = readl_poll_timeout(cafe->mmio + CAFE_NAND_IRQ, status,
> > > >                                  (status & wait) == wait, 1, USEC_PER_SEC);
> > > > +       for (i = 0; i < subop->ninstrs; i++) {
> > > > +               const struct nand_op_instr *instr = &subop->instrs[i];
> > > > +               printk("%d: ret=%d instr=%d status=%08x wait=%08x\n", i, ret, instr->type, status, wait);
> > > > +       }
> > > > +
> > > >         if (ret)
> > > >                 return ret;
> > > > 
> > > > It indeed looks like CAFE_NAND_IRQ_CMD_DONE is never raised if there's a
> > > > data operation involving DMA -- the status remains at 0x50000000. Full log:    
> > > 
> > > I see. The reason I was not entirely happy with the "wait on DMA_DONE
> > > when there's a DMA transfer" is because this transfer might not be the
> > > last instruction in a sub operation, and I feared we would not wait for
> > > the full operation to be done but only the DMA transfer itself. So I
> > > went back to the spec [1], and there's an interesting note page 38:
> > > 
> > > "
> > > Software waits for <dma_done> field in the Interrupt Register (Table 91
> > > p. 93) for read operation because DMA is the last step of read
> > > operation and waits for <cmd_done>field in the Interrupt Register
> > > (Table 91 p. 93) for write operation because Command execution is the
> > > last step of write operation.
> > > "
> > > 
> > > I just pushed a new fixup commit implementing this logic. Let me know
> > > if that solves the problem.    
> > 
> > Hmm, it now fails differently. With the same debugging statements as
> > above, instructions with NAND_OP_WAITRDY_INSTR and NAND_OP_DATA_IN_INSTR
> > ops end up with CAFE_NAND_IRQ_CMD_DONE (without
> > CAFE_NAND_IRQ_FLASH_RDY):
> > 
> > [    5.437591] 0: ret=-110 instr=4 status=80000000 wait=50000000
> > [    5.445514] 1: ret=-110 instr=2 status=80000000 wait=50000000
> > 
> > The log is now very different from before, there seem to be a lot more
> > insns invoked:
> > 
> > ...
> > [    2.015391] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x6362d8c130, max_idle_ns: 440795220004 ns
> > [    2.074923] CAF\xc3\x89 NAND 0000:00:0c.0: enabling device (0000 -> 0002)
> > [    2.106786] clocksource: Switched to clocksource tsc
> > [    2.143222] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.176055] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.208819] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.241588] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.274412] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.306431] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.337051] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.366696] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.395349] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.422788] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.448970] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.474571] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.498998] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.522198] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.544605] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.566084] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.586146] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.604824] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.622112] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.638020] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.652530] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.665652] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.677746] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.688759] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.698397] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.706697] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.713983] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.720317] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.725773] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.731212] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.736669] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.742105] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.747561] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.752997] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.758457] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.763892] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.769347] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.774808] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.780244] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.785703] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.791139] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.796596] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.802030] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.807491] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.812925] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.818385] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.823818] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.829275] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.834733] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.840163] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.845693] 0: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    2.851150] 1: ret=0 instr=4 status=c0000000 wait=c0000000
> > [    2.856691] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.862277] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.867894] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.873482] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.879099] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.884709] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.890298] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.895912] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.901503] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.907115] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.912700] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.918355] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.923937] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.929544] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.935160] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.940752] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.946369] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.951956] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.957574] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.963165] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.968777] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.974391] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.979976] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.985591] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.991181] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    2.996797] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.002360] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.007897] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.013393] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.018857] 1: ret=0 instr=1 status=c0000000 wait=80000000
> > [    3.024361] 2: ret=0 instr=2 status=c0000000 wait=80000000
> > [    3.029896] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.035509] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.041099] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.046718] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.052303] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.057921] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.063511] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.069128] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.074738] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.080324] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.085938] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.091528] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.097143] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.102736] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.108347] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.113932] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.119545] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.125201] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.130786] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.136405] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.141992] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.147609] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.153197] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.158813] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.164425] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.170010] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.175573] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.181064] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.186580] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.192018] 1: ret=0 instr=1 status=c0000000 wait=80000000
> > [    3.197527] 2: ret=0 instr=2 status=c0000000 wait=80000000
> > [    3.203081] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.208697] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.214287] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.219900] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.225506] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.231091] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.236704] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.242286] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.247902] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.253493] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.259108] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.264723] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.270313] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.275930] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.281518] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.287134] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.292714] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.298321] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.303907] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.309519] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.315123] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.320710] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.326322] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.331905] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.337561] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.343145] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.348711] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.354199] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.359716] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.365177] 1: ret=0 instr=1 status=c0000000 wait=80000000
> > [    3.370663] 2: ret=0 instr=2 status=c0000000 wait=80000000
> > [    3.376229] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.381816] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.387432] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.393022] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.398639] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.404224] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.409841] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.415454] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.421040] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.426656] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.432246] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.437858] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.443442] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.449057] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.454670] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.460256] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.465868] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.471460] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.477075] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.482666] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.488284] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.493871] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.499489] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.505099] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.510684] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.516297] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.521828] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.527342] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.532836] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.538300] 1: ret=0 instr=1 status=c0000000 wait=80000000
> > [    3.543783] 2: ret=0 instr=2 status=c0000000 wait=80000000
> > [    3.549387] nand: device found, Manufacturer ID: 0xad, Chip ID: 0xdc
> > [    3.557013] nand: Hynix NAND 512MiB 3,3V 8-bit
> > [    3.563159] nand: 512 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
> > [    3.574263] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.584103] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.593947] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.603781] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.613618] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.623455] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.633290] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.643128] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.652961] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.662801] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.672638] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.682474] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.692319] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.702154] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.711991] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.721828] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.731649] random: fast init done
> > [    3.739815] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.751384] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.762995] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.774571] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.786136] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.797705] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.809224] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.820693] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.831147] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.840734] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.849203] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.856386] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.863549] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.870739] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.877929] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.885115] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.892279] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.899469] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.906654] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.913812] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.920998] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.928191] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.935381] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.942541] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.949727] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.956917] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.964080] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.970442] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.975902] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.981335] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.986797] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.992228] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    3.997691] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.003124] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.008639] 0: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    4.014093] 1: ret=0 instr=4 status=c0000000 wait=c0000000
> > [    4.019634] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.025249] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.030836] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.036454] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.042041] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.047659] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.053248] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.058863] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.064475] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.070065] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.075678] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.081269] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.086879] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.092464] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.098075] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.103660] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.109276] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.114889] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.120472] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.126089] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.131676] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.137294] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.142882] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.148501] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.154087] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.159705] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.165290] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.170798] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.176360] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.181800] 1: ret=0 instr=1 status=c0000000 wait=80000000
> > [    4.187310] 2: ret=0 instr=2 status=c0000000 wait=80000000
> > [    4.192841] nand: 2 chips detected
> > [    4.196736] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.204000] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.211291] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.218580] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.225864] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.233132] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.240420] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.247706] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.254993] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.262259] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.269546] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.276834] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.284098] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.291383] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.298675] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.305961] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.313225] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.320513] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.327803] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.335095] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.342362] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.349651] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.356940] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.364212] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.371505] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.378744] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.385967] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.392267] 0: ret=0 instr=0 status=c0000000 wait=80000000
> > [    4.397788] 0: ret=0 instr=0 status=d0000000 wait=10000000
> > [    4.403274] 1: ret=0 instr=1 status=d0000000 wait=10000000
> > [    4.408832] 2: ret=0 instr=2 status=d0000000 wait=10000000
> > [    4.414591] 0: ret=0 instr=0 status=d0000000 wait=c0000000
> > [    4.420248] 1: ret=0 instr=1 status=d0000000 wait=c0000000
> > [    4.425982] 2: ret=0 instr=0 status=d0000000 wait=c0000000
> > [    4.431732] 3: ret=0 instr=4 status=d0000000 wait=c0000000
> > [    5.100219] random: crng init done
> > [    5.437591] 0: ret=-110 instr=4 status=80000000 wait=50000000
> > [    5.445514] 1: ret=-110 instr=2 status=80000000 wait=50000000
> > [    5.453530] 0: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    5.461864] 1: ret=0 instr=1 status=c0000000 wait=c0000000
> > [    5.470250] 2: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    5.478688] 3: ret=0 instr=4 status=c0000000 wait=c0000000
> > [    6.487183] 0: ret=-110 instr=4 status=80000000 wait=50000000
> > [    6.496679] 1: ret=-110 instr=2 status=80000000 wait=50000000
> > [    6.506283] 0: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    6.516185] 1: ret=0 instr=1 status=c0000000 wait=c0000000
> > [    6.526139] 2: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    6.536148] 3: ret=0 instr=4 status=c0000000 wait=c0000000
> > [    7.546203] 0: ret=-110 instr=4 status=80000000 wait=50000000
> > [    7.557261] 1: ret=-110 instr=2 status=80000000 wait=50000000
> > [    7.568434] 0: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    7.579909] 1: ret=0 instr=1 status=c0000000 wait=c0000000
> > [    7.591429] 2: ret=0 instr=0 status=c0000000 wait=c0000000
> > [    7.602996] 3: ret=0 instr=4 status=c0000000 wait=c0000000
> > [    8.614662] 0: ret=-110 instr=4 status=80000000 wait=50000000
> > [    8.627294] 1: ret=-110 instr=2 status=80000000 wait=50000000
> > [    8.639917] Bad block table not found for chip 0
> > ...
> > 
> > I'm happy to test another patch, or add more tracing (I'm not at all
> > familiar with NAND flashes or MTD for that matter, so I have little idea
> > what to look for).  
> 
> I pushed a new version with extended traces. That should tell us what
> those operations.

I pushed a new branch [1] containing only the cafe NAND changes (I fear
one of my other change in the nand/exec-op-conversion branch generates a
lot more operations that we should have).

[1]https://github.com/bbrezillon/linux/tree/nand/cafe-nand-exec-op-debug

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/