Hello all. I wanted to report on some logging changes that have gone into master of mynewt-core. All questions and comments are welcome.
Thanks, Chris ### SUMMARY There have been some changes to how Mynewt logs get configured. Now, Log modules are defined in `syscfg.yml` files rather than in C code. The old method of defining logs still works, but the recommended way (and the way mynewt-core and mynewt-nimble do it) has changed. ### IMPORTANT Setting LOG_LEVEL=0 (debug) no longer enables full verbosity for all logs. If you want full verbosity, you need to set LOG_LEVEL=0 *and* all module level settings to 0. Use the following command to get a list of log level settings that your target uses: newt target logcfg show <target> To *decrease* system-wide log verbosity, you can simply override `LOG_LEVEL` with the desired value (as always). ### SUGGESTED USE * Set LOG_LEVEL to 0 (DEBUG). * Tune individual module levels as desired. ### RATIONALE This change was made for the following reasons: 1. Ability to set log level per module at build time. Prior to the change, setting a global log level of DEBUG (LOG_LEVEL=0) might produce an image that is too big, and would produce lots of uninteresting log messages. Now, we can enable debug logging only for the modules we are interested in. 2. Easier to visualize system log configuration (see below). 3. Log modules can be remapped at build time in case of conflicts. DETAILS: *** Terminology: * LOG: A medium where log entries get written. Examples are: 1) the console, 2) a flash circular buffer (FCB), 3) a RAM circular buffer (cbmem). * ENTRY: A single unit of log data. Every entry consists of a header (seqeuence number, timestamp, etc.) and a body. * MODULE: Modules are mapped to one or more logs at runtime. When application code writes a log entry, it specifies the numeric module ID to write to. The `sys/modlog` package then routes the entry to the logs that the module is mapped to. By default, all modules are mapped to the console. *** Defining a log module in a package's `syscfg.yml` file: 1. Define two new settings: * module ID * module level 2. Define the module itself: * syscfg.logs Example (from `sys/log/common/syscfg.yml`): syscfg.defs: DFLT_LOG_MOD: description: 'Numeric module ID to use for default log messages.' value: 0 DFLT_LOG_LVL: description: 'Minimum level for the default log.' value: 1 syscfg.logs: DFLT_LOG: module: MYNEWT_VAL(DFLT_LOG_MOD) level: MYNEWT_VAL(DFLT_LOG_LVL) *** Visualize a target's log configuration: There are two newt commands for this: newt target logcfg brief <target> newt target logcfg show <target> Examples: # (brief) newt target logcfg brief slinky-nordic_pca10056 Brief log config for targets/slinky-nordic_pca10056: LOG | MODULE | LEVEL ---------------+----------+-------------- DFLT_LOG | 0 | 1 (INFO) IMGMGR_LOG | 176 | 0 (DEBUG) # (show) newt target logcfg show slinky-nordic_pca10056 Log config for targets/slinky-nordic_pca10056: DFLT_LOG: Package: @apache-mynewt-core/sys/log/common Module: 0 [DFLT_LOG_MOD] Level: 1 (INFO) [DFLT_LOG_LVL] IMGMGR_LOG: Package: @apache-mynewt-core/mgmt/imgmgr Module: 176 [IMGMGR_LOG_MOD] Level: 0 (DEBUG) [IMGMGR_LOG_LVL] *** Macros: At build time, newt generates the following macros for each defined log: <log-name>_DEBUG(...) <log-name>_INFO(...) <log-name>_WARN(...) <log-name>_ERROR(...) <log-name>_CRITICAL(...) These macros take a printf-style format string and an optional list of arguments. A macro writes a log entry if both of the following are true: * Module level is <= the macro level. * LOG_LEVEL is <= the macro level. Otherwise, the macro evaluates to a no-op [*]. So, using the DFLT_LOG above as an example, if DFLT_LOG_LVL=3 (ERROR) LOG_LEVEL=0 (DEBUG) then `DFLT_LOG_ERROR()` and `DFLT_LOG_CRITICAL()` write a log entry, whereas the `DEBUG`, `INFO`, and `WARN` macros are no-ops. Another example: if DFLT_LOG_LVL=3 (ERROR) LOG_LEVEL=4 (CRITICAL) then only `DFLT_LOG_CRITICAL()` has any effect. The other macros evaluate to no-ops. [*] These aren't strictly no-ops. The printf-style argument list gets evaluated and the results are discarded. This is done to prevent "set but unused" warnings. *** Recap: * Log modules are defined in `syscfg.yml` files. * To change a module's ID or level, override the appropriate syscfg setting. * LOG_LEVEL acts as a minimum log level for all modules. * To view a target's log conguration, use the following newt commands: * newt target logcfg brief <target> * newt target logcfg show <target> ### OPEN QUESTIONS 1. Do we need a way to set all of a target's modules to a particular level? This didn't seem very useful to me. Prior to this change, I never built with LOG_LEVEL=0 because the image would be too large (and the logs are too noisy). But we should add it if others would find it useful.