nRF52DK nRF52832 UART asynchronous receive

I am working through the Nordic Developer Academy and got stuck at lesson 4 (UART receive)

https://academy.nordicsemi.com/courses/nrf-connect-sdk-fundamentals/lessons/lesson-4-serial-communication-uart/topic/uart-driver/

In particular, I am confused about this part:

I have created a sample project and connected external CP2102 USB->Serial adapter to P0.06 and P0.08 pins.

The code that I use:

/*
 * Copyright (c) 2012-2014 Wind River Systems, Inc.
 *
 * SPDX-License-Identifier: Apache-2.0
 */

#include <zephyr/kernel.h>
#include <zephyr/drivers/gpio.h>
#include "stdio.h"
#include "zephyr/drivers/uart.h"

const struct device *uart = DEVICE_DT_GET(DT_NODELABEL(uart0));

static uint8_t tx_buf[] =  {"nRF Connect SDK Fundamentals Course \n\r"};
static uint8_t rx_buf[10] = {0}; //A buffer to store incoming UART data 

const struct uart_config uart_cfg = {
		.baudrate = 115200,
		.parity = UART_CFG_PARITY_NONE,
		.stop_bits = UART_CFG_STOP_BITS_1,
		.data_bits = UART_CFG_DATA_BITS_8,
		.flow_ctrl = UART_CFG_FLOW_CTRL_NONE
	};

static void uart_cb(const struct device *dev, struct uart_event *evt, void *user_data)
{
	switch (evt->type) {
	
	case UART_TX_DONE:
		printf("transmission complete \n");
		break;

	case UART_TX_ABORTED:
		// do something
		break;
		
	case UART_RX_RDY:
		printf("rx rdy \n");
		if((evt->data.rx.len) != 0){
			printf("data received = %s \n", evt->data.rx.buf[evt->data.rx.offset]);
		}


		
		break;

	case UART_RX_BUF_REQUEST:
		printf("requesting buffer \n");
		// do something
		break;

	case UART_RX_BUF_RELEASED:
		printf("buffer released \n");
		// do something
		break;
		
	case UART_RX_DISABLED:
		printf("rx disabled \n");
		uart_rx_enable(dev, rx_buf, sizeof(rx_buf), 100);
		break;

	case UART_RX_STOPPED:
		// do something
		break;
		
	default:
		break;
	}
}


int main(void)
{	

	if (!device_is_ready(uart)) {
    	return;
	}

	int err;
	err = uart_callback_set(uart, uart_cb, NULL);
	if (err) {
		return err;
	}

	uart_rx_enable(uart, rx_buf, sizeof(rx_buf), 100);


	err = uart_tx(uart, tx_buf, sizeof(tx_buf), SYS_FOREVER_US);
	if (err) {
		return err;
	}



	while(1){
		k_msleep(1000);
	}
	return 0;
}

I am having issues understanding how to properly print out all the received data:

I tried to do:

	case UART_RX_RDY:
		printf("rx rdy \n");
		if((evt->data.rx.len) != 0){
			printf("data received = %s \n", evt->data.rx.buf[evt->data.rx.offset]);
		}

		break;

but when I send the data via UART (using Termite) , the following is printed:

I would appreciate if someone could clarify how to correctly print out all the received data.  Thanks in advance

Just for testing, I have also tried to print:

    case UART_RX_RDY:
        printf("rx rdy \n");
        printf("data: %s \n", rx_buf);
        break;
 
and the logs are as following: (captured using Termite):
 
As you can see, it receives the first message (ping) correctly, but after that, the buffer overflows (rx_buf is 10 bytes size) and then it cannot print out the data correctly)
Parents Reply Children
  •    Thank you for the input, it's been very valuable to the discussion

    Regarding answering directly to a specific comment, you can use the quote funcitonality. 
     

    zazas321 said:
    AHaug Hello. It has been a while. Perhaps you had some time to look at our latest discussion with Achim Kraus ?

    We have discovered some interesting things about ASYNC UART and it would be really nice to get to the bottom of this.

    @zazas321, I've seen the discussion that has been ongoing here and I have nothing more to contribute to it other than the items that has already been discussed.

    I find in my own experiments as well that a larger buffer is required to allow for enough time to pass so that the buffers can fill, send, swap and empty properly

    Kind regards,
    Andreas

  • It has been a while but I still believe some things are not fully clear regarding ASYNC UART. Perhaps some things will be clarified at some point:

    POINT 1

    The async UART lesson in the code academy (https://academy.nordicsemi.com/courses/nrf-connect-sdk-fundamentals/lessons/lesson-4-serial-communication-uart/topic/exercise-1-5/)
    can only be used in cases where the fixed length serial data is being received which is not what most UART use cases are like.

    POINT 2

    In order to use async UART when trying to receive varying length serial data (strings) with terminator, double buffer approach should be used because we need to handle a scenario where the buffer fills up but the full message hasnt been received and we need to stitch 2 buffers together to build a complete message.

    I have created some test code to test this out:

    /*
     * Copyright (c) 2012-2014 Wind River Systems, Inc.
     *
     * SPDX-License-Identifier: Apache-2.0
     */
    
    #include <zephyr/kernel.h>
    #include <zephyr/drivers/gpio.h>
    #include "stdio.h"
    #include "my_gpio.h"
    #include "zephyr/drivers/uart.h"
    #include <zephyr/sys/ring_buffer.h>
    
    #define LOG_LEVEL 4
    #include <zephyr/logging/log.h>
    LOG_MODULE_REGISTER(nrf52_learning);
    
    #define UART_BUF_SIZE 24
    
    #define UART_RX_TIMEOUT_MS 1000
    K_SEM_DEFINE(rx_disabled, 0, 1);
    
    // UART RX primary buffers
    uint8_t uart_double_buffer[2][UART_BUF_SIZE];
    
    uint8_t *uart_buf_next = uart_double_buffer[1];
    
    uint8_t complete_message[UART_BUF_SIZE];
    uint8_t complete_message_counter = 0;
    bool currently_active_buffer = 1; // 0 - uart_double_buffer[0] is active, 1 - uart_double_buffer[1] is active
    
    static const struct device *dev_uart;
    
    static void uart_cb(const struct device *dev, struct uart_event *evt, void *user_data)
    {
    
    	switch (evt->type)
    	{
    
    	case UART_TX_DONE:
    		printf("transmission complete \n");
    		break;
    
    	case UART_TX_ABORTED:
    		// do something
    		break;
    
    	case UART_RX_RDY:
    
    		printf("Received %i bytes \n", evt->data.rx.len);
    		printf("Offset = %i  \n", evt->data.rx.offset);
    
    		printf("Constructing a complete message \n");
    		if (currently_active_buffer == 0)
    		{
    			// read all characters one by one till new line is found
    			for (int i = 0 + evt->data.rx.offset; i < UART_BUF_SIZE; i++)
    			{
    				complete_message[complete_message_counter] = uart_double_buffer[0][i];
    				complete_message_counter++;
    				if (uart_double_buffer[0][i] == '\n')
    				{
    					printf("new line found at buffer 0 index = %i \n", i);
    					complete_message_counter = 0;
    					printf("complete_message = %s \n", complete_message);
    					memset(&complete_message, 0, sizeof(complete_message)); // clear out the buffer to prepare for next read.
    					break;
    				}
    			}
    		}
    
    		if (currently_active_buffer == 1)
    		{
    			// read all characters one by one till new line is found
    			for (int i = 0 + evt->data.rx.offset; i < UART_BUF_SIZE; i++)
    			{
    				complete_message[complete_message_counter] = uart_double_buffer[1][i];
    				complete_message_counter++;
    				if (uart_double_buffer[1][i] == '\n')
    				{
    					printf("new line found at buffer 1 index = %i \n", i);
    					complete_message_counter = 0;
    					printf("complete_message = %s \n", complete_message);
    					memset(&complete_message, 0, sizeof(complete_message)); // clear out the buffer to prepare for next read.
    					break;
    				}
    			}
    		}
    
    		break;
    
    	case UART_RX_BUF_REQUEST:
    		uart_rx_buf_rsp(dev_uart, uart_buf_next, UART_BUF_SIZE);
    		currently_active_buffer = !currently_active_buffer;
    		if (currently_active_buffer == 0)
    		{
    			printf("currently active buffer is uart_double_buffer[0] \n");
    		}
    		else
    		{
    			printf("currently active buffer is uart_double_buffer[1] \n");
    		}
    		break;
    
    	case UART_RX_BUF_RELEASED:
    		printf("Old buffer has been released \n");
    		uart_buf_next = evt->data.rx_buf.buf;
    		break;
    
    	case UART_RX_DISABLED:
    		printf("rx disabled \n");
    		k_sem_give(&rx_disabled);
    		break;
    
    	case UART_RX_STOPPED:
    		// do something
    		break;
    
    	default:
    		break;
    	}
    }
    
    void app_uart_init()
    {
    	dev_uart = DEVICE_DT_GET(DT_NODELABEL(uart0));
    
    	if (!device_is_ready(dev_uart))
    	{
    		return 0;
    	}
    
    	int err;
    	err = uart_callback_set(dev_uart, uart_cb, NULL);
    	if (err)
    	{
    		return err;
    	}
    	uart_rx_enable(dev_uart, uart_double_buffer[0], UART_BUF_SIZE, UART_RX_TIMEOUT_MS);
    }
    
    int main(void)
    {
    	app_uart_init();
    }

    and prj.conf

    CONFIG_SERIAL=y
    CONFIG_UART_ASYNC_API=y
    CONFIG_LOG=y
    
    
    
    

    And I have tested it out on the nRF52840DK NRF52840

    The problem with the above code is that once the buffer fills up (UART_BUF_SIZE set to 24), the complete message will not be constructed properly out of 2 buffers. This can be easily observed here:

    POINT 3

    After many hours of debugging the code above, I have figured out what was causing the issues. It turned out to be printf staments. I have removed most of the printf statements and only left the complete_message print. The full code:

    /*
     * Copyright (c) 2012-2014 Wind River Systems, Inc.
     *
     * SPDX-License-Identifier: Apache-2.0
     */
    
    #include <zephyr/kernel.h>
    #include <zephyr/drivers/gpio.h>
    #include "stdio.h"
    #include "my_gpio.h"
    #include "zephyr/drivers/uart.h"
    #include <zephyr/sys/ring_buffer.h>
    
    #define LOG_LEVEL 4
    #include <zephyr/logging/log.h>
    LOG_MODULE_REGISTER(nrf52_learning);
    
    #define UART_BUF_SIZE 24
    
    #define UART_RX_TIMEOUT_MS 1000
    K_SEM_DEFINE(rx_disabled, 0, 1);
    
    // UART RX primary buffers
    uint8_t uart_double_buffer[2][UART_BUF_SIZE];
    
    uint8_t *uart_buf_next = uart_double_buffer[1];
    
    uint8_t complete_message[UART_BUF_SIZE];
    uint8_t complete_message_counter = 0;
    bool currently_active_buffer = 1; // 0 - uart_double_buffer[0] is active, 1 - uart_double_buffer[1] is active
    
    static const struct device *dev_uart;
    
    static void uart_cb(const struct device *dev, struct uart_event *evt, void *user_data)
    {
    
    	switch (evt->type)
    	{
    
    	case UART_TX_DONE:
    		//printf("transmission complete \n");
    		break;
    
    	case UART_TX_ABORTED:
    		// do something
    		break;
    
    	case UART_RX_RDY:
    
    		//printf("Received %i bytes \n", evt->data.rx.len);
    		//printf("Offset = %i  \n", evt->data.rx.offset);
    
    		//printf("Constructing a complete message \n");
    		if (currently_active_buffer == 0)
    		{
    			// read all characters one by one till new line is found
    			for (int i = 0 + evt->data.rx.offset; i < UART_BUF_SIZE; i++)
    			{
    				complete_message[complete_message_counter] = uart_double_buffer[0][i];
    				complete_message_counter++;
    				if (uart_double_buffer[0][i] == '\n')
    				{
    					//printf("new line found at buffer 0 index = %i \n", i);
    					complete_message_counter = 0;
    					printf("complete_message = %s \n", complete_message);
    					memset(&complete_message, 0, sizeof(complete_message)); // clear out the buffer to prepare for next read.
    					break;
    				}
    			}
    		}
    
    		if (currently_active_buffer == 1)
    		{
    			// read all characters one by one till new line is found
    			for (int i = 0 + evt->data.rx.offset; i < UART_BUF_SIZE; i++)
    			{
    				complete_message[complete_message_counter] = uart_double_buffer[1][i];
    				complete_message_counter++;
    				if (uart_double_buffer[1][i] == '\n')
    				{
    					//printf("new line found at buffer 1 index = %i \n", i);
    					complete_message_counter = 0;
    					printf("complete_message = %s \n", complete_message);
    					memset(&complete_message, 0, sizeof(complete_message)); // clear out the buffer to prepare for next read.
    					break;
    				}
    			}
    		}
    
    		break;
    
    	case UART_RX_BUF_REQUEST:
    		uart_rx_buf_rsp(dev_uart, uart_buf_next, UART_BUF_SIZE);
    		currently_active_buffer = !currently_active_buffer;
    		if (currently_active_buffer == 0)
    		{
    			//printf("currently active buffer is uart_double_buffer[0] \n");
    		}
    		else
    		{
    			//printf("currently active buffer is uart_double_buffer[1] \n");
    		}
    		break;
    
    	case UART_RX_BUF_RELEASED:
    		//printf("Old buffer has been released \n");
    		uart_buf_next = evt->data.rx_buf.buf;
    		break;
    
    	case UART_RX_DISABLED:
    		//printf("rx disabled \n");
    		k_sem_give(&rx_disabled);
    		break;
    
    	case UART_RX_STOPPED:
    		// do something
    		break;
    
    	default:
    		break;
    	}
    }
    
    void app_uart_init()
    {
    	dev_uart = DEVICE_DT_GET(DT_NODELABEL(uart0));
    
    	if (!device_is_ready(dev_uart))
    	{
    		return 0;
    	}
    
    	int err;
    	err = uart_callback_set(dev_uart, uart_cb, NULL);
    	if (err)
    	{
    		return err;
    	}
    	uart_rx_enable(dev_uart, uart_double_buffer[0], UART_BUF_SIZE, UART_RX_TIMEOUT_MS);
    }
    
    int main(void)
    {
    	app_uart_init();
    }

    and prj.conf:

    CONFIG_SERIAL=y
    CONFIG_UART_ASYNC_API=y
    CONFIG_LOG=y

    And when I try to send the exact same sequence of messages using serial terminal, it seems to work fine even after the UART buffer fills up:

    POINT 4

    4. Additionally, I have found out that if you add options :

    CONFIG_UART_0_ASYNC=y
    CONFIG_UART_0_NRF_HW_ASYNC=y
    CONFIG_UART_0_NRF_HW_ASYNC_TIMER=2
    CONFIG_NRFX_TIMER2=y

    in the prj.conf, then the complete messages will be received even if I use many printf statements. I do not fully understand why and how which is quite frustrating.

    The full code:

    /*
     * Copyright (c) 2012-2014 Wind River Systems, Inc.
     *
     * SPDX-License-Identifier: Apache-2.0
     */
    
    #include <zephyr/kernel.h>
    #include <zephyr/drivers/gpio.h>
    #include "stdio.h"
    #include "my_gpio.h"
    #include "zephyr/drivers/uart.h"
    #include <zephyr/sys/ring_buffer.h>
    
    #define LOG_LEVEL 4
    #include <zephyr/logging/log.h>
    LOG_MODULE_REGISTER(nrf52_learning);
    
    #define UART_BUF_SIZE 24
    
    #define UART_RX_TIMEOUT_MS 1000
    K_SEM_DEFINE(rx_disabled, 0, 1);
    
    // UART RX primary buffers
    uint8_t uart_double_buffer[2][UART_BUF_SIZE];
    
    uint8_t *uart_buf_next = uart_double_buffer[1];
    
    uint8_t complete_message[UART_BUF_SIZE];
    uint8_t complete_message_counter = 0;
    bool currently_active_buffer = 1; // 0 - uart_double_buffer[0] is active, 1 - uart_double_buffer[1] is active
    
    static const struct device *dev_uart;
    
    static void uart_cb(const struct device *dev, struct uart_event *evt, void *user_data)
    {
    
    	switch (evt->type)
    	{
    
    	case UART_TX_DONE:
    		printf("transmission complete \n");
    		break;
    
    	case UART_TX_ABORTED:
    		// do something
    		break;
    
    	case UART_RX_RDY:
    
    		printf("Received %i bytes \n", evt->data.rx.len);
    		printf("Offset = %i  \n", evt->data.rx.offset);
    
    		printf("Constructing a complete message \n");
    		if (currently_active_buffer == 0)
    		{
    			// read all characters one by one till new line is found
    			for (int i = 0 + evt->data.rx.offset; i < UART_BUF_SIZE; i++)
    			{
    				complete_message[complete_message_counter] = uart_double_buffer[0][i];
    				complete_message_counter++;
    				if (uart_double_buffer[0][i] == '\n')
    				{
    					printf("new line found at buffer 0 index = %i \n", i);
    					complete_message_counter = 0;
    					printf("complete_message = %s \n", complete_message);
    					memset(&complete_message, 0, sizeof(complete_message)); // clear out the buffer to prepare for next read.
    					break;
    				}
    			}
    		}
    
    		if (currently_active_buffer == 1)
    		{
    			// read all characters one by one till new line is found
    			for (int i = 0 + evt->data.rx.offset; i < UART_BUF_SIZE; i++)
    			{
    				complete_message[complete_message_counter] = uart_double_buffer[1][i];
    				complete_message_counter++;
    				if (uart_double_buffer[1][i] == '\n')
    				{
    					printf("new line found at buffer 1 index = %i \n", i);
    					complete_message_counter = 0;
    					printf("complete_message = %s \n", complete_message);
    					memset(&complete_message, 0, sizeof(complete_message)); // clear out the buffer to prepare for next read.
    					break;
    				}
    			}
    		}
    
    		break;
    
    	case UART_RX_BUF_REQUEST:
    		uart_rx_buf_rsp(dev_uart, uart_buf_next, UART_BUF_SIZE);
    		currently_active_buffer = !currently_active_buffer;
    		if (currently_active_buffer == 0)
    		{
    			printf("currently active buffer is uart_double_buffer[0] \n");
    		}
    		else
    		{
    			printf("currently active buffer is uart_double_buffer[1] \n");
    		}
    		break;
    
    	case UART_RX_BUF_RELEASED:
    		printf("Old buffer has been released \n");
    		uart_buf_next = evt->data.rx_buf.buf;
    		break;
    
    	case UART_RX_DISABLED:
    		printf("rx disabled \n");
    		k_sem_give(&rx_disabled);
    		break;
    
    	case UART_RX_STOPPED:
    		// do something
    		break;
    
    	default:
    		break;
    	}
    }
    
    void app_uart_init()
    {
    	dev_uart = DEVICE_DT_GET(DT_NODELABEL(uart0));
    
    	if (!device_is_ready(dev_uart))
    	{
    		return 0;
    	}
    
    	int err;
    	err = uart_callback_set(dev_uart, uart_cb, NULL);
    	if (err)
    	{
    		return err;
    	}
    	uart_rx_enable(dev_uart, uart_double_buffer[0], UART_BUF_SIZE, UART_RX_TIMEOUT_MS);
    }
    
    int main(void)
    {
    	app_uart_init();
    }

    and prj.conf:

    CONFIG_SERIAL=y
    CONFIG_UART_ASYNC_API=y
    CONFIG_LOG=y
    
    
    
    CONFIG_UART_0_ASYNC=y
    CONFIG_UART_0_NRF_HW_ASYNC=y
    CONFIG_UART_0_NRF_HW_ASYNC_TIMER=2
    CONFIG_NRFX_TIMER2=y

    Despite the solution being found, it is still not fully clear to me what is the best way to handle ASYNC UART varying length data reception. I could not find enough information/examples available to fully understand the different methods of handling ASYNC UART reception and I am hoping to get some clarifications regarding this.

    • Is this expected behaviour that a few printf statements in uart_cb causes weird behaviour as have been shown above?

    •  If above is true, I am concerned about other high priority tasks or callbacks interrupting the UART reception and causing similar issues even when all print statements are removed from the callback itself. Is ASYNC UART affected by other Zephyr RTOS threads running or it is independent and not affected at all?

    • During the discussion above it has been mentioned that it is recommended to use larger UART_BUF_SIZE but that did not help in any way. The only thing that does is just simply requires more serial data to be received before it fills up and eventually breaks.

    • Throughout this discussion, other things have been suggested such as using additional config options:

    CONFIG_UART_0_ASYNC=y
    CONFIG_UART_0_NRF_HW_ASYNC=y
    CONFIG_UART_0_NRF_HW_ASYNC_TIMER=2
    CONFIG_NRFX_TIMER2=y

    which seem to help when having multiple print statements in the callback. 

    I would highly appreciate if someone with good Zephyr and ASYNC UART knowledge could shed some light here and cover the issues that I have encountered and the solutions that I have found. I believe the solutions that I have discovered are not the most optimal and not the best way to handle UART ASYNC data reception. I also believe that this should be relevant for other developers who are working with ASYNC UART.

  • Hello,

    Andreas is currently busy with other tasks, so I will have a look at this ticket. 

    Please note that there is a lot of information here, but I have tried to get a reasonable overview. 

    zazas321 said:
    POINT 1

    Yes. This is a very simplified application. I suspect you are looking for functionality closer to the one found in ncs\nrf\samples\bluetooth\peripheral_uart. Please note that this doesn't echo the data back on the UART, but it will transmit the UART data over BLE to the connected device. Please see the sample description.

    zazas321 said:
    POINT 2

    Noted. I agree.

    zazas321 said:
    POINT 3

    This makes sense, actually. 

    printf, in your case uses the UART backend, so every time you send a message, or possibly a character, over UART, it will trigger a new callback to the very same uart callback that printed the character in the first place. Therefore, I recommend, if you want to use the log while using the UART, you should use the logging module (LOG_INF()) with RTT backend (and not UART backend). To see how to do this, look at how it is done in the ncs\nrf\samples\bluetooth\peripheral_uart sample. 

    zazas321 said:
    Is this expected behaviour that a few printf statements in uart_cb causes weird behaviour as have been shown above?

    I wouldn't recommend using printf(), which will trigger uart callbacks inside the uart_cb.

    zazas321 said:
     If above is true, I am concerned about other high priority tasks or callbacks interrupting the UART reception and causing similar issues even when all print statements are removed from the callback itself. Is ASYNC UART affected by other Zephyr RTOS threads running or it is independent and not affected at all?

    I don't think you will see similar issues with other high priority interrupts, as long as they are not triggered recursively via the UART callback. 

    zazas321 said:
    During the discussion above it has been mentioned that it is recommended to use larger UART_BUF_SIZE but that did not help in any way. The only thing that does is just simply requires more serial data to be received before it fills up and eventually breaks.

    I agree. That will just postpone the issue. 

    zazas321 said:
    I would highly appreciate if someone with good Zephyr and ASYNC UART knowledge could shed some light here and cover the issues that I have encountered and the solutions that I have found.

    I agree that this seems like a good solution for this need. However, I suggest not using the UART for log messages at all inside the uart callback handler. Either use no log, or use the RTT backend.

    Best regards,

    Edvin

Related