Hang in logger frontend

[rabarton]

I'm hitting a couple of different logging issues with the latest SDK15. In the most recent case it appears std_n is hanging while calling nrf_log_frontend_dequeue.

Attached a picture of the call stack and the current values of m_log_data.  Any suggestions on what I may be doing wrong or if this is a known issue?  I noticed m_log_data.rd_idx is quite large. Is that an expected value?

[Krzysztof Chruscinski]

Do you have NRF_LOG_DEFERRED set in sdk_config.h? I see that you have m_log_data.autoflush set. It indicates that you are not in deferred mode or you are in panic mode (NRF_LOG_FINAL_FLUSH() has been called and logger switched to blocking operation). In non-deferred mode logs are processed where called without any protection. Sooner of later that will lead to corruption because one will preempt another. rd_idx should always be smaller than wr_idx.

[rabarton]

Thanks for the explanation. So it sounds like if we are calling logging functions in interrupt code, we risk re-entering logging functions that shouldn't be re-entered and using deferred mode will support logging from application and interrupts?

[Krzysztof Chruscinski]

yes, deferred mode is recommened for more complex aplication. Non-deferred mode is risky to used but straightforward: you call log, data is processed and send vs. deferred mode where log is buffered and handled in idle context by calling LOG_PROCESS().

[rabarton]

I assume all the modules have log messages that are within the limitations of deferred mode (4 arguments max, etc). If that's true, for my app I was thinking for each interrupt level I can have a separate buffer, do string printf to the buffer, and log the string. I'm assuming the logger copies that entire string in so I can log multiple strings back to back in the same interrupt handler, and I work around the limitations of deferred logging. Would that be the correct assumption?

[Krzysztof Chruscinski]

In deferred mode logger does not copy whole string to the buffer. It copies only pointer to the string and arguments (and addtional information like timestamp, severity level). Such log message is queued and processed when LOG_PROCESS() is called. Processing means that message is passed to available backends. It is backend responsibility to format log message to string and send it over transport (e.g. uart)