Cannot get Async UART0 to work with USB CDC

[Dean]

Hello,

I first got the USB CDC Zephyr sample with interrupt driven UART to work just fine. 

But because I want to to be able to TX outside of interrupts I tried to convert that sample to use Async UART while using USB CDC.  I have looked at all tickets that seem related to this but nothing works, maybe because I'm using a  newer SDK version, which is v2.4.2.

When I call uart_callback_set I get -ENOSYS.   I can see all callbacks for the API are not set which is why I get this.  (I print the pointers and they are 0)

from C:\ncs\v2.4.2\zephyr\include\zephyr\drivers\uart.h

static inline int uart_callback_set(const struct device *dev,
				    uart_callback_t callback,
				    void *user_data)
{
#ifdef CONFIG_UART_ASYNC_API
	const struct uart_driver_api *api =
			(const struct uart_driver_api *)dev->api;

	if (api->callback_set == NULL) {
		return -ENOSYS;
	}

	return api->callback_set(dev, callback, user_data);
#else
	ARG_UNUSED(dev);
	ARG_UNUSED(callback);
	ARG_UNUSED(user_data);
	return -ENOTSUP;
#endif
}

I have tried all kings of CONFIG options (from other tickets) and nothing seems to work.  I can see the ASYNC code is enabled in the file C:\ncs\v2.4.2\zephyr\drivers\serial\uart_nrfx_uarte.c.  I can not see the linkage with the calling of DEVICE_DT_GET_ONE(zephyr_cdc_acm_uart) and driver API callbacks being set correctly. 

Last configs I tried are:

CONFIG_LOG=y

CONFIG_MAIN_STACK_SIZE=1536


CONFIG_STDOUT_CONSOLE=y

CONFIG_USB_DEVICE_STACK=y
CONFIG_USB_DEVICE_PRODUCT="Zephyr CDC ACM sample"
CONFIG_USB_DEVICE_SN="0123456789ABCDEG"
CONFIG_USB_DEVICE_MANUFACTURER="Zephyr USBD CDC ACM with MS"
CONFIG_USB_DEVICE_PID=0x0002
CONFIG_USB_DEVICE_VID=0x2fe3
CONFIG_USB_DRIVER_LOG_LEVEL_ERR=y
CONFIG_USB_DEVICE_LOG_LEVEL_ERR=y
CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=n
CONFIG_USB_CDC_ACM=y
CONFIG_SERIAL=y

CONFIG_UART_ASYNC_API=y
CONFIG_UART_INTERRUPT_DRIVEN=y
CONFIG_UART_0_ASYNC=y
CONFIG_UART_0_INTERRUPT_DRIVEN=n
CONFIG_NRFX_UARTE0=y

CONFIG_UART_LINE_CTRL=y

&zephyr_udc0 {
	cdc_acm_uart0 {
		compatible = "zephyr,cdc-acm-uart";
	};
};

My Code

#include <zephyr/kernel.h>
#include <zephyr/device.h>


#include <zephyr/usb/usb_device.h>
#include <zephyr/usb/usbd.h>

#include <zephyr/drivers/uart.h>
#include <zephyr/sys/ring_buffer.h>

#include <zephyr/logging/log.h>
LOG_MODULE_REGISTER(main, LOG_LEVEL_INF);

#define RING_BUF_SIZE 1024
uint8_t ring_buffer[RING_BUF_SIZE];
struct ring_buf ringbuf;

// static void interrupt_handler(const struct device *dev, void *user_data)
// {
// 	ARG_UNUSED(user_data);

// 	LOG_INF("11");

// 	while (uart_irq_update(dev) && uart_irq_is_pending(dev)) {

// 		LOG_INF("222");

// 		if (uart_irq_rx_ready(dev)) {
// 			int recv_len, rb_len;
// 			uint8_t buffer[64];
// 			size_t len = MIN(ring_buf_space_get(&ringbuf), sizeof(buffer));

// 			recv_len = uart_fifo_read(dev, buffer, len);
// 			if (recv_len < 0) {
// 				LOG_ERR("Failed to read UART FIFO");
// 				recv_len = 0;
// 			};

// 			rb_len = ring_buf_put(&ringbuf, buffer, recv_len);
// 			if (rb_len < recv_len) {
// 				LOG_ERR("Drop %u bytes", recv_len - rb_len);
// 			}

// 			LOG_DBG("tty fifo -> ringbuf %d bytes", rb_len);
// 			if (rb_len) {
// 				uart_irq_tx_enable(dev);
// 			}
// 		}

// 		if (uart_irq_tx_ready(dev)) {
// 			uint8_t buffer[64];
// 			int rb_len, send_len;

// 			rb_len = ring_buf_get(&ringbuf, buffer, sizeof(buffer));
// 			if (!rb_len) {
// 				LOG_DBG("Ring buffer empty, disable TX IRQ");
// 				uart_irq_tx_disable(dev);
// 				continue;
// 			}

// 			send_len = uart_fifo_fill(dev, buffer, rb_len);
// 			if (send_len < rb_len) {
// 				LOG_ERR("Drop %d bytes", rb_len - send_len);
// 			}

// 			LOG_DBG("ringbuf -> tty fifo %d bytes", send_len);
// 		}
// 	}
// }

static uint8_t rx_buf[64] = {0}; //A buffer to store incoming UART data 

static void async_interrupt_cb(const struct device *dev, struct uart_event *evt, void *user_data)
{
	switch (evt->type) {
	
	case UART_TX_DONE:
		// do something
		break;

	case UART_TX_ABORTED:
		// do something
		break;
		
	case UART_RX_RDY:
		LOG_INF("UART_RX_RDY");
		break;

	case UART_RX_BUF_REQUEST:
		LOG_INF("UART_RX_BUF_REQUEST");
		break;

	case UART_RX_BUF_RELEASED:
		LOG_INF("UART_RX_BUF_RELEASED");
		break;
		
	case UART_RX_DISABLED:
		// do something
		break;

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

int main(void) {

	const struct device *dev;
	uint32_t baudrate, dtr = 0U;
	int ret;

	//
	// Setup USB
	//

	dev = DEVICE_DT_GET_ONE(zephyr_cdc_acm_uart);
	if (!device_is_ready(dev)) {
		LOG_ERR("CDC ACM device not ready");
		return 0;
	}

	ret = usb_enable(NULL);

	LOG_INF("Configured.......");

	if (ret != 0) {
		LOG_ERR("Failed to enable USB");
		return 0;
	}

	ring_buf_init(&ringbuf, sizeof(ring_buffer), ring_buffer);

	LOG_INF("Wait for DTR");

	while (true) {
		uart_line_ctrl_get(dev, UART_LINE_CTRL_DTR, &dtr);
		if (dtr) {
			break;
		} else {
			/* Give CPU resources to low priority threads. */
			k_sleep(K_MSEC(100));
		}
	}

	LOG_INF("DTR set");

		/* They are optional, we use them to test the interrupt endpoint */
	ret = uart_line_ctrl_set(dev, UART_LINE_CTRL_DCD, 1);
	if (ret) {
		LOG_WRN("Failed to set DCD, ret code %d", ret);
	}

	ret = uart_line_ctrl_set(dev, UART_LINE_CTRL_DSR, 1);
	if (ret) {
		LOG_WRN("Failed to set DSR, ret code %d", ret);
	}

	/* Wait 100ms for the host to do all settings */
	k_msleep(100);

	ret = uart_line_ctrl_get(dev, UART_LINE_CTRL_BAUD_RATE, &baudrate);
	if (ret) {
		LOG_WRN("Failed to get baudrate, ret code %d", ret);
	} else {
		LOG_INF("Baudrate detected: %d", baudrate);
	}


	//uart_irq_callback_set(dev, interrupt_handler);
	ret = uart_callback_set(dev, async_interrupt_cb, NULL);
	if (ret != 0) { // :TODO:
		LOG_ERR("Failed to register UART UART cb: %i", ret);
		return 0;
	}

	/* Enable rx interrupts */
	//uart_irq_rx_enable(dev);

	ret = uart_rx_enable(dev, rx_buf, sizeof(rx_buf), 100);
	if (ret != 0) { // :TODO:
		LOG_ERR("Failed to enable UART RX");
		return 0;
	}

	LOG_INF("Starting Observer Demo\n");

	LOG_ERR("Exiting %s thread", __func__);
	return 0;
}

When I connect with pyserial I always get the error NOSYS, 88.  You will note I can make some sort of connection to get the baudrate.  (below)

*** Booting Zephyr OS build v3.3.99-ncs1-1 ***
[00:00:00.416,503] <inf> main: Configured.......
[00:00:00.416,534] <inf> main: Wait for DTR
[00:00:00.420,562] <inf> usb_cdc_acm: Device suspended
[00:00:00.518,188] <inf> usb_cdc_acm: Device resumed
[00:00:00.869,995] <inf> usb_cdc_acm: Device configured
[00:00:04.319,244] <inf> main: DTR set
[00:00:04.433,929] <inf> main: Baudrate detected: 115200
[00:00:04.433,959] <err> main: Failed to register UART UART cb: -88

After spending hours on this I don't know what else to try.  Any help with this would be very much appreciated.

Async UART0 (with EasyDMA) is supposed to work with USB CDC, they are compatible?

[Dean]

The later, use Async API for USB CDC.  I need to use the uart in async mode going over USB CDC.

I did see that ticket but didn’t get any hints.

It seems like there is a disconnect on setup between the uart and usb cdc stacks.  I can see all the individual uart api callbacks are just not set, I.e.

if (api->callback_set == NULL) {

     return -ENOSYS;
}

In uart_callback_set.  So it is easy to see what is not working, but just cannot figure out why.

Thanks

[Dean]

To follow up with more, I did see from that ticket:

"The CDC ACM driver does not support the ASYNC API, and will return ENOTSUP if you try to enable the callback"

From the code:

from C:\ncs\v2.4.2\zephyr\include\zephyr\drivers\uart.h

static inline int uart_callback_set(const struct device *dev,
				    uart_callback_t callback,
				    void *user_data)
{
#ifdef CONFIG_UART_ASYNC_API
	const struct uart_driver_api *api =
			(const struct uart_driver_api *)dev->api;

	if (api->callback_set == NULL) {
		return -ENOSYS;
	}

	return api->callback_set(dev, callback, user_data);
#else
	ARG_UNUSED(dev);
	ARG_UNUSED(callback);
	ARG_UNUSED(user_data);
	return -ENOTSUP;
#endif
}

There is specific logic for CONFIG_UART_ASYNC_API use in uart_callback_set.  And this is why I get the ENOSYS error and not the ENOTSUP error as in that ticket (he was likely not specifying CONFIG_UART_ASYNC_API).

But I guess fundamentally does the CDC ACM driver support the ASYNC API? This could theoretically cause something farther up the stack to cause api->callback_set == NULL too be TRUE.

Thanks

[Sigurd Hellesvik]

CONFIG_USB_CDC_ACM selects CONFIG_UART_INTERRUPT_DRIVEN.
Do you by chance have this warning in your build log?

warning: UART_INTERRUPT_DRIVEN (defined at boards/shields/sparkfun_sara_r4/Kconfig.defconfig:24,
boards/shields/wnc_m14a2a/Kconfig.defconfig:17, soc/arm/quicklogic_eos_s3/Kconfig.defconfig:17,
drivers/serial/Kconfig:72) was assigned the value 'n' but got the value 'y'. See
http://docs.zephyrproject.org/latest/kconfig.html#CONFIG_UART_INTERRUPT_DRIVEN and/or look up
UART_INTERRUPT_DRIVEN in the menuconfig/guiconfig interface. The Application Development Primer,
Setting Configuration Values, and Kconfig - Tips and Best Practices sections of the manual might be
helpful too.

Torsten Robitzki said:

Sure, Nodic is not the only contributor to Zephyr, but if the Zephyr documentation states, that there are 3 different APIs for UARTs, I would expect either support for the 3 APIs or I would expect that the documentation states, that there are some exceptions and how to find out which implementations do not support the documented features.

For whats it's worth, I agree.

Torsten Robitzki said:

In the end, when I have the task to develop firmware for the nordic hardware, I have not much choices, but to use Zephyr (and in deed, I have to use the Nordic branch of Zephyr). And in order to find out, how to do so, I have to rely on the documentation.

That is true. I can talk to our documentation team and see if we can get a disclaimer into the CDC ACM documentation of Zephyr.

[Torsten Robitzki]

Yes, I see the KConfig warning. Would love to see an error when setting `CONFIG_UART_ASYNC_API=y`. But maybe the problem is that "normal" UART and CDC are handled by the very same configuration parameters, while they are most likely handled by very different parts of the software.

[Kyrre Aalerud]

I am so glad I found this as it has been bugging me a lot.

Earlier (2 years ago!) I had issues with CDC_ACM and discovered most of the time was spent copying data to the ring-buffer. At this time I was not able to get the async api to work so instead I moved the copying of data out of my interrupt handler and let a separate thread add data to the fifo whenever there was room for more, while at the same time never filling it completely (as I also ran into issues doing this).
I was able to get massive transfer speed improvements and do 900+ kbyte/s but posted an issue as I was seeing data corruption. I suspected this to be caused by the access to the fifo outside of ISR but lately I have become less sure. I find the corruption to be highly host dependent and on some systems it seems absent all together. It may still be an interaction between the host and device however, causing the issues.

If Nordic had added support for the async api I am hopeful they would have discovered something relating to the fifo and possibly solved multiple issues. I do see there is a device_next folder in zephyr/subsys/usb for a more flexible device descriptor setup but is this using a better approach to buffers and data?
usbd_cdc_acm.c does not appear to do things the same way as the old cdc_acm.c ?

[Torsten Robitzki]

The Zephyr cdc_acm example contains some "shortcoming", that might result in what you are observing.

In the IRQ, data to be transmitted is read into a local buffer. That buffer is then send via USB. If not all data could be send, the data is simply dropped. This situation can happen in real world applications when the receiver can not keep up with the transmitted data. And that situation is usually well handled with flow control, so there is no reason to handle this as an unavoidable error.

My solution to this, was to write my own ring buffer, that allows me to peek into the buffer, try to transmit it and to only remove that data from the buffer, that I was able to pass successfully to the USB stack.

I have searched quite some time for such a buffer in Zephyr, but couldn't find anything suitable.

[Kyrre Aalerud]

I understand what you mean. I also noticed that there was no apparent flow control yet USB is a guaranteed transmission channel in this regard. Data is also CRC checked in the stack.

The issue you discovered though, appears to match what I found about the interrupts being triggered by any data that had been sent, not when a finished transfer occurred. I observed (using SEGGER_SYSTEMVIEW) that transfers did not stop after the interrupt, but instead more data was fetched and transfer continued. What I fist thought was missing data was then sent later and caused another interrupt. This appeared to happen at the end of the ring buffer since allocating a chunk of data from buffer to send never "loops" the buffer.

Trying to use the usb/device_next/class gave me some trouble, and I wish I could find an example use. Maybe it is not ready yet or I look in wrong place? It is still using ring_buffer.c so I am not too hopeful. Not sure if it is thread-safe.