nrf5340 is unable to trigger rpmsg(ipc) transfer

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.

flow

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

Parents
  • [00:01:23.903,991] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                          02 00 20 07 00                                   |.. ..
    [00:01:23.999,847] <inf> main: === Reseting data buffer ===
    [00:01:24.001,159] <inf> ads129x_log: Data transfer enabled
    [00:01:24.001,220] <inf> main: === Start analog data transfer ===
    [00:01:24.001,220] <inf> main: Sending 126 bytes (value after rounding to max packet size)
    [00:01:24.003,784] <dbg> bt_hci_driver: bt_rpmsg_send: buf 0x20019a88 type 2 len 137
    [00:01:24.003,906] <dbg> bt_hci_driver: bt_rpmsg_send: Final HCI buffer:
                                            02 00 00 85 00 81 00 04  00 52 12 00 00 00 01 c0 |........ .R......
                                            00 00 01 a6 f7 f5 c3 eb  ff fd 22 ff f6 bf ff f6 |........ ..".....
                                            de ff f7 54 ff f6 cd ff  fa ff f5 c6 c9 05 1f 79 |...T.... .......y
                                            05 1c 9b 05 1c 9b 00 00  01 c0 00 00 01 a6 ac f5 |........ ........
                                            d0 59 ff fd 2b ff f6 cf  ff f6 d4 ff f7 41 ff f6 |.Y..+... .....A..
                                            c5 ff fb 1f f5 d3 2e 05  19 3e 05 16 69 05 16 69 |........ .>..i..i
                                            00 00 02 c0 00 00 01 a5  e6 f5 d2 54 ff fd 1f ff |........ ...T....
                                            f6 e1 ff f6 c4 ff f7 31  ff f6 ae ff fb 22 f5 d5 |.......1 ....."..
                                            35 05 18 46 05 15 65 05  15 65                   |5..F..e. .e
    [00:01:24.004,119] <inf> main: [local] sent 126 bytes (0 KB) in 3 ms at 336 kbps
    [00:01:24.005,676] <inf> ads129x_log: Data transfer disabled
    [00:01:24.005,889] <dbg> bt_hci_driver: bt_rpmsg_send: buf 0x20019a88 type 2 len 11
    [00:01:24.005,920] <dbg> bt_hci_driver: bt_rpmsg_send: Final HCI buffer:
                                            02 00 00 07 00 03 00 04  00 0a 12 00             |........ ....
    [00:01:24.011,444] <dbg> bt_hci_driver: bt_rpmsg_rx: RPMsg data:
                                            04 13 05 01 00 00 01 00                          |........
    [00:01:24.011,474] <dbg> bt_hci_driver: bt_rpmsg_evt_recv: len 5
    [00:01:24.011,505] <dbg> bt_hci_driver: bt_rpmsg_rx: Calling bt_recv(0x20019758)
    [00:01:24.011,810] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                            04 00 00 00 e1                                   |.....
    [00:01:24.011,993] <dbg> bt_hci_driver: bt_rpmsg_rx: RPMsg data:
                                            04 13 05 01 00 00 01 00                          |........
    [00:01:24.012,084] <dbg> bt_hci_driver: bt_rpmsg_evt_recv: len 5
    [00:01:24.012,115] <dbg> bt_hci_driver: bt_rpmsg_rx: Calling bt_recv(0x20019758)
    [00:01:24.012,451] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                            42 00 00 00 ac                                   |B....
    [00:01:24.043,762] <dbg> bt_hci_driver: bt_rpmsg_rx: RPMsg data:
                                            02 00 20 15 00 11 00 04  00 0b 01 00 00 00 7e 00 |.. ..... ......~.
                                            00 00 87 24 00 00 ff ff  ff ff                   |...$.... ..
    [00:01:24.043,792] <dbg> bt_hci_driver: bt_rpmsg_acl_recv: len 21
    [00:01:24.043,823] <dbg> bt_hci_driver: bt_rpmsg_rx: Calling bt_recv(0x200197c8)
    [00:01:24.043,914] <inf> main: [peer] received 126 bytes (0 KB) in 1 GATT writes at 9 kbps
    [00:01:24.044,006] <dbg> bt_hci_driver: bt_rpmsg_send: buf 0x20019970 type 0 len 8
    [00:01:24.044,036] <dbg> bt_hci_driver: bt_rpmsg_send: Final HCI buffer:
                                            01 35 0c 05 01 00 00 01  00                      |.5...... .
    [00:01:24.044,250] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                            e2 ae 03 00 88 9a 01 20  02 00 00 00 0f 00 00 00 |.......  ........
    [00:01:24.044,372] <inf> main:

    Here is a debug log from rpmsg. 

    I send 100 bytes with write ble command. The final hci buffer was ok 137 bytes.
    Sadly there is quite long response from NETWORK, which makes it unusable

Reply
  • [00:01:23.903,991] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                          02 00 20 07 00                                   |.. ..
    [00:01:23.999,847] <inf> main: === Reseting data buffer ===
    [00:01:24.001,159] <inf> ads129x_log: Data transfer enabled
    [00:01:24.001,220] <inf> main: === Start analog data transfer ===
    [00:01:24.001,220] <inf> main: Sending 126 bytes (value after rounding to max packet size)
    [00:01:24.003,784] <dbg> bt_hci_driver: bt_rpmsg_send: buf 0x20019a88 type 2 len 137
    [00:01:24.003,906] <dbg> bt_hci_driver: bt_rpmsg_send: Final HCI buffer:
                                            02 00 00 85 00 81 00 04  00 52 12 00 00 00 01 c0 |........ .R......
                                            00 00 01 a6 f7 f5 c3 eb  ff fd 22 ff f6 bf ff f6 |........ ..".....
                                            de ff f7 54 ff f6 cd ff  fa ff f5 c6 c9 05 1f 79 |...T.... .......y
                                            05 1c 9b 05 1c 9b 00 00  01 c0 00 00 01 a6 ac f5 |........ ........
                                            d0 59 ff fd 2b ff f6 cf  ff f6 d4 ff f7 41 ff f6 |.Y..+... .....A..
                                            c5 ff fb 1f f5 d3 2e 05  19 3e 05 16 69 05 16 69 |........ .>..i..i
                                            00 00 02 c0 00 00 01 a5  e6 f5 d2 54 ff fd 1f ff |........ ...T....
                                            f6 e1 ff f6 c4 ff f7 31  ff f6 ae ff fb 22 f5 d5 |.......1 ....."..
                                            35 05 18 46 05 15 65 05  15 65                   |5..F..e. .e
    [00:01:24.004,119] <inf> main: [local] sent 126 bytes (0 KB) in 3 ms at 336 kbps
    [00:01:24.005,676] <inf> ads129x_log: Data transfer disabled
    [00:01:24.005,889] <dbg> bt_hci_driver: bt_rpmsg_send: buf 0x20019a88 type 2 len 11
    [00:01:24.005,920] <dbg> bt_hci_driver: bt_rpmsg_send: Final HCI buffer:
                                            02 00 00 07 00 03 00 04  00 0a 12 00             |........ ....
    [00:01:24.011,444] <dbg> bt_hci_driver: bt_rpmsg_rx: RPMsg data:
                                            04 13 05 01 00 00 01 00                          |........
    [00:01:24.011,474] <dbg> bt_hci_driver: bt_rpmsg_evt_recv: len 5
    [00:01:24.011,505] <dbg> bt_hci_driver: bt_rpmsg_rx: Calling bt_recv(0x20019758)
    [00:01:24.011,810] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                            04 00 00 00 e1                                   |.....
    [00:01:24.011,993] <dbg> bt_hci_driver: bt_rpmsg_rx: RPMsg data:
                                            04 13 05 01 00 00 01 00                          |........
    [00:01:24.012,084] <dbg> bt_hci_driver: bt_rpmsg_evt_recv: len 5
    [00:01:24.012,115] <dbg> bt_hci_driver: bt_rpmsg_rx: Calling bt_recv(0x20019758)
    [00:01:24.012,451] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                            42 00 00 00 ac                                   |B....
    [00:01:24.043,762] <dbg> bt_hci_driver: bt_rpmsg_rx: RPMsg data:
                                            02 00 20 15 00 11 00 04  00 0b 01 00 00 00 7e 00 |.. ..... ......~.
                                            00 00 87 24 00 00 ff ff  ff ff                   |...$.... ..
    [00:01:24.043,792] <dbg> bt_hci_driver: bt_rpmsg_acl_recv: len 21
    [00:01:24.043,823] <dbg> bt_hci_driver: bt_rpmsg_rx: Calling bt_recv(0x200197c8)
    [00:01:24.043,914] <inf> main: [peer] received 126 bytes (0 KB) in 1 GATT writes at 9 kbps
    [00:01:24.044,006] <dbg> bt_hci_driver: bt_rpmsg_send: buf 0x20019970 type 0 len 8
    [00:01:24.044,036] <dbg> bt_hci_driver: bt_rpmsg_send: Final HCI buffer:
                                            01 35 0c 05 01 00 00 01  00                      |.5...... .
    [00:01:24.044,250] <dbg> bt_hci_driver: bt_rpmsg_rx: RX buf payload:
                                            e2 ae 03 00 88 9a 01 20  02 00 00 00 0f 00 00 00 |.......  ........
    [00:01:24.044,372] <inf> main:

    Here is a debug log from rpmsg. 

    I send 100 bytes with write ble command. The final hci buffer was ok 137 bytes.
    Sadly there is quite long response from NETWORK, which makes it unusable

Children
No Data
Related