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.
