How to enable system logs in webrepl/dupterm

[electriczity]

Hi,

When Micropython runs under FreeRTOS (and probably similar too) and tasks using the printf or some system logging library like esp_log for an ESP32, the printout message is shown in normal repl but it is missing in webrepl or dupterm-ed repl provided through some interface.

I need to debug an embedded system with ESP32 over WAN using REPL, but without system logs printouts It is impossible. Any library written in C looks silent even when printing errors or debug printouts on the standard output using the printf.

Is there a way to enable system printouts?

I tried to redirect ESP32 log vprintf and dupterm to stream written in Python but I failed when gc_alloc called from some system task caused CPU core panic. I can't find what changes the behavior that duplicated repl does not show system prints.

Best regards,
Electry

[andrewleech]

On esp platforms, C printf / esp log go directly to the IDF configured serial out (as you've seen), micropython stdout is not involved.

In C, you should be able to use mp_printf to target micropython stdout instead, this should then work with whatever streams you've got configured.

See https://github.com/orgs/micropython/discussions/9739

[electriczity]

Hi,
I used mp_vprintf(&mp_plat_print, ...); to direct ESP-IDF logs to the Micropython printing facility. When I set the ESP-IDF logging level to INFO (to get some system-level log outputs) and for example connect to ESP32 WiFi AP with a mobile phone, I should see nice printouts about the WiFi connection while REPL is responsive. (BTW.. ESP-IDF logs use escape sequences for coloring text.) The reality is, the WiFi log printouts appear partially discolored and the REPL appears blocked and unresponsive and I am unable to input anything. When I press enter the REPL prompt does not appear. On the contrary, output from the python-called function in the C module that produces system log printouts is colored correctly and does not block REPL even when it is called in loop. (For this purpose, I implemented a C module for printout testing with a function that only calls ESP_LOG* functions.)

Sadly, I do not have ESP32 with JTAG or ESP32S3 at hand to look at what call stack it freezes.

Any idea where should be the problem?

[andrewleech]

Can you have a uart or usb repl connected at the same time? Sometimes you can see more / raw come through on that to diagnose if it's the webrepl part of the interface causing issues.

When it's in the locked up state, try some other interrupts like ctrl-b and ctrl-d, maybe something in the ESP log stream is tricking it into going into raw repl mode or something.

I also don't know if it's possible that something in the micropython stdout code is calling ESP_LOG_INFO which could then be throwing you into an recursive loop by redirecting ESP_LOG back to stdout?

[electriczity]

I have ESP32 connected through the UART-USB interface, and it is also a REPL interface. There are also colorless printouts of firmware besides ESP log printouts. ESP log library printouts are well defined and their pattern can be quickly identified so I can with certainty say which printout is just printf in firmware and which is ESP log library.

For completeness, I configured ESP32 to create AP and start webrepl in boot.py. After connecting to the AP, I use the webrepl-cli.py script to check if all log printouts are present. I modified the "main.c" of the ESP32 port to set up the ESP-IDF log vprintf function before the REPL loop. There are no more modifications to the actual ESP32 port. There is a check in the REPL loop for the raw REPL mode. When REPL switches to raw mode, the ESP log vprintf function is set to NULL, so there should be no printouts during the raw mode.

I will check if there is any call that can cause a recursive loop, but I do not think the MP uses the ESP-IDF log library. Is it even possible for mp_printf/mp_vprintf to cause MP to interpret it as some command? The mp_printf should only use MP framework and port implementation to print expressions and not interpret them in any way.

[electriczity]

Micropython do not call ESP logging library, so there are not recursive calls. So I really do not think what's the cause of Micropython freeze.

It is big issue for me :/ I have a system with multiple wireless nodes and I can't plug an UART-USB adapter in every of them. The wireless/ethernet debugging channel is the only way but this issue makes it useless 😕

[cnadler86]

Hi,

I have tested a method on my esp32s3, which worked for me and my problem, but I don't know if this can help in your case. Anyway, here my solution:

int mpcamera_log_writer(const char *format, va_list args) {
        mp_vprintf(&mp_plat_print, format, args);
        mp_hal_delay_ms(1);
    return 0;
}

void set_debug_level(esp_log_level_t logLevel) {

esp_log_level_set(TAG,logLevel);
    if (logLevel > ESP_LOG_NONE) {
        esp_log_set_vprintf(mpcamera_log_writer);
    }
}

I put a wrapper callback Funktion and overwrite the standard UART callback with this wrapper (with esp_log_set_vprintf). You might need to lock a mutex before mp_vprintf and release it afterwards, in order to make it more thread safe.
Let me know if this helps. In this case I will start a PR for this functionality.