Beware that this post is related to an SDK in maintenance mode
More Info: Consider nRF Connect SDK for new designs
This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

[bug] nrf_log_frontend: m_log_data.buffer overflow

Symptom

Depending on the data values written to the log this either triggers a hardfault or executes some random code with random results.

Repeatability

I can reproduce this by configuring deferred logging (NRF_LOG_DEFERRED = 1) and hammering on the log in the main loop:-

uint32_t loop_count = 0;
for (;;)
{

    char dummy[] = "XXXXXXXXXXXXXXXXXXXX";
    NRF_LOG_INFO("Main Loop %08X %s", loop_count++, NRF_LOG_PUSH(dummy));

    while (NRF_LOG_PROCESS()) {;}

}

This hardfaults after the same number of iterations every time. I have not calculated if this corresponds to the first or a subsequent wrap of the underlying buffer.

Analysis (so far)

The m_log_data.buffer can overflow by at least 4 bytes. This corrupts the adjacent m_log_data.timestamp_func pointer.

This pointer is de-referenced in nrf_log_frontend/std_header_set(). This is the source line:-

    m_log_data.buffer[(wr_idx + 2) & mask] = m_log_data.timestamp_func();

The NRF_LOG_PUSH() mechanism is strongly implicated because the overflowed data in the pointer is 0x58585858 ("XXXX").

I can dig deeper, but not just now.

SDK Version

nRF5_SDK_14.2.0_17b948a

Related