log

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

<uml> participant Application as APP queue “Circular Buffer\nNRF_LOG_BUFSIZE” as CB queue “log_mempool\ndynamic memory pool” as MEM control “nrf_log_frontend_dequeue()” as DE note over MEM NRF_LOG_MSGPOOL_ELEMENT_SIZE

• *x NRF_LOG_MSGPOOL_ELEMENT_COUNT endnote control “backend RTT” as B1 control “backend UART” as B2 control “backend x” as B3 APP → CB: NRF_LOG_INFO() activate CB APP → CB: NRF_LOG_DEBUG() activate CB APP → CB: NRF_LOG_HEXDUMP() activate CB … APP → DE: NRF_LOG_PROCESS() activate DE DE ←- MEM: nrf_memobj_alloc() activate MEM activate DE CB –> DE: pop one entry deactivate CB DE –> DE: copy entry to allocated\nmempool object DE ←- DE: backend1:\ncheck filters and status DE –> B1: mempool object DE ←- DE: backend2:\ncheck filters and status DE –> B2: mempool object DE ←- DE: backend3:\ncheck filters and status DE –> B3: mempool object MEM ←- DE: nrf_memobj_put() deactivate MEM DE –> APP: return “circular buffer is empty” deactivate DE deactivate DE </uml> ===== 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 ===== <code c> 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; </code> * 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).