NUS central example can't send more than 4 packets of 244 Bytes

[TermiteUser]

Hi everybody,

I have some trouble fixing the ERROR 19 [NRF_ERROR_RESOURCES]. I think it's something about the buffer queue size that is too busy. But I don't know how to fix it because most of the resolution on that matter was on the peripheral side with BLE_GATTS_EVT_HVN_TX_COMPLETE but it's a server whereas on the central side it's a client. 

So I think I can't solve my problem with BLE_GATTS_EVT_HVN_TX_COMPLETE or I misunderstood something.

If you could enlighten me on that matter or give me some solutions. It would be great.

Some informations that might be useful : 

NRF_SDH_BLE_GAP_EVENT_LENGTH is 320

NRF_SDH_BLE_GAP_DATA_LENGTH is 251

NRF_SDH_BLE_GATTS_ATTR_TAB_SIZE 1408

// Where I send my 244 Bytes data

void uart_event_handle(app_uart_evt_t * p_event)
{
    static uint8_t data_array[BLE_NUS_MAX_DATA_LEN];
    
    static uint16_t index = 0;
	static uint32_t ret_val;
    static uint16_t length = 244;
	static uint8_t j;
	static uint8_t send_data[BLE_NUS_MAX_DATA_LEN];
  
    
	for (uint8_t i=0; i<length; i++)
	{
		send_data[i]=i;
	}
    switch (p_event->evt_type)
    {
        /**@snippet [Handling data from UART] */
        case APP_UART_DATA_READY:
            UNUSED_VARIABLE(app_uart_get(&data_array[index]));
            index++;

            if (//(data_array[index - 1] == '\n') ||
                (data_array[index - 1] == '\r') ||
                (index >= (m_ble_nus_max_data_len)))
            {
                NRF_LOG_INFO("Ready to send data over BLE NUS");
                NRF_LOG_HEXDUMP_INFO(data_array, index);

                do
                {
					if (index % 4 != 0 || index > 4)
                    {
						for (int i=0;i<10;i++)
						{
								ret_val = ble_nus_c_string_send(&m_ble_nus_c, send_data, length);
						}
					}

                    if ( (ret_val != NRF_ERROR_INVALID_STATE) && (ret_val != NRF_ERROR_RESOURCES) &&
						(ret_val != NRF_ERROR_NOT_FOUND))
                    {
                        APP_ERROR_CHECK(ret_val);
                    }
                } while (ret_val == NRF_ERROR_RESOURCES);

                index = 0;
            }
            break;

        /**@snippet [Handling data from UART] */
        case APP_UART_COMMUNICATION_ERROR:
            NRF_LOG_ERROR("Communication error occurred while handling UART.");
            APP_ERROR_HANDLER(p_event->data.error_communication);
            break;

        case APP_UART_FIFO_ERROR:
            NRF_LOG_ERROR("Error occurred in FIFO module used by UART.");
            APP_ERROR_HANDLER(p_event->data.error_code);
            break;

        default:
            break;
    }
}

Best Regards,

[Edvin]

Hello,

The ble_nus_c_string_send() will result in a sd_ble_gattc_write() call in the end. Depending on what SDK version you are using, it is either called directly. Alternativley it is called via the GQ module. 

Check out the declaration of this function in ble_gattc.h (may differ between different SDK versions).

/**@brief Perform a Write (Characteristic Value or Descriptor, with or without response, signed or not, long or reliable) procedure.
 *
 * @details This function can perform all write procedures described in GATT.
 *
 * @note    Only one write with response procedure can be ongoing per connection at a time.
 *          If the application tries to write with response while another write with response procedure is ongoing,
 *          the function call will return @ref NRF_ERROR_BUSY.
 *          A @ref BLE_GATTC_EVT_WRITE_RSP event will be issued as soon as the write response arrives from the peer.
 *
 * @note    The number of Write without Response that can be queued is configured by @ref ble_gattc_conn_cfg_t::write_cmd_tx_queue_size
 *          When the queue is full, the function call will return @ref NRF_ERROR_RESOURCES.
 *          A @ref BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event will be issued as soon as the transmission of the write without response is complete.
 *
 * @note    The application can keep track of the available queue element count for writes without responses by following the procedure below:
 *          - Store initial queue element count in a variable.
 *          - Decrement the variable, which stores the currently available queue element count, by one when a call to this function returns @ref NRF_SUCCESS.
 *          - Increment the variable, which stores the current available queue element count, by the count variable in @ref BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event.
 *
 * @events
 * @event{@ref BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE, Write without response transmission complete.}
 * @event{@ref BLE_GATTC_EVT_WRITE_RSP, Write response received from the peer.}
 * @endevents
 *
 * @mscs
 * @mmsc{@ref BLE_GATTC_VALUE_WRITE_WITHOUT_RESP_MSC}
 * @mmsc{@ref BLE_GATTC_VALUE_WRITE_MSC}
 * @mmsc{@ref BLE_GATTC_VALUE_LONG_WRITE_MSC}
 * @mmsc{@ref BLE_GATTC_VALUE_RELIABLE_WRITE_MSC}
 * @endmscs
 *
 * @param[in] conn_handle The connection handle identifying the connection to perform this procedure on.
 * @param[in] p_write_params A pointer to a write parameters structure.
 *
 * @retval ::NRF_SUCCESS Successfully started the Write procedure.
 * @retval ::BLE_ERROR_INVALID_CONN_HANDLE Invalid Connection Handle.
 * @retval ::NRF_ERROR_INVALID_STATE Invalid Connection State.
 * @retval ::NRF_ERROR_INVALID_ADDR Invalid pointer supplied.
 * @retval ::NRF_ERROR_INVALID_PARAM Invalid parameter(s) supplied.
 * @retval ::NRF_ERROR_DATA_SIZE Invalid data size(s) supplied.
 * @retval ::NRF_ERROR_BUSY For write with response, procedure already in progress. Wait for a @ref BLE_GATTC_EVT_WRITE_RSP event and retry.
 * @retval ::NRF_ERROR_RESOURCES Too many writes without responses queued.
 *                               Wait for a @ref BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event and retry.
 * @retval ::NRF_ERROR_TIMEOUT There has been a GATT procedure timeout. No new GATT procedure can be performed without reestablishing the connection.
 */
SVCALL(SD_BLE_GATTC_WRITE, uint32_t, sd_ble_gattc_write(uint16_t conn_handle, ble_gattc_write_params_t const *p_write_params));

Particularly these lines:

* @retval ::NRF_ERROR_RESOURCES Too many writes without responses queued.
* Wait for a @ref BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event and retry.

So that is the solution in your case. If that doesn't work, let me know what SDK version you are using.

Best regards,

Edvin

[TermiteUser]

Hi, 

I was testing your solution but i encountered another problem...
When I send 4 packets now on the peripheral I have :

<error> app: Failed receiving NUS message. Error 0x4.
<error> app: ERROR 4 [NRF_ERROR_NO_MEM] 
PC at: 0x00045DDD

On err_code = app_uart_put(p_evt->params.rx_data.p_data[i]);

but i didn't have that issue before i don't know why suddenly i have this problem

Best regards,

[Edvin]

Did you try to step into app_uart_put() and check why it returned NRF_ERROR_NO_MEM (4)?

Basically, it means that your fifo buffer is full, and you need to either:

a) increase the buffer size (UART_TX_BUF_SIZE and UART_RX_BUF_SIZE)

b) wait until the UART has processed some of the buffer, and try again:

while (app_uart_put(...) == NRF_ERROR_NO_MEM)
{
    // Wait.
}

BR,
Edvin

[TermiteUser]

Hi,

I fixed the app_uart_put() issue thanks to your solution b) 

But I noticed that I have a strange bug which is : 

- When I send 244 bytes per packet I have the proper behavior which is each time I receive a packet I stock it in the external memory of the board with QSPI. So here I have stored the 4 packets

- When I send 120 bytes per packet I receive 2 packets then I store only the 2nd packet in the memory. So here I have stored 2 packets  

Here is my code : 

static void nus_data_handler(ble_nus_evt_t * p_evt)
{

    if (p_evt->type == BLE_NUS_EVT_RX_DATA)
    {
        uint32_t err_code;

        NRF_LOG_INFO("Received data from BLE NUS. Writing data on UART.");
//        NRF_LOG_HEXDUMP_INFO(p_evt->params.rx_data.p_data, p_evt->params.rx_data.length);
		NRF_LOG_INFO("Data length : %d", p_evt->params.rx_data.length );

         for (uint32_t i = 0; i < p_evt->params.rx_data.length; ++i)
		{
			m_buffer_tx[i] = p_evt->params.rx_data.p_data[i];
		}
		m_buffer_length = p_evt->params.rx_data.length;
		data_ready = true;

        for (uint32_t i = 0; i < p_evt->params.rx_data.length; i++)
        {
            do
            {
                err_code = app_uart_put(p_evt->params.rx_data.p_data[i]);
                if ((err_code != NRF_SUCCESS) && (err_code != NRF_ERROR_NO_MEM))
                {
                    NRF_LOG_ERROR("Failed receiving NUS message. Error 0x%x. ", err_code);
                    APP_ERROR_CHECK(err_code);
                }
            } while (err_code == NRF_ERROR_NO_MEM);
        }
        if (p_evt->params.rx_data.p_data[p_evt->params.rx_data.length - 1] == '\r')
        {
            while (app_uart_put('\n') == NRF_ERROR_NO_MEM);
        }
    }

}

int main(void)
{
    bool erase_bonds;
	ret_code_t err_code;
    // Initialize.
    uart_init();
    log_init();
    timers_init();
    buttons_leds_init(&erase_bonds);
    power_management_init();
    ble_stack_init();
    gap_params_init();
    gatt_init();
    services_init();
    advertising_init();
    conn_params_init();
	
	uint32_t adrShift = 0;
    uint32_t pktCount = 0;
    unsigned long long dataSize = 0;

    nrf_drv_qspi_config_t config = NRF_DRV_QSPI_DEFAULT_CONFIG;

	err_code = nrf_drv_qspi_init(&config, qspi_handler, NULL);
	APP_ERROR_CHECK(err_code);
	NRF_LOG_INFO("QSPI example started.");

	configure_memory();

	m_finished = false;
	err_code = nrf_drv_qspi_erase(NRF_QSPI_ERASE_LEN_64KB, 0);
	APP_ERROR_CHECK(err_code); 
	WAIT_FOR_PERIPH();
	NRF_LOG_INFO("Process of erasing first block start");

    // Start execution.
    printf("\r\nUART started.\r\n");
    NRF_LOG_INFO("Debug logging for UART over RTT started.");
    advertising_start();

    // Enter main loop.
    for (;;)
    {
        idle_state_handle();
        if (data_ready == true)
			{
					NRF_LOG_INFO("I'm here2");
				{
					err_code = nrf_drv_qspi_write(m_buffer_tx, m_buffer_length, adrShift);
					APP_ERROR_CHECK(err_code);
					WAIT_FOR_PERIPH(); 
					NRF_LOG_INFO("Process of writing data start");
					NRF_LOG_FLUSH();

					err_code = nrf_drv_qspi_read(m_buffer_rx, m_buffer_length, adrShift);
					WAIT_FOR_PERIPH();
					NRF_LOG_INFO("Data read");
					NRF_LOG_INFO("Compare...");
                    NRF_LOG_FLUSH();
					if (memcmp(m_buffer_tx, m_buffer_rx, m_buffer_length) == 0)
					{
						NRF_LOG_INFO("Data consistent");
                        NRF_LOG_FLUSH();
						data_ready = false;
					}
					else
					{
						NRF_LOG_INFO("Data inconsistent");
                        NRF_LOG_FLUSH();
                        NRF_LOG_HEXDUMP_INFO(m_buffer_rx, m_buffer_length);
						data_ready = false;
					}
                    adrShift = adrShift + m_buffer_length;
                    pktCount++;
                    dataSize = dataSize + m_buffer_length;
					NRF_LOG_INFO("Data size : %d octet", dataSize);
                    NRF_LOG_FLUSH();
			}
    }
}

[Edvin]

TermiteUser said:

- When I send 120 bytes per packet I receive 2 packets then I store only the 2nd packet in the memory. So here I have stored 2 packets  

 What does this mean? Do you store only 1 or 2 packets?

Perhaps the interrupts are too close, so you don't have enough time to do whatever you are doing in your main loop?

BR,

Edvin

[TermiteUser]

Sorry if i wasn't clear enough.

What I meant is that I store in total 2 packets for the 120 bytes case when I should be storing 4. And the storing process is as follow : 2 packets received the 2nd packet is stored and again  2 packets received the 2nd packet is stored. It's like I receive packet too fast before I can store it. 

I didn't use an interrupts I use a flag that I put to true when the data is loaded and I put it to false when the storing process is done. 

But yeah it feels like I don't have time to store my data. 

But what I don't understand is why I don't have this issue with 244 bytes packets. It's like since it takes more time to process 244 bytes it has more time to store the data.

[Edvin]

TermiteUser said:

But what I don't understand is why I don't have this issue with 244 bytes packets. It's like since it takes more time to process 244 bytes it has more time to store the data.

That depends on how often you receive 244 bytes vs. how often you receive 120 bytes. 

In BLE there is something called a connection interval. The master and slave (central and peripheral) only communicate once every connection interval. Whenever you send data from one device to another, it will store the data in a queue, and send it at the next connection event (one connection event every connection interval). If you store two smaller packets instead of one large, they are probably sent in the same connection event, meaning you will receive them back to back.

This boils down to application logic. How is your application supposed to handle the case where you get a new event with new data before the previous data has been stored? Have you tried setting a flag when you are done saving the data in your main loop, and checking this flag before you replace the data in m_buffer_tx[]? That doesn't solve the issue, but it may highlight the weakness of your implementation?

Perhaps you need more buffers? Try doubling buffering the m_buffer_tx[]. Basically, set up m_buffer_tx1[] and m_buffer_tx2[], and write to them every other time. 

[TermiteUser]

I suspected that the connection interval has some impact on how I receive my packets but there is something that I don't understand. 

Each time I have that event p_evt->type == BLE_NUS_EVT_RX_DATA

I take the data and store it in m_buffer_tx[]. That is working perfectly. Right after I do that I set my flag data_ready to true and so an event should trigger in my main.

In case that the packet is 244 bytes right after my m_buffer_tx[] has its data it goes to my main loop and flash the data.

Now if the data is too small. After data_ready is set to true it goes to my main loop but another event p_evt->type == BLE_NUS_EVT_RX_DATA pop out so it doesn't complete his task in the main and it does another p_evt->type == BLE_NUS_EVT_RX_DATA which load m_buffer_tx[] again. 
Why does it not continue his task ? Shouldn't the main loop takes priority ? 

At least that the behavior that my logs tell me :

<info> app: Received data from BLE NUS. Writing data on UART.
<info> app: Data length : 120
<info> app: In main loop
<info> app: Received data from BLE NUS. Writing data on UART.
<info> app: Data length : 120
<info> app: Process of writing data start
<info> app: Data read
<info> app: Compare...
<info> app: Data consistent
<info> app: Data size : 120 octet
<info> app: Received data from BLE NUS. Writing data on UART.
<info> app: Data length : 120
<info> app: In main loop
<info> app: Received data from BLE NUS. Writing data on UART.
<info> app: Data length : 120
<info> app: Process of writing data start
<info> app: Data read
<info> app: Compare...
<info> app: Data consistent
<info> app: Data size : 240 octet

[Edvin]

The main loop has the lowest priority, so if you receive any interrupts, the main loop will be halted. Since your interrupt overwrites the m_buffer_tx[], the main loop will not have any way to continue with the previous data when your interrupt has written new data to m_buffer_tx[].

[TermiteUser]

Can I change the priority so my main loop has a bit more priority at least over BLE_NUS_EVT_RX_DATA ? 

[Edvin]

Not possible. You could handle the SPI inside the interrupt by calling a function from the interrupt. But if you spend too long time, you risk loosing future BLE events. 

I suggest you try to double buffer the m_buffer_tx[]. Even though you get two events quite quickly, there is a lot of time between the connection events to handle your data. Alternatively you can look into something called a ring buffer.

BR,

Edvin

[TermiteUser]

I see I will try to implement your solution then. Thanks for that.

That's one problem that has been solved. Unfortunately I still have my initial my problem which involve BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE.

I tested it and I did trigger the event but i was wondering if that it's normal that It triggers after I send all my packets instead of triggering after one packet. 

That's my logs : 

<info> app: packet sent
<info> app: packet sent
<info> app: packet sent
<info> app: packet sent
<info> app: Buffer empty
<info> app: Buffer empty
<info> app: Buffer empty
<info> app: Buffer empty

For information the version of my SDK is nRF5_SDK_17.0.2_d674dde
And I put the event in the void ble_evt_handler(ble_evt_t const * p_ble_evt, void * p_context)