Logging using USB serial port on nRF52

jbussmann

I am developing firmware on a Arduino Nano 33 on Windows 10. It is for an upcoming project with a custom board based on the nRF52840 powered ublox NINA-B306. Since this board will not have a UART interface but I would still like to use the Zephyr logging, I thought logging through USB serial port might be a good idea.

I watched “Zephyr 101 - Application Logging and Log Backends” which gave me hope to get tis to work but I continue to fail.

I can printk() to UART using the “Hello World” example.
I can extend the example by enabling logging and LOG_XXX() to UART.
I can printk() to the USB serial port using the “Console over CDC ACM UART” example.
Extending the example by enabling logging with “CONFIG_LOG=y” makes the serial port (and the device as a whole) not being recognised anymore by my computer. When trying around I have also been in the situation where the device was recognised but failed to install properly.

The video suggests this should be possible and makes it look very easy to redirect the console output to the USB serial port by changing the chosen node in the device tree. Am I missing some important concepts or configurations? Can it be a problem on the computer side of the setup? In case logging can be redirected to the USB serial port, what information can I supply to help figure out where I am stuck?

jaredwolff

Hey jbussmann

Check out the samples here:

https://github.com/circuitdojo/air-quality-wing-zephyr-demo/tree/main/basic

Specifically look at the overlays for the Particle Xenon. The most important part being:

# USB
CONFIG_USB=y
CONFIG_USB_DEVICE_STACK=y
CONFIG_USB_DEVICE_PRODUCT="Air Quality Wing"
CONFIG_USB_UART_CONSOLE=y

CONFIG_UART_CONSOLE_ON_DEV_NAME="CDC_ACM_0"
CONFIG_UART_INTERRUPT_DRIVEN=y
CONFIG_UART_LINE_CTRL=y

Also make sure you have

# Logging
CONFIG_LOG=y
CONFIG_CONSOLE=y

enabled.

By default in the DT definitions they call out using UART0 for the console which gets mapped to in the aforementioned configuration.

Hope that helps!

jbussmann

Hi jaredwolff

Thank you for the quick reply. Unfortunately following lines of configuration are not accepted, as they appear to be deprecated in the most recent version of the nRF Connect SDK.

CONFIG_USB=y
CONFIG_UART_CONSOLE_ON_DEV_NAME="CDC_ACM_0"
CONFIG_USB_UART_CONSOLE=y

None the less I got logging over USB working now. CONFIG_UART_INTERRUPT_DRIVEN=y made the difference. Which is a bit strange since configuring USB CDC ACM Class support should also configure UART Interrupt support.

Now at least I don’t feel completely dumb, since this config was not specifically mentioned in the video. Thanks again.

jaredwolff

@jaredwolff let me get back to you on a newer SDK version configuration setup.

jbussmann

Meanwhile I assembled my custom board and sure enough, logging stopped working again. So back to square one with the exception that I still have a working example.

Long story short: after doing a lot of digging I found the true problem to be enabling debugging options in the build configuration. So it seems I got it working by accident, as I was tired when trying your suggestions and forgot to check “Enable debug options” when I created a new example. Feel free to strike through the false information above, as I cannot find a way to edit the post.

Enabling debug options changes the compiler flags and some Kconfig options. I will post again if I find the specific option which breaks the logs. Until then I am just happy it finally and reliably works. 🙂

Do you think this can be considered to be a bug and should be reported to the Zephyr Project and/or the nRF devs?

jaredwolff

jbussmann sorry for the delay on my part.

In newer versions of Zephyr your USB console should be set up in the overlay. Example:

chosen {
	zephyr,console = &cdc_acm_uart0;
	zephyr,shell-uart = &cdc_acm_uart0;
};

zephyr_udc0: &usbd {
	compatible = "nordic,nrf-usbd";
	status = "okay";
	cdc_acm_uart0: cdc_acm_uart0 {
		compatible = "zephyr,cdc-acm-uart";
		label = "CDC_ACM_0";
	};
};

This will redirect your UART console to USB.

Then within you project config set these guys:

CONFIG_CONSOLE=y
CONFIG_UART_CONSOLE=y
CONFIG_LOG=y
CONFIG_LOG_BACKEND_UART=y
CONFIG_UART_CONSOLE=y
CONFIG_USB_DEVICE_STACK=y
CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=y

You can also set VID & PID using these config variables:

CONFIG_USB_DEVICE_MANUFACTURER="Nordic Semiconductor"
CONFIG_USB_DEVICE_PRODUCT="Thingy:91 UART"
CONFIG_USB_DEVICE_VID=0x1915
CONFIG_USB_DEVICE_PID=0x9100
CONFIG_USB_DEVICE_SN="THINGY91 12PLACEHLDRS" # This is overridden at runtime

Without knowing what you set exactly it’s hard to tell if it will reliably work in the future. Glad you got something going though!

jbussmann

jaredwolff thank you for your repeated replies. Here are the exact steps for a minimal reproducible example on nRF Connect SDK v2.1.0 with a Arduino nano 33 BLE:

Create new application from zephyr/samples/subsys/usb/console.
Create build configuration for arduino_nano_33_ble and tick “Enable debug options”.
Build and flash. Observe: COM port opens and “Hello World! arm” is received.
Add CONFIG_LOG=y to prj.conf.
Build and flash. Observe: COM port is not available anymore.
Edit build configuration and untick “Enable debug options”.
Build and flash. Observe: COM port opens and “Hello World! arm” is received after a bunch of info level messages from the usb_cdc_acm module.
Optional: re-enable debug options and observe how COM port breaks again.

The device tree reflects your overlay and the full content of proj.conf is as follows:

CONFIG_USB_DEVICE_STACK=y
CONFIG_USB_DEVICE_PRODUCT="Zephyr USB console sample"

CONFIG_SERIAL=y
CONFIG_CONSOLE=y
CONFIG_UART_CONSOLE=y
CONFIG_UART_LINE_CTRL=y

CONFIG_LOG=y

As you already suggested, this configuration is rather flaky. Changing the log mode by use of CONFIG_LOG_MODE_IMMEDIATE=y or CONFIG_LOG_MODE_MINIMAL=y breaks the output again.

Using CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=y appears to be a very sensible choice. Is this documented somewhere, or do you know this form experience? Unfortunately this config only changes the problem for the worse and I could not observe any improvements at all. Continuation of the above minimal reproducible example:

Add CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=y to prj.conf.
Edit build configuration and tick “Enable debug options”.
Build and flash. Observe: COM port is still not available.
Edit build configuration and untick “Enable debug options”.
Build and flash. Observe: COM port opens and a bunch of info level messages from the usb_cdc_acm module are received, but no “Hello World! arm” messages.
Remove CONFIG_LOG=y from prj.conf.
Build and flash. Observe: COM port opens but no messages are received.

Therefore I will keep the configuration as is. Do you need any more information about my exact configuration? Do you have any of the following working:

Logging over USB COM port with debug options enabled in build config.
Logging over USB COM port without a bunch of “<inf> usb_cdc_acm: Ring buffer full, drain buffer” messages.
Minimal logging over USB COM port.
Functioning printk() with CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=y.

If so, do you mind sharing your working setup/config/hardware? When I find the time, I intend to try nRF Connect SDK v2.1.2 and v2.1.99 as well as another computer and/or another operating system. Also at some point I would like to try out the shell and see how it behaves compared to logging and printk().

jaredwolff

jbussmann Using CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=y appears to be a very sensible choice. Is this documented somewhere, or do you know this form experience?

https://docs.zephyrproject.org/3.0.0/reference/kconfig/CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT.html

It’s in the Zephyr docs but a bunch of examples use it. You also have the option of keeping this disabled but it’s on you to enable the USB stack in your application.

Therefore I will keep the configuration as is. Do you need any more information about my exact configuration?

You’re welcome to check out the samples in the link below where I have it working. Albeit an older version of Zephyr.

https://github.com/circuitdojo/air-quality-wing-zephyr-demo/tree/1fdf461da904f49fd2e82a6918346ac3eb49ab45/basic

Look at the files for particle_xenon as that’s where I have logging enabled and working.

ebernste123123

@jbussmann Thank you for the info. I was able to confirm the same thing when CONFIG_LOG is enabled and DEBUG is enabled in the build configuration.

Was anyone able to figure out why this is happening? Not having the debug log when in debug mode is an issue?

@jaredwolff The examples you showed are for an older version of Zephyr, so they don’t work. Is there anything else we can figure out why enable debug mode on the build will cause this ?

Thank you,
Eran

jaredwolff

ebernste123123 you’re welcome to open a new post. We try not yo necrobump here since a lot can change in 6 months!