BT_HCI_SPI and BSDLib, chasing down increased HCI processing latency

[henriksern]

Hey!

I have inherited a project with a nRF9160 + nRF52480 combination to do LTE and BLE communication.

The setup is as follows:

- nRF9160 using BSDlib @ NCS 1.5.0

- nRF52840 running HCI_SPI example acting as a controller

Issue:

Host (nRF9160) is unable to keep up with interrupts generated by HCI controller. When the IRQ is lost / not processed quickly enough the HCI layer gets stuck in a situation where the HCI controller waits for the host to read data, and the host waits for an interrupt that never comes (the IRQ is trigger by GPIO state change, but the IRQ pin is already active (low on our board).

I have gone through the threads running in this application (7 in total) and they are all with lower priority than the HCI SPI thread. The only thing I have found that have higher priority (except for kernel stuff) is the BSDLib interrupts.

This also correlates with my findings when probing the IRQ pin, activity stops dead when there is LTE traffic (MQTT data in this application).

My question is then:

Does it sound reasonable that HCI SPI processing gets interrupted and delayed by BSDLib? Any tips on how I can verify/debunk my theory?

EDIT: bluetooth is running a a simple passive advertisement scanner

[Jonathan Rico]

Hi, I see that the only thing the ISR does is give a semaphore. So even if that's delayed, the message shouldn't get lost, it's only the big while loop that does the processing that will be delayed.

If it does indeed get lost, I think that would indicate a problem on the controller side, e.g., discarding buffers not received in time. But I think that's also not the case since you say it gets stuck (so it must be filling up a buffer pool that doesn't get emptied by the other side).

Could you instrument zephyr/drivers/bluetooth/hci/spi.c in a few strategic places to confirm if processing is stuck? Like a log_dbg right after the while(true) (~L285) but before the sem take, also between the two sem takes a line or two below. There's already one after the second sem take.

I'm also wondering if your interrupt pin isn't getting reconfigured by the rest of the application, that could also be why you're seeing erratic behavior. You could try also putting a log_dbg inside the spi.c ISR.