Dump Flashlog to RTT

[wko]

Hello!

A few questions about the flashlog:

1. What's the difference between the flashlog and the crashlog?

2. What is the recommended way to obtain flashlog/crashlog data from a device once it has failed in the field? We looked into the CLI but the power draw requirements were quite high and it did not seem reliable.

3. If we have the flashlog enabled for severity WARNING and above, do we need to call NRF_LOG_FLUSH between usages of NRF_LOG_INFO and NRF_LOG_WARNING?

4. If we want to write the contents of the flashlog out to RTT on bootup, can we use the nrf_log_backend_flash_next_entry_get function to obtain the contents, and pass the results to NRF_LOG_INFO?  We attempted this and discovered very odd behavior where messages are sometimes absent in the SEGGER debug console.

Thanks for any assistance!

[Jørgen Holmefjord]

Hi,

1. This is explained in the library documentation:

   The backend consists of the following logical parts:

   • flashlog - used to store log entries during application lifetime,
   • crashlog - used to dump messages logged before an error condition (NRF_LOG_FINAL_FLUSH) and between NRF_LOG_FINAL_FLUSH and reset.
2. The simplest solution would be to use the CLI. I suppose you could only enable this interface when needed to save power? Alternatively you can read the content of flash using a debugger/programmer and the nrfjprog command line tool (argument --readcode will read whole flash, --memrd will read specified part of flash).
3. I'm not sure I understand the question. NRF_LOG_FLUSH() is used to process the entire logger queue in deferred mode. Typically this is only called in idle state to process logs.
4. What is the configuration of NRF_LOG_ALLOW_OVERFLOW in your application? Have you tried increasing the size of NRF_LOG_BUFSIZE?

Best regards,
Jørgen

[wko]

Hi Jørgen!

Thanks for the quick response; apologies it took us a while to figure out what was happening.

1. Thank you but it looks like there are a few other undocumented differences, specifically around a crashlog injected log message (see below).

2. The CLI added additional complication since it's prompts didn't play well with log messages in the RTT Viewer.

3. My understanding is that when deferred logging is enabled, NRF_LOG_FLUSH is a blocking call that waits until the logger backends have flushed all current messages to e.g. RTT or flash.  This is necessary when e.g. a buffer on the stack needs to be flushed before it leaves a function's scope.  We're seeing issues where consecutive invocations of NRF_LOG_FLUSH ends up with data not sent to RTT Viewer or Segger's debugging console.  Is this expected?  Should we be introducing delays to allow time for processing to complete?

4. NRF_LOG_ALLOW_OVERFLOW is set to 1 and NRF_LOG_BUFSIZE is set to 1024.  We actually got this working but it was a bit complicated.

Specifically, it turns out that when crashlog is enabled, a log message "-----------CRASHLOG------------" is injected by nrf_log_backend_flash.c when processing NRF_LOG_FINAL_FLUSH.

5. If you call NRF_LOG_FINAL_FLUSH multiple times, you end up with multiple injected log entries in the crashlog queue. Is this intentional?

6. It would be nice to document that nrf_pwr_mgmt_shutdown itself calls NRF_LOG_FINAL_FLUSH so there's no need for the user to do so.

7. In the nrf_log_panic function defined in nrf_log_frontend.c, the nrf_log_backend_panic_set function is called once for each logger backend.  It looks like both the flashlog and the crashlog inject that "-----------CRASHLOG------------" log message.  If you have both crashlog and flashlog configured, you will get two injected log messages.

8. In nrf_fprintf_format.c, the nrf_fprintf_fmt does NOT add a terminating NULL character to the buffer.  In the above case where crashlog and flashlog were both enabled, the second injected log message included garbled text.

Thank you again for any help,

Andrew