Nordic's own documentation explains that a "call" to NRF_LOG_PROCESS() processes, at most, one log entry:
infocenter.nordicsemi.com/.../group__nrf__log__ctrl.html
In other words, a "call" to NRF_LOG_PROCESS() may leave log entries still waiting to be processed.
The documentation provides an example of correct usage:
while(1)
{
scheduler();
if (!NRF_LOG_PROCESS())
{
//sleep
}
}
which is found in most of the SDK examples; eg, the ble_app_uart_c Central example:
static void idle_state_handle(void)
{
if (NRF_LOG_PROCESS() == false)
{
nrf_pwr_mgmt_run();
}
}
and yet the ble_app_uart Peripheral example (among others) contains this:
static void idle_state_handle(void)
{
UNUSED_RETURN_VALUE(NRF_LOG_PROCESS());
nrf_pwr_mgmt_run();
}
Which is clearly wrong - as it can only process, at most, one log entry before sleeping!!
This results in log messages getting delayed - and not appearing until the next event wakes the system.
So you see new events "releasing" log messages that related to previous events!
Nordic: please go through all the examples and correct all occurrences of this blunder!
EDIT
Corrected code snippet from ble_app_uart Peripheral example - show original Nordic code, not my correction!
