Repeatedly aborting and restarting streaming transfers from flash loses data

MichaelBell commented

2021-02-11 18:20:15 -06:00

(Migrated from github.com)

I was trying out the flash data streaming functionality as used in the example here: https://github.com/raspberrypi/pico-examples/blob/master/flash/xip_stream

I found that if I start then repeatedly abort and restart the streaming transfer, then the third transfer loses the first word that should be transferred.

Project that reproduces the problem here: https://github.com/MichaelBell/pico-projects/tree/master/flashtest

Adding a 1us sleep after aborting the streaming transfer fixes the problem.

I was trying out the flash data streaming functionality as used in the example here: https://github.com/raspberrypi/pico-examples/blob/master/flash/xip_stream I found that if I start then repeatedly abort and restart the streaming transfer, then the third transfer loses the first word that should be transferred. Project that reproduces the problem here: https://github.com/MichaelBell/pico-projects/tree/master/flashtest Adding a 1us sleep after aborting the streaming transfer fixes the problem.

MichaelBell commented

2021-02-11 18:34:38 -06:00

(Migrated from github.com)

As requested by @Wren6991 I've added a binary that reproduces the problem here: https://github.com/MichaelBell/pico-projects/raw/master/flashtest/flashtest.bin

Wren6991 commented

2021-02-12 08:42:27 -06:00

(Migrated from github.com)

Thanks, your repro does hit the breakpoint in the sim. Will try to dig in now and understand what's happening.

Wren6991 commented

2021-02-12 09:06:40 -06:00

(Migrated from github.com)

I think I understand what is happening. Following a stream abort, your code is sometimes able to setup a new DMA transfer, and start a new stream, before the last QSPI access from the aborted stream completes. There is some logic to handle this case, and it correctly marks that transfer as dirty, suppressing the FIFO write and the count decrement. However the address increment is not suppressed, so the addresses of your stream are offset by 1 word once your stream starts. This is a hardware bug.

Wren6991 commented

2021-02-12 09:08:26 -06:00

(Migrated from github.com)

Will have a look around and see if there is some state to poll to fence off on the last transfer following an abort (replacing your 1us delay) -- the SSI BUSY flag should get you within a few cycles.

Once we've found a good workaround, I'll add an errata entry to the datasheet, and we can look at updating the software and other docs.

Will have a look around and see if there is some state to poll to fence off on the last transfer following an abort (replacing your 1us delay) -- the SSI BUSY flag should get you within a few cycles. Once we've found a good workaround, I'll add an errata entry to the datasheet, and we can look at updating the software and other docs.

👍 2

Wren6991 commented

2021-02-12 10:02:19 -06:00

(Migrated from github.com)

Took me a while to chase everything through -- the SSI BUSY flag doesn't have quite the right timing internally, but the QSPI transfer in progress creates a bus stall when you poll the flag, that should delay sampling to the correct point.

Do you still see the same behaviour if you insert this polling:

    while (ssi_hw->sr & SSI_SR_BUSY_BITS)
        ;

Following your clearing of the the stream counter?

Took me a while to chase everything through -- the SSI BUSY flag doesn't have quite the right timing internally, but the QSPI transfer in progress creates a bus stall when you poll the flag, that should delay sampling to the correct point. Do you still see the same behaviour if you insert this polling: ``` while (ssi_hw->sr & SSI_SR_BUSY_BITS) ; ``` Following your clearing of the the stream counter?

Wren6991 commented

2021-02-12 10:08:31 -06:00

(Migrated from github.com)

Alternatively you should actually be able to do a dummy read of any SSI register and make use of the bus stall

    (void)ssi_hw->sr;

Alternatively you should actually be able to do a dummy read of _any_ SSI register and make use of the bus stall ``` (void)ssi_hw->sr; ```

MichaelBell commented

2021-02-12 11:37:47 -06:00

(Migrated from github.com)

My test works with the first option. Woohoo!

The second option just locks up and leaves the pico in a state where I can't reprogram over SWD :-( It says things like:

target halted due to debug-request, current mode: Thread
xPSR: 0x01000000 pc: 0x00000178 msp: 0x20041f00
Error: timed out while waiting for target halted
target halted due to debug-request, current mode: Thread
xPSR: 0x01000000 pc: 0x00000178 msp: 0x20041f00
Error: Failed to invoke ROM function EX (@00002659)

Error: RP2040 erase: failed to exit flash XIP mode
Error: failed erasing sectors 0 to 6
** Programming Failed **

Reset with BOOTSEL held lets me get back to a good state though, so that's OK!

My test works with the first option. Woohoo! The second option just locks up and leaves the pico in a state where I can't reprogram over SWD :-( It says things like: ``` target halted due to debug-request, current mode: Thread xPSR: 0x01000000 pc: 0x00000178 msp: 0x20041f00 Error: timed out while waiting for target halted target halted due to debug-request, current mode: Thread xPSR: 0x01000000 pc: 0x00000178 msp: 0x20041f00 Error: Failed to invoke ROM function EX (@00002659) Error: RP2040 erase: failed to exit flash XIP mode Error: failed erasing sectors 0 to 6 ** Programming Failed ** ``` Reset with BOOTSEL held lets me get back to a good state though, so that's OK!

Wren6991 commented

2021-02-12 11:49:18 -06:00

(Migrated from github.com)

That's interesting, I'll dig in further on Monday to make sure my understanding is complete. Glad to hear the first option works, but want to understand the issue fully before adding the errata entry to the datasheet.

kilograham commented

2021-02-12 12:20:36 -06:00

(Migrated from github.com)

yeah, i'm pretty sure the first option is still a bit broken... it seems to lock up if i start mixing printfs to display progress every 65536 iterations

MichaelBell commented

2021-02-12 13:43:05 -06:00

(Migrated from github.com)

I updated the flashtest.bin file in my repo with the "workaround 2" version that locks everything up, hopefully that's useful to you.

I am also seeing things stop working in my actual use case with the workaround in, but had assumed that the problem was now in my code - haven't debugged into that to check yet.

I updated the flashtest.bin file in my repo with the "workaround 2" version that locks everything up, hopefully that's useful to you. I am also seeing things stop working in my actual use case with the workaround in, but had assumed that the problem was now in my code - haven't debugged into that to check yet.

Wren6991 commented

2021-02-15 08:31:32 -06:00

(Migrated from github.com)

Thanks, I am able to reproduce with the binary you provided, but don't see the same behaviour when I build your source with my local GCC 9 (I get slightly different timing of the dummy read). Adding this immediately after the counter clear (rather than trying to access an SSI register) results in correct DMA data:

(void)*(io_rw_32*)XIP_NOCACHE_NOALLOC_BASE;

i.e. do a dummy XIP read to flush out any in-progress stream XIP read.

My local build does still trip the breakpoint with this fix in place, but I see the DMA transferring the correct data. The processor only seems to access the DMA buffer once, before any DMA transfers actually take place, and then later only checks a stack variable (presumably uint32_t buff[4]; in your code), so that seems like the compiler trying to optimise things out.

Thanks, I am able to reproduce with the binary you provided, but don't see the same behaviour when I build your source with my local GCC 9 (I get slightly different timing of the dummy read). Adding this immediately after the counter clear (rather than trying to access an SSI register) results in correct DMA data: ``` (void)*(io_rw_32*)XIP_NOCACHE_NOALLOC_BASE; ``` i.e. do a dummy XIP read to flush out any in-progress stream XIP read. My local build does still trip the breakpoint with this fix in place, but I see the DMA transferring the correct data. The processor only seems to access the DMA buffer once, before any DMA transfers actually take place, and then later only checks a stack variable (presumably `uint32_t buff[4];` in your code), so that seems like the compiler trying to optimise things out.

Wren6991 commented

2021-02-15 08:46:28 -06:00

(Migrated from github.com)

Yep so changing the flash abort to this

void flash_stop_dma()
{
  if (dma_channel_is_busy(flash_dma_chan)) {
    xip_ctrl_hw->stream_ctr = 0;
    (void)*(io_rw_32*)XIP_NOCACHE_NOALLOC_BASE;
    dma_channel_abort(flash_dma_chan);
  }
}

And putting a "here be dragons" for the compiler so it doesn't try to think too hard about the DMA dataflow

      // Copy out the beginning of the buffer being DMA'd into 
      asm volatile ("" ::: "memory");
      memcpy(buff, flash_read_buffer, 16);

Means this seems to work reliably for me now

Yep so changing the flash abort to this ``` void flash_stop_dma() { if (dma_channel_is_busy(flash_dma_chan)) { xip_ctrl_hw->stream_ctr = 0; (void)*(io_rw_32*)XIP_NOCACHE_NOALLOC_BASE; dma_channel_abort(flash_dma_chan); } } ``` And putting a "here be dragons" for the compiler so it doesn't try to think too hard about the DMA dataflow ``` // Copy out the beginning of the buffer being DMA'd into asm volatile ("" ::: "memory"); memcpy(buff, flash_read_buffer, 16); ``` Means this seems to work reliably for me now

👍 2

MichaelBell commented

2021-02-15 14:32:19 -06:00

(Migrated from github.com)

That suggestion is working reliably for me too. Thank you!

🎉 1

Wren6991 commented

2021-02-16 06:25:31 -06:00

(Migrated from github.com)

Thanks, this is now listed in a datasheet errata entry, will appear in the next docs release

Rows
Columns

Repeatedly aborting and restarting streaming transfers from flash loses data #122