nrf5340 is unable to trigger rpmsg(ipc) transfer

[Dumam]

Hi,

I have quite demanding SPI device which should send its data over BLE.
Thanks to throughput example i was able to achieve maximum transfer speeds for synthetic tests (without SPI).
Sadly after adding real data input, I noticed that no transfer is executed until I finish my commands. 

Thanks to SystemView I was able to narrow this problem to one part of configuration -> rpmsg.

Colors:

Green -> spi thread
Yellow -> bt_hci thread
Orange -> ble host TX
Red (small squere in top) - IRQ 58 from probably ipc, but i wasnt able to find it in manual (not listed)
Blue - probably openAmp mailing work queue thread
purple - systemwork queue

SystemView Data Log
4010.BleProblem.dat

Here is repo with configs etc.
https://github.com/DuMaM/bitly_nrf5x

[Edvin]

Hello,

I am not sure I understand the question? What are you seeing, and how do you expect it to work?

I noticed that no transfer is executed until I finish my commands. 

What sort of commands are you talking about here?

BR,
Edvin

[Dumam]

 Edvin Thanks for response, and sorry to not be clear enough. 

This is what i'm doing here:
-> I have ads129x communication over SPI. It's set to work in continuous mode, so every n seconds it sends data packet (24bytes). To notify that we should get them it pulls up DATA_READY pin. I detect this in ISR callback and via semaphore i'm notifying SPI thread to read data. (GREEN part in picture)
-> after SPI read this it send that data via pipe to other thread which is packing up data for BLE transfer, every time i get 251 bytes in this thread I'm sending this with `bt_gatt_write_without_response`. (YELLOW part in picture)

The question is:
why it takes so long rpmsg to start transmit data and why there are so big delays between each frame. (BLUE part in picture)

[Dumam]

Hi Edvin,

You were right. There was problem with connection interval.
Zephyr needs a constant feed of data at the beginning of a connection event.
If this steam is not delivered, then the connection is instantly terminated.
I was planning to just retransmit my SPI data without any additional buffering, but this will not work in that case.

So, I increased SPI buffer, and now it provides space for data from 35ms long SPI stream.
At the end, I was able to reach 0.5Mbits/s of throughput 

That's so big step forward  thanks for this help.


Sadly, I still require some help.
I noticed that SPI is now a blocking factor. 
Do you have nice example how to work with EasyDMA SPI in zephyr, so I can fetch data only on interrupt from it? Additional GPIO, takes too many CPU cycles in ISR, and it duplicates SPI work.

Please do not close this ticket yet.

[Edvin]

Dumam said:

Please do not close this ticket yet.

No problem. We can go on for a while more. Just please note that I will be out of office tomorrow, but I'll be back on Monday.

I am glad you figured it out! That makes sense. The data needs to be queued up before the connection event. Obviously, all individual packets needs to be queued before they go on air. And in each packet, there is a bit that says whether or not it has more data. So the Bluetooth stack (SoftDevice Controller) needs to at least be aware of the second packet before it starts transmitting the initial packet. Whether or not that is recursive, I am not sure. That is, if you have queued packet #1 and #2 when packet #1 goes on air. Then you queue packet #3 before packet #2 has started airing, I am not sure whether it will change the "more data" bit in packet #2 or not. If not, then all packets needs to be queued before the connection event starts. 

As for the SPI. I am not aware of any SPI with EasyDMA samples in Zephyr, but you can set up a ppi approach. On how to use PPI, please see the sample found in NCS\zephyr\samples\boards\nrf\nrfx. What you can do here is to chain the transfer end event with a transfer start, so that it runs in the background, if that is what you are looking for. Then you would typically use a timer in counter mode to also count up, and then set an interrupt when the timer (counter) reaches a certain value, to then trigger a "timeout" interrupt in your application.

Best regards,

Edvin

[Dumam]

Edvin said:

Whether or not that is recursive, I am not sure. That is, if you have queued packet #1 and #2 when packet #1 goes on air. Then you queue packet #3 before packet #2 has started airing, I am not sure whether it will change the "more data" bit in packet #2 or not. If not, then all packets needs to be queued before the connection event starts. 

As far as I can tell, write request is locked since there will be a free space in rpmsg buffer.
I don't understand why I see only 2 work queue execution per, connection event, even thought I have more data prepared for transmission. I think this is a one of settings from RPMSG. 

I'm not sure about PPI. My guess is that SPI is taking too long, and I'm unable to provide next packet for BT_TX thread.

[Dumam]

I also increased systick speed and this didnt helped.

# clock settings
# https://github.com/zephyrproject-rtos/zephyr/issues/28469#issuecomment-704164283
# https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/zephyr/kernel/services/timing/clocks.html
# https://devzone.nordicsemi.com/f/nordic-q-a/92297/increasing-cpu-clock-frequency-for-bl653
CONFIG_NRF_RTC_TIMER=n
CONFIG_CORTEX_M_SYSTICK=y
CONFIG_SYS_CLOCK_HW_CYCLES_PER_SEC=64000000
CONFIG_SYS_CLOCK_TICKS_PER_SEC=6400000

[Edvin]

I believe it is rather the work queue holding you back than the BLE stack. You can try to either skip the work queue, and call the bt_gatt_notify_cb() directly from your spi callback handler.

[Dumam]

Ok, I added BLE call inside SPI callback.
https://github.com/DuMaM/bitly_nrf5x/pull/13
I got even worse performance ;( 

BTW. I'm using bt_gett_write_without_response, which is under the hood:

static inline int bt_gatt_write_without_response(struct bt_conn *conn,
						 uint16_t handle, const void *data,
						 uint16_t length, bool sign)
{
	return bt_gatt_write_without_response_cb(conn, handle, data, length,
						 sign, NULL, NULL);
}

[Dumam]

[Dumam]

Dear Edvin 
bt_write_without_response is locking function, which is bad for me because my SPI do not have time to prepare new data for connection event. 
I'm looking for something what will help me in determining if i have still space in in my TX buffers.
According to docs.zephyrproject.org/.../l2cap.html , there is nothing like that.

[Edvin]

Can you please check my colleague, Einar's replies in this ticket:
bt_gatt_notify() can block when running on Zephyr workqueue.

In general, you should not call bt_gatt_notify_cb() from a workqueue, because it can lead to a deadlock, or in some cases, blocking calls, as you see here. Try calling it from another context. 

Best regards,

Edvin

[Dumam]

Thanks for this reply, but:

1. I posted URL to my code where you can easily track that I'm not using work queue but separate thread.
I posted a print screen from Seeger System View, where there is only info about thread
2. I call there bt_gatt_write_without_response_cb(), which calls bt_gatt_write_without_response_cb(). This calls still blocks thread execution. 
3. My issues are the same as ones mentioned here, for the same board, for the same situation:
What's different in my case is that I'm using a `write without response` not notify.
Fast notifications with nRF5340 and nRF Connect SDK

4. For this board, if you use BLE stack anywhere, then net CPU is included.
This converts the project to multicore one and adds a simple rpmsg project for net-core and installs SoftDevice by default on it.
After that in config you can also see that HCI RPMSG stack is enabled for app core. 
So every command from app-core to HCI BLE is sent via RPMSG module.
This module uses RPROC protocol and MBOX module to sync over IPC.
Sadly, to process this in correct manner, MBOX module is using WORKQUEUE.

I guess this is the main reason for locks.
If this issue is true.
bt_gatt_notify() can block when running on Zephyr workqueue.

5. nrf52840 has different driver HCI RPC, but there is similar WORKQUEUE implemented to sync with SoftDevice.