This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

Segmentation fault in nrf_log_frontend.c when writing string onto USB CDC-ACM iface

Hello,

when writing content onto the CDC-ACM interface of the nrf52840, I sooner or later always end up in a Segmentation fault.

I'm on nRF52840 and using the SDK v16.

I'm writing the string "ABCDEFGHIJKLMNOPQRSTOVWXYZ" - per byte, using app_usbd_cdc_acm_write(&m_app_cdc_acm, &byte, 1); - looping through the string.

The Segmentation fault happens in total different scenarios with different code and structures.

What's always the same though is, that my debugger shows it happening in:

Program received signal SIGSEGV, Segmentation fault.
0x0002786e in nrf_log_backend_flush (warning: while parsing target memory map (at line 1): Required element <memory> is missing
p_backend=0x1)
at ../../../../../../components/libraries/log/nrf_log_backend_interface.h:235
235 p_backend->p_api->flush(p_backend);

while the backtrace is an infinite scrolling of:

#0 0x0002786e in nrf_log_backend_flush (p_backend=0x1) at ../../../../../../components/libraries/log/nrf_log_backend_interface.h:235
#1 nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:895
#2 0x000277be in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:556
#3 std_n (args=0x0, nargs=0, p_str=0x3606c "Backends flushed", severity_mid=393218) at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:562
#4 nrf_log_frontend_std_0 (severity_mid=393218, p_str=p_str@entry=0x3606c "Backends flushed") at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:573
#5 0x0002788e in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:898
#6 0x000277be in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:556
#7 std_n (args=0x0, nargs=0, p_str=0x3606c "Backends flushed", severity_mid=393218) at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:562
#8 nrf_log_frontend_std_0 (severity_mid=393218, p_str=p_str@entry=0x3606c "Backends flushed") at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:573
#9 0x0002788e in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:898
#10 0x000277be in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:556
#11 std_n (args=0x0, nargs=0, p_str=0x3606c "Backends flushed", severity_mid=393218) at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:562
#12 nrf_log_frontend_std_0 (severity_mid=393218, p_str=p_str@entry=0x3606c "Backends flushed") at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:573s
#13 0x0002788e in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:898
#14 0x000277be in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:556
#15 std_n (args=0x0, nargs=0, p_str=0x3606c "Backends flushed", severity_mid=393218) at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:562
#16 nrf_log_frontend_std_0 (severity_mid=393218, p_str=p_str@entry=0x3606c "Backends flushed") at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:573
#17 0x0002788e in nrf_log_frontend_dequeue () at ../../../../../../components/libraries/log/src/nrf_log_frontend.c:898
[..]

I'm happy to create and provide a minimal test case, however the always same, yet seemingly unrelated backtrace (nrf_log_frontend) as well as the correlation with using app_usbd_cdc_acm_write() makes me wonder whether I should start looking somewhere else for its cause.

I'd be happy for any hint!

  • Removing the NRF_LOG_PROCESS() alone from everywhere but the mainloop improved the situation when logging is deferred, however I'm still running this very backtrace.

    When disabling logging completely, though, I haven't seen any crash so far.

    For NRF_LOG_PROCESS() I would expected a warning not using it outside of the mainloop.

    "You can call this macro from the main context or from the error handler to process log entries one by one." doesn't cut it.

    Besides, NRF_LOG_PROCESS() - according to the docs - is a NOOP when deferred logging is disabled - and I was/am having it disabled.

    The overall state here I have to say is.. disappointing. Logging is an essential tool for debugging. If logging of a framework/SDK itself is so fragile and causing these issues, eventually even hiding the issues you're trying to debug, its use is to be discouraged - this is every developers' nightmare.

Related