spi_bcm2835: CLK occasionally stops during SPI transfer

[mjs]

We are using a Raspberry Pi 3 with a FLIR Lepton 3 thermal camera. This camera uses VoSPI to transfer thermal video frames. The protocol involves performing continuous, regular SPI transfers. While we are able to successfully get frames off the camera most of the time, we occasionally lose data. This is obvious because the camera uses a scheme of packet and segment numbers to identify the data - we sometimes see gaps in the returned identifiers. These loss of sync events happens irregularly and are spaced anywhere from 10s to 5 mins apart.

When looking at various SPI signals with a scope we've observed that just before a loss of sync is observed the CLK signal stops while /CS stays low.

Here's the output from the scope shows the CLK going away twice in quick succession:

Notes for interpreting the output: The large bottom area of the output is a zoomed in section of the smaller top area. The zoomed in section is shown with the [ ] indicators.

• purple is /CS
• yellow is CLK
• blue is connected to a GPIO which goes high when our software detects loss of sync (slightly delayed because it takes a little time to notice)

We've watched a number of loss of sync events with the scope and the CLK output stopping seems to be highly correlated to the problem.

We are using the 4.9.59-v7+ Raspian kernel.

Our /boot/config.txt looks like this:

gpu_mem=16
start_x=0
enable_uart=0

arm_freq=600
arm_freq_min=600

gpu_freq=200
gpu_freq_min=200

dtparam=i2c_arm=on
dtparam=spi=on

# Enable audio (loads snd_bcm2835)
dtparam=audio=on

We have disabled CPU scaling because it significantly reduces the frequency of the sync loss events.

We do not set the CS change flag during SPI transfers.

Could we be doing something wrong? Could this be a problem with the spi_bcm2835 driver? Could there be a hardware issue?

We are highly motivated to get this resolved and are willing and able to try out any suggestions or potential fixes.

[mjs]

@msperl ping

[pelwell]

The SPI protocol uses an explicit clock - provided it doesn't exceed the devices limits and can support the required bandwidth, the clock rate should be free to change without notice.

The Notes section of the SPI chapter of the BCM2835 ARM Peripherals guide says:

2. SCLK is only generated during byte serial transfer. It pauses in the rest state if the
   next byte to send is not ready or RXF is set.

If you want a continuous clock then there must be something to transmit - receiving involves sending the required number of bytes, zeroes if there is really nothing to transmit, in order to clock the data out of the slave. In order to avoid gaps, to the extent that is possible, you must submit your transfers asynchronously with sufficient buffering in the system to keep the DMA engine busy while the CPU goes away for a while.

If interrupts are locked out for any length of time then the detection of the end of a DMA transfer will be delayed. If there are no subsequent transfers queued in the DMA's work queue then you have up to 16 words of SPI FIFOs (RX and TX) before the clock will be switched off.

What clock and data rates are you trying to achieve? If you assume that the CPU may go AWOL for (say) 10ms, do you have enough buffering in your application to cover that gap?

[mjs]

Thanks for your detailed reply @pelwell.

I probably should have used a different word instead of "continuous". I don't want or expect a constant SPI CLK. I only meant that the camera requires regular SPI transfers in order to get video data out without losing data. I expect the CLK signal to be active during transfers (when /CS is asserted) and not otherwise.

Some more details:

• we are requesting a SPI clock rate of 20 MHz (although the camera should be OK with anything between 10 and 20 MHz).
• we have set a large spidev buffer size (spidev.bufsiz=65536)
• we do have buffering in our application as well as a thread that purely dedicated to simply retrieving data from the /dev/spidev0 device file

Can you explain why the SPI CLK appears to stop while /CS is still asserted? (as per the oscilloscope output). AFAIK, that's not something we can cause from userland and it seems to happen every time before we observe bad/missing data from the camera.

[pelwell]

CS lines, even the "hardware" CS lines like SPI_CE0_N, are controlled by software running on the ARM. If the ARM is slow to respond to the interrupt at the end of a DMA transfer then there will be a break in the data stream; if that break exceeds the FIFO size then the SPI CLK will stop. Notice how the CS is deasserted at the end of each of the clock stall intervals; this shows that the driver was waiting to stop the clock but hadn't been able to - it isn't just a random stall in the middle of a transfer.

The spidev driver only uses the synchronous interface, so there are limits to how much you can mitigate against occasional CPU starvation like this without a proper kernel driver. It's unfortunate that the camera doesn't have more buffering.

[msperl]

To me this actually looks like a scheduling issue of the user space process - it would be more apparent if non-native chip-selects were used instead.

From a user space perspective the one thing that you may be able to do is pin your spidev reading thread/process to a separate cpu only used by this process.

Then you should get almost exclusive usage of the cpu (@pelwell: I assume that the Irqs of the usb (hard and soft) go to cpu0).

This together with the fact that you seem to be doing 5 byte transfers only should ensure that the spi transfers run in polling mode and thus without any interrupts, that add scheduling overhead.

To achieve this you may need to follow this howto: http://xmodulo.com/run-program-process-specific-cpu-cores-linux.html

If you have multiple spi devices on the bus then this will no longer work...

Martin

P.s: all this assumes that spidev is running synchronous spi calls internally that will avoid the shared spi pipeline and execute the spi transfer in place.

[mjs]

@pelwell & @msperl - thanks for all the useful information.

I'll try locking our camera reading process to it's own CPU. We don't have multiple SPI devices on the bus so that isn't an issue.

5 byte transfers certainly doesn't sound right. They should be much larger. It may just appear that we're doing 5 byte transfers due to scope sampling artifacts but I will double check as such small transfers would certainly not be helping.

I'm not adverse to trying to create a driver for the camera that uses an asynchronous approach if that would be more reliable. Are there any SPI related drivers for other devices that already do this that you're aware of?

[pelwell]

I don't understand how Martin arrives at his 5 byte transfers conclusion. Reading (correctly, I hope) the scope screenshot I can make out about about 28 transfers in 20ms, which leaves about 700us per transfer. Ignoring for a moment setup delays and per-transfer overhead, 5 bytes (40 bits) at 20MHz takes 2us, a lot less than the 700us previously calculated, which would suggest that we can transfer on the order of 1500 bytes in 700us.

Where is my mistake, Martin?

[msperl]

I was just looking at those screenshot pattern where there are about "4 gaps" while CS is down.
But this may be just aliasing.

Even 28 transfers is quite small and should definitely make us use polling SPI in the thread.

[pelwell]

@mjs There are two network drivers and a codec driver that use asynchronous SPI:

https://github.com/raspberrypi/linux/blob/rpi-4.9.y/drivers/net/ieee802154/at86rf230.c
https://github.com/raspberrypi/linux/blob/rpi-4.9.y/drivers/net/ieee802154/mrf24j40.c
https://github.com/raspberrypi/linux/blob/rpi-4.9.y/sound/soc/codecs/wm0010.c

They are all fairly substantial bits of code, but the bits of the code that interface with SPI are fairly small and simple.

Actually, the 4.14 tree has another networking driver that looks slightly simpler/morre localised - between the 4 drivers you should be able to work it out.

[mjs]

I've finally had time to get back to this (we've been limping along with the CPU locked at 600MHz and tolerating the frequent loss of sync events). I've split our code into 2 parts so that there's one process that reads the camera and does nothing else except send frames over a Unix domain socket. The receiving part takes care of analysing and compressing the frames for storage.

The camera handling part has been given its own CPU core (via isolcpus and taskset) and that has eliminated the problems we've been having.

Even with the CPU at 1.2GHz, which previously increased our resync rate to unacceptable levels, we can read the camera just fine. High load on the other 3 cores also has no effect on the camera. I'm really pleased.

Thanks @msperl and @pelwell for all your help. I think this issue can be closed.