Problem getting console log esp32-s3

[shariltumin]

I had problems getting console log with USB-CDC board. ESP default console is UART0. During system development being able to see console log is important to say the least. I manage to force ESP to write log to UART1.

A needed part of sdkconfig.board where console was defined as follows:

# UART1 console output
CONFIG_ESP_CONSOLE_UART_CUSTOM=y
CONFIG_ESP_CONSOLE_UART_CUSTOM_NUM_1=y
CONFIG_ESP_CONSOLE_UART_TX_GPIO=1
CONFIG_ESP_CONSOLE_UART_RX_GPIO=3

# DEBUGGING
# -CONFIG_LOG_DEFAULT_LEVEL_VERBOSE=y
CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y
# -CONFIG_LOG_DEFAULT_LEVEL_INFO=y
# -CONFIG_LOG_DEFAULT_LEVEL_WARN=y
# -CONFIG_LOG_DEFAULT_LEVEL_ERROR=y

After the firmware was built and flashed, we need to create uart object corresponding to the console defined in sdkconfig.board.

>>> import machine
>>> c = machine.UART(1, tx=1, rx=3)
>>> c
UART(1, baudrate=115211, bits=8, parity=None, stop=1, tx=1, rx=3, rts=-1, cts=-1, txbuf=256, rxbuf=256, timeout=0, timeout_char=0)

Now take a jumper wire and short (connect) GPIO1 and GPIO3. Since the firmware was built with CONFIG_LOG_DEFAULT_LEVEL_DEBUG, debug messages will be written to the console, take for example the network module.

>>> network.WLAN(network.AP_IF).active(False)
False
>>> c.any()
240
>>> w = c.read()
>>> w
b'D (206602) modnetwork: Initializing TCP/IP\x1b[0m\r\nD (206602) esp_netif_lwip: LwIP stack has been initialized\x1b[0m\r\nD (206602) esp_netif_lwip: esp-netif has been successfully initialized\x1b[0m\r\nD (206612) modnetwork: Initializing Event Loop\x1b[0m\r\nD (206612) event: created task for loop 0x3fcf6584\x1b[0m\r\nD (206612) event: running task for loop 0x3fcf6584\x1b[0m\r\nD (20662 (225832) modnetwork: Initialized\x1b[0m\r\n'
>>> c.any()
0
>>> wlan = network.WLAN(network.STA_IF)
>>> c.read()
>>> wlan.active(True)
True
>>> c.read()
b'D (304352) ADC: Wi-Fi takes adc2 lock.\x1b[0m\r\n\x1b[0;32mI (304352) phy_init: phy_version 601,fe52df4,May 10 2023,17:26:54\x1b[0m\r\nD (304352) phy_init: loading PHY init data from application binary\x1b[0m\r\nD (304362) nvs: nvs_open_from_partition phy 0\x1b[0m\r\nD (304362) phy_init: esp_phy_load_cal_data_from_nvs: failed to open NVS namespace (0x1102)\x1b[0m\r\n\x1b[0;33mW (304372) p[0;32mI (304642) wifi: STA_START\x1b[0m\r\n'
>>> wlan.scan()
[(b'kakilima', b'\xac\xec\x85w3f', 2, -60, 3, False), (b'', b'\xac\xec\x85w3h', 2, -61, 0, False), (b'dlink-3530', b'x2\x1b\x8a50', 8, -62, 4, False), (b'', b'\xac\xec\x85w3d', 2, -63, 6, False), (b'KOPIMOJO', b'\x9c\x9c\x1f\xca\xa4\xe5', 8, -64, 3, False), (b'Kaki5AP', b'H\xf1\x7fsX ', 1, -80, 4, False), (b'', b'\xac\xec\x85h\x1eh', 10, -80, 0, False), (b'TheBruviks', b'\xb0\xbev\xe2\xec\xd0', 7, -81, 4, False), (b'', b'\xac\xec\x85h\x1ed', 10, -81, 6, False), (b'IreneogJan', b'\xac\xec\x85h\x1ef', 10, -81, 3, False), (b'', b'\xac\xec\x85\\\xf1(', 2, -82, 0, False), (b'bruviks', b'\xac\xec\x85\\\xf1&', 2, -83, 3, False), (b'', b'\xac\xec\x85\\\xf1$', 2, -83, 6, False), (b'', b'\xac\xec\x85{Nh', 5, -85, 0, False), (b'H108', b'D\xd47ut"', 1, -86, 3, False), (b'Bergen171', b'`\xa4\xb76\x9b\x12', 6, -88, 4, False), (b'audogtom', b'\xac\xec\x85lK\xc6', 10, -88, 3, False), (b'HK Citation 500-40e1fa.n035', b'\xfa\x8f\xcan\xd0j', 2, -90, 0, False), (b'Inteno-2CD2', b'D\xd47u,\xd2', 11, -90, 3, False), (b'Inteno-35EA', b'D\xd47u5\xea', 1, -91, 3, False), (b'COYS', b'D\xd47u1r', 11, -92, 3, False), (b'Stix', b'\xfc\xec\xda\xfd\xf7\xac', 1, -93, 3, False)]
>>> print(w.decode())
D (353302) wifi:Start wifi scan
D (353302) wifi:ssid=, channel=0, hidden=1, type=active, active=<0,0>, passive=0
D (353302) wifi:first chan=1
D (353302) wifi:filter: set rx policy=3
D (353312) wifi:clear scan ap list
D (353312) wifi:start scan: type=0x50f, priority=3, cb=0x0, arg=0x3fca2cf0, ss_state=0x1, time=353315956, index=0
D (353322) wifi:performext 0x3fcf74dc on loop 0x3fcf6584
I (355762) network: event 1

It is clear that we can see something of what was going on, which is what we want. Increasing the txbuf and rxbuf will store more debugging messages.

This trick works for both MP w/IDF4x and MP w/IDF5x.

Working with ESP32-S3 without a debug log is a pain. CONFIG_ESP_CONSOLE_USB_CDC does not work.

If anyone knows an easy way, please let me know.

[shariltumin]

Here is a simple class we can use with the setup.

from machine import UART, Timer

class debug():
   def __init__(my, tp=1, rp=3, tb=1024, rb=1024):
       my.uart = UART(1, tx=tp, rx=rp, txbuf=tb, rxbuf=rb)
       my.t = Timer(0)
       print(f'Short (connect) pin#{tp} and pin#{rp}')
   def test(my, m='Hello'):
       print(m)
   def _show(my):
       if my.uart.any():
          print(my.uart.read().decode())
   def start(my, p=200):
       my.t.init(period=p, mode=Timer.PERIODIC, callback=lambda t: my._show())
   def stop(my):
       my.t.deinit()

Example of how to use.

>>> from log import debug
>>> d = debug()
Short (connect) pin#1 and pin#3
>>> d.test()
Hello
>>> d.test("Hello there")
Hello there
>>> d.start()
>>> I (22313) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated
D (22313) intr_alloc: Connected src 28 to int 13 (cpu 1)
D (36843) intr_alloc: Connected src 50 to int 17 (cpu 1)

import network
>>> D (48303) esp_netif_lwip: LwIP stack has been initialized
D (48303) esp_netif_lwip: check: remote, if=0x0 fn=0x420915a0

D (48303) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (48313) esp_netif_lwip: esp-netif has been successfully initialized

[shlomozippel]

I found an easier way. You need to call init the tusb console in ports/esp32/usb.c:

    ...
    ESP_ERROR_CHECK(tusb_cdc_acm_init(&acm_cfg));
    ESP_ERROR_CHECK(esp_tusb_init_console(CDC_ITF));
    ...

You'll have to #include "tusb_console.h" for that to work

[MathyV]

I can confirm this works on my ESP32S3 board

[shariltumin]

Thanks @shlomozippel this:

$ diff usb.c usb.c-ORIG
30d29
< #include "tusb_console.h"
90d88
<     ESP_ERROR_CHECK(esp_tusb_init_console(CDC_ITF)); // to get debuging info

has done the job nicely and easily. You should tell the core team about your findings, others may be interested.