meta data for this page
  •  

Differences

This shows you the differences between two versions of the page.

Link to this comparison view

Next revision		Previous revision
embedded:nordic:sdk5:log [2024/10/14 21:20] – created niziakembedded:nordic:sdk5:log [2024/10/24 11:26] (current) – niziak
Line 1: Line 1:
 ====== log ====== ====== 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
 +
 +<uml>
 +participant Application as APP
 +queue "Circular Buffer\n**NRF_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'').