meta data for this page

log

Flow

Application:

  • every call to NRF_LOG_sth puts a log entry into ringbuffer.
  • NOT DEFERRED: NRF_LOG_FLUSH() is enforced: calls nrf_log_frontend_dequeue() in loop until ringbuffer empty.

Frontend:

  • DEFERRED: Application calls nrf_log_frontend_dequeue() and:
  • nrf_log_frontend_dequeue():
    • one entry is pop-ed from ringbuffer
    • new memobj is allocated from log_mempool to fit log entry.
    • all registered backends are iterated:
      • check if backend is enabled nrf_log_backend_is_enabled(p_backend)
      • filters: check if module log level and log entry severity level matches
      • if log entry should be send to backend - call nrf_log_backend_put
      • BACKEND: process log entry and do really printf-like processing and sending / TX-ing / storing for background processing (NRF_CLI_LOG_BACKEND)
  • nrf_log_frontend_dequeue() return false if ringbuffer is empty

ApplicationApplicationCircular BufferNRF_LOG_BUFSIZECircular BufferNRF_LOG_BUFSIZElog_mempooldynamic memory poollog_mempooldynamic memory poolnrf_log_frontend_dequeue()nrf_log_frontend_dequeue()backend RTTbackend RTTbackend UARTbackend UARTbackend xbackend xNRF_LOG_MSGPOOL_ELEMENT_SIZE                            xNRF_LOG_MSGPOOL_ELEMENT_COUNTNRF_LOG_INFO()NRF_LOG_DEBUG()NRF_LOG_HEXDUMP()NRF_LOG_PROCESS()nrf_memobj_alloc()pop one entrycopy entry to allocatedmempool objectbackend1:check filters and statusmempool objectbackend2:check filters and statusmempool objectbackend3:check filters and statusmempool objectnrf_memobj_put()return "circular buffer is empty"

buffer sizes

  • Circular buffer of NRF_LOG_BUFSIZE (1024):
    • Its aim is to store log entry from app as fast as possible without further processing.
    • DEFERRED: should be big enough to store all log entries until apps calls log to be processed.
  • Dynamic memory pool:
    • size is NRF_LOG_MSGPOOL_ELEMENT_SIZE (20) x NRF_LOG_MSGPOOL_ELEMENT_COUNT (8)
    • provides dynamic memory access, even to fragmented memory.
    • provides storage for log entry qualified to be passed to backends.
    • provides get/put counting semaphore locking mechanism, so one log entry can be passed to multiple log backends at time.
    • It looks like to be designed for background backends. Counting semaphore will keep object locked until all backends finish.
    • Background backends:
      • NRF_CLI_LOG_BACKEND
  • Backends are using temporary string buffers - this is the real place where printf-like function writes generated strings.
    • NRF_LOG_BACKEND_UART_TEMP_BUFFER_SIZE 64

Backends api

typedef struct
{
    void (*put)(nrf_log_backend_t const * p_backend, nrf_log_entry_t * p_entry);
    void (*panic_set)(nrf_log_backend_t const * p_backend);
    void (*flush)(nrf_log_backend_t const * p_backend);
} nrf_log_backend_api_t;
  • put
    • UART/RTT:
      • printf-like processing
      • memobj with log entry is released (put() - counting semaphore decremented)
    • CLI:
      • memobj is not released. get() is called to lock it. And entry is pushed to own queue.
      • own queue size is defined by NRF_CLI_DEF
      • nrf_cli_process() –> cli_log_entry_process() gets entries from queue. It makes memobj free by put() after processing.
  • panic_set:
    • RTT: empty
    • UART: uninit uart driver
  • flush - empty function in most backends
    • CLI: (void)cli_log_entry_process(p_cli, true);
  • nrf_cli_process()
    • cli_log_entry_process()
      • do { } while loop until no log entries in CLI internal queue. So all entries are processed at once.
      • result of processing is passed to printf-like writer p_cli→p_fprintf_ctx == nrf_cli_print_stream
        • cli_write which maps to nrf_cli_uart_transport_api.write == cli_uart_write
        • cli_uart_write puts data to UART TX ringbuffer defined by macro NRF_CLI_UART_DEF

using CLI and deferred log

SUMMARY:

  • app logs data and metadata to ringbuffer: NRF_LOG_BUFSIZE - so must be big enough to handle all entries until log process
  • app idle calls: NRF_LOG_PROCESS()
    • if dynamic log levels enabled it filter what to log
    • it copies entries from ringbuffer to memobj (dynamic memory of size NRF_LOG_MSGPOOL_ELEMENT_SIZE (20) x NRF_LOG_MSGPOOL_ELEMENT_COUNT (8))
    • each one memobj log entry is passed to all active backends (multiple reference locking possible by counting semaphore)
      • UART backend: it process log entry (printf-like formatting) and put it in UART TX buffer. Memobj log entry is released.
      • RTT backend: it process log entry (printf-like formatting) and put it in RTT buffer. Memobj log entry is released.
      • CLI backend: it puts log entry into own queue. Memobj log entry is NOT released.
        • conclusion: dynamic memory pool size NRF_LOG_MSGPOOL_ELEMENT_SIZE (20) x NRF_LOG_MSGPOOL_ELEMENT_COUNT (8) should be the same as NRF_LOG_BUFSIZE.
        • conclusion: CLI LOG queue sized defined by macro NRF_CLI_DEF should be big enough to track all memobj log entries.
  • app idle calls: nrf_cli_process()
    • whole queue is processed in loop
      • each memobj log entry is processed (printf-like formatting) and put into UART TX ring buffer (size defined by NRF_CLI_UART_DEF).