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)

[Edvin]

A Bluetooth Low Energy device can only communicate with the connected device every connection interval.

In fact, it is a bit more complicated than that. A BLE connection has something called a connection interval. Every connection interval there is a connection event. This event is not initializing a connection, but the connection event is the event that occurs every connection interval, where the two devices are able to communicate.

In the start of a connection event, the devices can start sending messages. When both devices are done, and don't have any more data, they will turn off their radios and go to sleep (hence Bluetooth Low Power). So even if you wanted to send data immediately after that, the receiving device would not have the radio turned on, and it wouldn't hear it. Therefore they must wait up to one connection intrval, until the next connection event occurs before they can send any more data. 

Best regards,

Edvin

[Dumam]

It makes sense to me but this happens also for longer data transfers. I can accept some delay while i start communication, but for me it looks like there is some interference between components.

For example If I would like to sent 3MB. Instead of stable stream of data, it looks like my app is buffering them in HCI driver and then after some time, it starts to send them in every connection event (like in picture). To set some reference, time spent on buffering is 30-100ms, and when transfer starts time between each frame is around 3-10ms.

At the end my throughput is around 60kbps.

My connection interval is set to 28units now. 
https://github.com/DuMaM/bitly_nrf5x/blob/496ad8dfe21107d0d8ec1a2fd75c939aa89076fb/include/app/cmd.h#L11

What makes it more interesting is that I observe such behavior only when SPI is enabled.
For testing purposes I prepared artificial data set which I sent in exactly the same way. With this approach I'm able to get throughput around 1100kbps. 
With exactly the same devices, with the same connection setups, and parameters, programs.
https://github.com/DuMaM/bitly_nrf5x/blob/496ad8dfe21107d0d8ec1a2fd75c939aa89076fb/src/app/cmd_run_sim.c

I think the issue here is that `cmd_sim` function is sending everything in one thread, by locking itself on `bt_gatt_write_without_response`. This way it dont have to switch thread context.
Where case with SPI needs to use mutexes and ISR to switch into different thread and protect shared resources.

[Dumam]

Edvin I think it's more a problem of how communication between threads is set up.

I checked this with Particle Xenon board and I observed exactly the same behavior.
I also switched from pipe to ring_buffers to save copy operations. This also didn't helped.

Here is BLE thread:
https://github.com/DuMaM/bitly_nrf5x/blob/e6cf66e1655bf3da2c65d58fedb561893194ba80/src/app/cmd_run_adc.c

Here is SPI thread:
github.com/.../spi_adc.c

[Edvin]

Dumam said:

I think the issue here is that `cmd_sim` function is sending everything in one thread,

Where is this cmd_sim? Is it part of the repository that you are linking to? I am not familiar with that application, and it is not written by anyone from Nordic. 

Best regards,
Edvin

[Dumam]

Yep, this is my command i wrote for testing purposes.

Everything base on this example.
https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/samples/bluetooth/throughput/README.html

I changed few parameters, to fit my needs. cmd_sim is basically this function from sample.
github.com/.../main.c

The problematic code do the same but gets data from SPI. 

[Edvin]

Dumam said:

The problematic code do the same but gets data from SPI. 

Can you please show me how you do that? 

In case I have follow up questions, feel free to zip and upload the entire project here (just drag and drop into the window where you are typing). 

[Dumam]

My repo is public you can download or clone it without any issues.

https://github.com/DuMaM/bitly_nrf5x
I also placed this in attachment.

SPI Thread.
More here: github.com/.../spi_adc.c

void ads129x_set_data()
{
    /* add timestamp */
    tx_data.packet.timestamp = k_uptime_get() - timestamp;
    conv_u24_to_raw(tx_data.packet.timestamp, tx_data.buffer, 0);

    /* do processing */
    /* NOTE: Work directly on a ring buffer memory */
    int ret = spi_read(ads129x_spi, &ads129x_spi_cfg, &ads129x_rx);
    if (!ret)
    {
        /* add missing leads */
        lead1 = conv_u24_to_i32(conv_raw_to_u24(tx_data.packet.leads._buffer, ADS129x_LEAD1_OFFSET));
        lead2 = conv_u24_to_i32(conv_raw_to_u24(tx_data.packet.leads._buffer, ADS129x_LEAD2_OFFSET));
        conv_u24_to_raw(ads129x_get_leadIII(lead1, lead2), tx_data.packet.leads._buffer, ADS129x_LEAD3_OFFSET);
        conv_u24_to_raw(ads129x_get_aVR(lead1, lead2), tx_data.packet.leads._buffer, ADS129x_AVR_OFFSET);
        conv_u24_to_raw(ads129x_get_aVL(lead1, lead2), tx_data.packet.leads._buffer, ADS129x_AVL_OFFSET);
        conv_u24_to_raw(ads129x_get_aVF(lead1, lead2), tx_data.packet.leads._buffer, ADS129x_AVF_OFFSET);

        //ads129x_dump_data(tx_data.packet.leads._buffer);
    }

    /* send data to consumers */
    /* send data to the consumers */
    k_pipe_put(&ads129x_pipe, &tx_data.buffer, total_size, &bytes_written, sizeof(pipe_packet_u), K_NO_WAIT);
}

void ads129x_th(void)
{
    /* setup ecg */
    ads129x_setup();

    for (;;)
    {
        /*
         * Wait for semaphore from ISR; if acquired, do related work, then
         * go to next loop iteration (the semaphore might have been given
         * again); else, make the CPU idle.
         */
        if (k_sem_take(&ads129x_new_data, K_FOREVER) == 0)
        {
            ads129x_set_data();
        }
    }
}

K_THREAD_DEFINE(thread_ads129x, STACKSIZE, ads129x_th, NULL, NULL, NULL, PRIORITY, K_ESSENTIAL, 0);

BLE Thread:
More here: https://github.com/DuMaM/bitly_nrf5x/blob/e6cf66e1655bf3da2c65d58fedb561893194ba80/src/app/cmd_run_adc.c#L104

K_THREAD_STACK_DEFINE(ecg_ble_stack, 4096);
struct k_thread ecg_ble_thread;
static uint32_t bytes_to_send = 1024;

static uint32_t send_test_ecg_data(uint32_t _bytes_to_send)
{
    uint32_t prog = 0;
    uint8_t *analog_data_ptr = test_data_buffer;
    uint32_t analog_data_size = 0;
    int err = 0;

    /*
     * we always waiting for data to match whole buffer
     * so data requested should also match it
     * otherwise we should ignore it
     */
    uint16_t remainder = _bytes_to_send % ADS129x_DATA_BUFFER_SIZE;
    if (remainder) {
        _bytes_to_send = ((_bytes_to_send / ADS129x_DATA_BUFFER_SIZE) + 1) * ADS129x_DATA_BUFFER_SIZE;
    }
    LOG_INF("Sending %"PRIu32" bytes (value after rounding to max packet size)", _bytes_to_send);

    while (prog < _bytes_to_send)
    {
        analog_data_size = _bytes_to_send - prog;
        if (test_params.data_len->tx_max_len <= analog_data_size) {
            analog_data_size = test_params.data_len->tx_max_len;
        }

        /*
         * TODO: add scaling from shell
         * It would be good to send optimal number of data
         * during each transfer
         * also when we change a number o leads
         */
        if (!ads129x_get_data(analog_data_ptr, analog_data_size))
        {
            continue;
        }

        err = bt_performance_test_write(&performance_test, analog_data_ptr, analog_data_size);
        if (err)
        {
            LOG_ERR("GATT write failed (err %d)", err);
            break;
        }

        prog += analog_data_size;
    }
    return prog;
}

bitly_nrf5x-main.zip

[Edvin]

Oh, my impression was that this was someone else's repository. I understand. I will have a look at it as soon as possible.

[Dumam]

 Edvin I'm soo grateful for this. I'm trying to figure it out for 2 months without any luck. :(

[Edvin]

Ok, I am trying to navigate your project. I am struggling to see exactly how it relates to the throughput sample. Where exactly are you sending the BLE packets. Can you please point to it? Where it sends, and how long are the packets that you are sending? There should be a call to bt_gatt_notify_cb() or bt_gatt_write() or something like that.

You say that your throughput is much higher when you disable the SPI and just use dummy data. So the MTU and connection interval and everything else is the same, just that you wait for the SPI to finish? 

What is it that triggers send_test_ecg_data()? 

ads129x_get_data() only triggers a read from a buffer? No actual peripheral transferring data? When will it continue; and when will it send data (which I assume it does inside bt_performance_test_write(). And when bt_performance_test_write() is called, what is the length of the data that is being sent?

Sorry, a lot of unstructured questions, but I was reading more and more into your project. So the question is, how often is send_test_ecg_data() called, and how often is bt_performance_test_write() called? Is bt_performance_test_write() called every time send_test_ecg_data() is called, or does it often skip it because of continue; ?