[SPI]SPI slave in DMA mode report RX FIFO overflow after each several success xfers

fh2077 · March 16, 2021, 8:17am

Hi,

Currently we config spi0 as slave mode connect to a external devices. The external device would output frames continuously. So we try not to reset controller during each application transfer request, and try to re-enable interrupt/DMA in spi isr handle. For PIO mode, this mechanism seems work well per spitest result. But in DMA mode, the controller would continuously report RX FIFO overflow after several success RX xfer(as below log show). That cause data corruption and high error rate.
For more detail, our current test scene is external device would continuously send 512 byte frame in 10ms interval(CS Deassert). In spi-tegra124-slave interrupt isr, after data read out from dma buffer, the block value and trig value would be reprogramed to DMA_CTL, and write DMA_EN after call tegra_spi_start_rx_dma.
Questions:

Why controller would report RX FIFO overflow error sometimes while same config sequence excecuted?
Seems DMA didn’t start request somehow. Do i mis-configurate/miss some parameters?
How to further debug this issue? As i tried to enable DEBUG macro in dma driver, but no much info output.
For more log, please check attached log file. Great appreciate your comments!!

Jan 28 15:59:45 [ 102.923957] spidev spi0.0: setup 8 bpw, cpol, cpha, 50000000Hz
Jan 28 15:59:45 [ 102.924196] spidev spi0.0: setup 8 bpw, cpol, cpha, 50000000Hz
Jan 28 15:59:45 [ 102.924380] spidev spi0.0: setup 8 bpw, cpol, cpha, 8000000Hz
Jan 28 15:59:45 [ 102.924636] spi-tegra124-slave 3210000.spi: Rx len:512 bpw:8 3000us 8000000Hz, varlen: 0
Jan 28 15:59:45 [ 102.925790] spi-tegra124-slave 3210000.spi: Setting clk_src pll_p
Jan 28 15:59:45 [ 102.926252] spi-tegra124-slave 3210000.spi: The def 0x13f00000 and written 0x33f01027
Jan 28 15:59:45 [ 102.926268] spi-tegra124-slave 3210000.spi: Starting rx dma for len:512
Jan 28 15:59:45 [ 102.926316] spi_master spi0: Before DMA EN
Jan 28 15:59:45 [ 102.926343] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff0000]:BSY I:255 B:0
Jan 28 15:59:45 [ 102.926357] spi_master spi0: FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[00010000]: RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.931886] spi_master spi0: @isr
Jan 28 15:59:45 [ 102.931902] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[40ff0200]:RDY I:255 B:512
Jan 28 15:59:45 [ 102.931912] spi_master spi0: FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[00010000]: RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.931931] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::w2t: 512, is_dma: 1, bpw: 8, kfifo len: 0
Jan 28 15:59:45 [ 102.931942] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::status: 0x400005, fifo len 512
Jan 28 15:59:45 [ 102.931961] tegra-gpcdma 2600000.dma: tegra_dma_terminate_all():handling isr
Jan 28 15:59:45 [ 102.931971] tegra-gpcdma 2600000.dma: tegra_dma_stop():clearing interrupt
Jan 28 15:59:45 [ 102.931977] spi-tegra124-slave 3210000.spi: Starting rx dma for len:512
Jan 28 15:59:45 [ 102.932005] spi_master spi0: After DMA EN
Jan 28 15:59:45 [ 102.932014] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff0000]:BSY I:255 B:0
Jan 28 15:59:45 [ 102.932023] spi_master spi0: FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[80010000]:De RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.946099] spi_master spi0: @isr
Jan 28 15:59:45 [ 102.946132] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[40ff0200]:RDY I:255 B:512
Jan 28 15:59:45 [ 102.946148] spi_master spi0: FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[00010000]: RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.946165] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::w2t: 512, is_dma: 1, bpw: 8, kfifo len: 512
Jan 28 15:59:45 [ 102.946191] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::status: 0x400005, fifo len 1024
Jan 28 15:59:45 [ 102.946210] tegra-gpcdma 2600000.dma: tegra_dma_terminate_all():handling isr
Jan 28 15:59:45 [ 102.946220] tegra-gpcdma 2600000.dma: tegra_dma_stop():clearing interrupt
Jan 28 15:59:45 [ 102.946226] spi-tegra124-slave 3210000.spi: Starting rx dma for len:512
Jan 28 15:59:45 [ 102.946236] spi-tegra124-slave 3210000.spi: tegra_spi_read_kfifo_to_client_rxbuf: read from kfifo 512 bytes of len 512[rem:512], fifo: 512
Jan 28 15:59:45 [ 102.946244] spi-tegra124-slave 3210000.spi: xfer len=512B rem len=0B, actual_len=512B, ret=512
Jan 28 15:59:45 [ 102.946253] spi-tegra124-slave 3210000.spi: Profile: size=512B time-from-spi-int=89120ns
Jan 28 15:59:45 [ 102.946255] spi_master spi0: After DMA EN
Jan 28 15:59:45 [ 102.946273] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff0000]:BSY I:255 B:0
Jan 28 15:59:45 [ 102.946288] spi_master spi0: FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[80010000]:De RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.946825] spi-tegra124-slave 3210000.spi: Rx len:512 bpw:8 3000us 8000000Hz, varlen: 1
Jan 28 15:59:45 [ 102.946841] spi-tegra124-slave 3210000.spi: tegra_spi_read_kfifo_to_client_rxbuf: read from kfifo 512 bytes of len 512[rem:512], fifo: 0
Jan 28 15:59:45 [ 102.946846] spi-tegra124-slave 3210000.spi: xfer len=512B rem len=0B, actual_len=512B, ret=512
Jan 28 15:59:45 [ 102.946852] spi-tegra124-slave 3210000.spi: Profile: size=512B time-from-spi-int=690784ns
Jan 28 15:59:45 [ 102.947325] spi-tegra124-slave 3210000.spi: Rx len:512 bpw:8 3000us 8000000Hz, varlen: 1
Jan 28 15:59:45 [ 102.958324] spi_master spi0: @isr
Jan 28 15:59:45 [ 102.958352] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[40ff0000]:RDY I:255 B:0
Jan 28 15:59:45 [ 102.958368] spi_master spi0: FIFO[20c00126]:RxF:65 TxE:64 Err[Er] RxSTA[OF] TxSTA[E]DMA[00010000]: RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.958386] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::w2t: 0, is_dma: 1, bpw: 8, kfifo len: 0
Jan 28 15:59:45 [ 102.958396] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::status: 0x20c00006, fifo len 0
Jan 28 15:59:45 [ 102.958408] spi_master spi0: rx-dma-err [status:20c00126]
Jan 28 15:59:45 [ 102.958557] spi_master spi0: CMD[33f00027]: Sl M3 CS0 [HHHH] MSB MSb Pa 8b TRANS[00ff0000]:BSY I:255 B:0
Jan 28 15:59:45 [ 102.958731] spi_master spi0: FIFO[20c00006]:RxF:65 TxE:64 Err RxSTA[F] TxSTA[E]DMA[00010000]: RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.958923] spi-tegra124-slave 3210000.spi: Starting rx dma for len:512
Jan 28 15:59:45 [ 102.958949] spi_master spi0: After DMA EN
Jan 28 15:59:45 [ 102.958964] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[00ff0000]:BSY I:255 B:0
Jan 28 15:59:45 [ 102.958975] spi_master spi0: FIFO[00400005]:RxF:0 TxE:64 Err RxSTA[E] TxSTA[E]DMA[80010000]:De RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.960299] spi_master spi0: @isr
Jan 28 15:59:45 [ 102.960323] spi_master spi0: CMD[33f01027]: Sl M3 CS0 [HHHH] MSB MSb Rx Pa 8b TRANS[40ff00a3]:RDY I:255 B:163
Jan 28 15:59:45 [ 102.960337] spi_master spi0: FIFO[80400005]:RxF:0 TxE:64 Err[Cs] RxSTA[E] TxSTA[E]DMA[00010000]: RxTr:0 TxTr:2 B:511
Jan 28 15:59:45 [ 102.960354] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::w2t: 163, is_dma: 1, bpw: 8, kfifo len: 0
Jan 28 15:59:45 [ 102.960363] spi-tegra124-slave 3210000.spi: tegra_spi_read_rx_fifo_to_kfifo::status: 0x400005, fifo len 163
Jan 28 15:59:45 [ 102.960383] spi-tegra124-slave 3210000.spi: Starting rx dma for len:512

kern.log (1.7 MB)

ShaneCCC · March 16, 2021, 11:02am

Did you run spidev_test?
What’s to full command line to run it?

fh2077 · March 17, 2021, 1:10am

Thanks for the quick reply. Above issue may due to some of the exception handle didn’t code well, and it reset DMA controller in some cases. There’s still some case that DMA won’t get data. I remember I saw in this forum there’s a tool could read/write registers online. Could you help to give some guidance and share the download link? Also how could I get SPI controller/DMA channel register address? Thanks!

ShaneCCC · March 17, 2021, 2:51am

You can install the devmem2 by apt-get and the check the TRM from download center for the REG address.

fh2077 · March 17, 2021, 9:25am

OK, I have installed the devmem2. But for the REG address, is it simply the TRM base + offset? For example, if i want to read spi0’s command_0, is it 0x3210000 + 0? However, when I tried “sudo devmem2 0x3210000” or “sudo devmem2 0x3210000 w”, the board would reboot without any output.
How to map the REG address? Do i need other command to unlock/ the address?

ShaneCCC · March 17, 2021, 10:26am

Maybe access by the spi driver would be legal.