elesp_log killing performance

[akhodakivskiy]

esp-ids 5.1.1 user here with esp32-wroom dev board.

I have some code with timer and peripherial interrupts. the ISR routines send to the queue, and a task receives from the queue and processes the events. normally i’m seeing 50 usec delay between interrupt handler and task getting unblocked for event processing. if i use some logging (esp_log) in the task handler then this delay skyrockets up to 25 millis depending on the amount of logging. the logger is printing to UART

what’s the problem with esp_log component? does it have longish noInterrupt sections internally? is there any way to keep this delay under control? i need some logging for development, but i can’t develop with such poor logging performance (unless i’m doing something wrong)

in the past i had my own logger where lines were stored in a buffer and later printed to UART in low priority task, and with all the mutexes the performance was much better..

[akhodakivskiy]

I realized that I can redefine vprintf using `esp_log_set_vprintf` and implement log data buffering.

[MicroController]

what’s the problem with esp_log component?

Logging is kind-of expensive, even in the best of cases.

does it have longish noInterrupt sections internally? is there any way to keep this delay under control?

Note that the logger outputs to a single output stream. All tasks logging concurrently will get synchronized on that single output.

i need some logging for development, but i can’t develop with such poor logging performance (unless i’m doing something wrong)

Log less. Don't log in time-critical sections. Consider using a debugger instead of logging, and/or logging via JTAG.
IIRC, the default logger does some buffering (UART HW FIFO), but the buffer is of finite size.
You can also register your own function to handle/buffer/transfer/... log messages.