nrf_log_frontend_dequeue must be atomically protected against re-entry from interrupt context

[Anthony Ambuehl]

This issue exists in NRF SDK5 15.2.0 and earlier.  NRF log module has entered "production" level as of SDK5 15.2.

While implementing an additional logging backend, I discovered a race condition in the nrf_log_frontend_dequeue function.

The bug can occur when logging is DEFERRED, and logs using nrf_log_push are generated from an interrupt.

The root issue is that nrf_log_frontend_dequeue which processes an internal buffer is normally called from the idle loop, but can also be called from an interrupt after nrf_log_push sets the autoflush flag.

To fix this issue I recommend adding an atomic busy flag to nrf_log_frontend_dequeue to avoid re-entrant calls from proceeding.

[awneil]

Hmmm - what would be the symptoms of this going wrong?

[Anthony Ambuehl]

The symptom is log messages that are sometimes repeated.  They may be a single log repeated or a series of logs that are repeated in a sequence. 

for example

log 1

log 2

log 2

log 3

or

log 1

log 2

log 3

log 1

log 2

log 3

[awneil]

Thanks.