1.. _module-pw_log: 2 3====== 4pw_log 5====== 6Pigweed's logging module provides facilities for applications to log 7information about the execution of their application. The module is split into 8two components: 9 101. The facade (this module) which is only a macro interface layer 112. The backend, provided elsewhere, that implements the low level logging 12 13``pw_log`` also defines a logging protobuf, helper utilities, and an RPC 14service for efficiently storing and transmitting log messages. See 15:ref:`module-pw_log-protobuf` for details. 16 17.. toctree:: 18 :hidden: 19 20 protobuf 21 22-------------- 23Usage examples 24-------------- 25Here is a typical usage example, showing setting the module name, and using the 26long-form names. 27 28.. code-block:: cpp 29 30 #define PW_LOG_MODULE_NAME "BLE" 31 32 #include "pw_log/log.h" 33 34 int main() { 35 PW_LOG_INFO("Booting..."); 36 PW_LOG_DEBUG("CPU temp: %.2f", cpu_temperature); 37 if (BootFailed()) { 38 PW_LOG_CRITICAL("Had trouble booting due to error %d", GetErrorCode()); 39 ReportErrorsAndHalt(); 40 } 41 PW_LOG_INFO("Successfully booted"); 42 } 43 44In ``.cc`` files, it is possible to dispense with the ``PW_`` part of the log 45names and go for shorter log macros. Include ``pw_log/short.h`` or 46``pw_log/shorter.h`` for shorter versions of the macros. 47 48.. code-block:: cpp 49 50 #define PW_LOG_MODULE_NAME "BLE" 51 52 #include "pw_log/shorter.h" 53 54 int main() { 55 INF("Booting..."); 56 DBG("CPU temp: %.2f", cpu_temperature); 57 if (BootFailed()) { 58 CRT("Had trouble booting due to error %d", GetErrorCode()); 59 ReportErrorsAndHalt(); 60 } 61 INF("Successfully booted"); 62 } 63 64Layer diagram example: ``stm32f429i-disc1`` 65=========================================== 66Below is an example diagram showing how the modules connect together for the 67``stm32f429i-disc1`` target, where the ``pw_log`` backend is ``pw_log_basic``. 68``pw_log_basic`` uses the ``pw_sys_io`` module to log in plaintext, which in 69turn outputs to the STM32F429 bare metal backend for ``pw_sys_io``, which is 70``pw_sys_io_baremetal_stm32f429i``. 71 72.. image:: example_layer_diagram.svg 73 74Logging macros 75============== 76These are the primary macros for logging information about the functioning of a 77system, intended to be used directly. 78 79.. c:macro:: PW_LOG(level, module, flags, fmt, ...) 80 81 This is the primary mechanism for logging. 82 83 *level* - An integer level as defined by ``pw_log/levels.h``. 84 85 *module* - A string literal for the module name. Defaults to 86 :c:macro:`PW_LOG_MODULE_NAME`. 87 88 *flags* - Arbitrary flags the backend can leverage. The semantics of these 89 flags are not defined in the facade, but are instead meant as a general 90 mechanism for communication bits of information to the logging backend. 91 ``pw_log`` reserves 2 flag bits by default, but log backends may provide for 92 more or fewer flag bits. 93 94 Here are some ideas for what a backend might use flags for: 95 96 - Example: ``HAS_PII`` - A log has personally-identifying data 97 - Example: ``HAS_DII`` - A log has device-identifying data 98 - Example: ``RELIABLE_DELIVERY`` - Ask the backend to ensure the log is 99 delivered; this may entail blocking other logs. 100 - Example: ``BEST_EFFORT`` - Don't deliver this log if it would mean blocking 101 or dropping important-flagged logs 102 103 *fmt* - The message to log, which may contain format specifiers like ``%d`` 104 or ``%0.2f``. 105 106 Example: 107 108 .. code-block:: cpp 109 110 PW_LOG(PW_LOG_LEVEL_INFO, PW_LOG_MODULE_NAME, PW_LOG_FLAGS, "Temp is %d degrees", temp); 111 PW_LOG(PW_LOG_LEVEL_ERROR, PW_LOG_MODULE_NAME, UNRELIABLE_DELIVERY, "It didn't work!"); 112 113 .. note:: 114 115 ``PW_LOG()`` should not be used frequently; typically only when adding 116 flags to a particular message to mark PII or to indicate delivery 117 guarantees. For most cases, prefer to use the direct ``PW_LOG_INFO`` or 118 ``PW_LOG_DEBUG`` style macros, which are often implemented more efficiently 119 in the backend. 120 121 122.. c:macro:: PW_LOG_DEBUG(fmt, ...) 123.. c:macro:: PW_LOG_INFO(fmt, ...) 124.. c:macro:: PW_LOG_WARN(fmt, ...) 125.. c:macro:: PW_LOG_ERROR(fmt, ...) 126.. c:macro:: PW_LOG_CRITICAL(fmt, ...) 127 128 Shorthand for ``PW_LOG(<level>, PW_LOG_MODULE_NAME, PW_LOG_FLAGS, fmt, ...)``. 129 130-------------------- 131Module configuration 132-------------------- 133This module has configuration options that globally affect the behavior of 134pw_log via compile-time configuration of this module, see the 135:ref:`module documentation <module-structure-compile-time-configuration>` for 136more details. 137 138.. c:macro:: PW_LOG_LEVEL_DEFAULT 139 140 Controls the default value of ``PW_LOG_LEVEL``. Setting 141 ``PW_LOG_LEVEL_DEFAULT`` will change the behavior of all source files that 142 have not explicitly set ``PW_LOG_LEVEL``. Defaults to ``PW_LOG_LEVEL_DEBUG``. 143 144.. c:macro:: PW_LOG_FLAGS_DEFAULT 145 146 Controls the default value of ``PW_LOG_FLAGS``. Setting 147 ``PW_LOG_FLAGS_DEFAULT`` will change the behavior of all source files that 148 have not explicitly set ``PW_LOG_FLAGS``. Defaults to ``0``. 149 150.. c:macro:: PW_LOG_ENABLE_IF_DEFAULT 151 152 Controls the default value of ``PW_LOG_ENABLE_IF``. Setting 153 ``PW_LOG_ENABLE_IF_DEFAULT`` will change the behavior of all source files that 154 have not explicitly set ``PW_LOG_ENABLE_IF``. Defaults to 155 ``((level) >= PW_LOG_LEVEL)``. 156 157 158Per-source file configuration 159============================= 160This module defines macros that can be overridden to independently control the 161behavior of ``pw_log`` statements for each C or C++ source file. To override 162these macros, add ``#define`` statements for them before including headers. 163 164The option macro definitions must be visible to ``pw_log/log.h`` the first time 165it is included. To handle potential transitive includes, place these 166``#defines`` before all ``#include`` statements. This should only be done in 167source files, not headers. For example: 168 169 .. code-block:: cpp 170 171 // Set the pw_log option macros here, before ALL of the #includes. 172 #define PW_LOG_MODULE_NAME "Calibration" 173 #define PW_LOG_LEVEL PW_LOG_LEVEL_WARN 174 175 #include <array> 176 #include <random> 177 178 #include "devices/hal9000.h" 179 #include "pw_log/log.h" 180 #include "pw_rpc/server.h" 181 182 int MyFunction() { 183 PW_LOG_INFO("hello???"); 184 } 185 186.. c:macro:: PW_LOG_MODULE_NAME 187 188 A string literal module name to use in logs. Log backends may attach this 189 name to log messages or use it for runtime filtering. Defaults to ``""``. The 190 ``PW_LOG_MODULE_NAME_DEFINED`` macro is set to ``1`` or ``0`` to indicate 191 whether ``PW_LOG_MODULE_NAME`` was overridden. 192 193.. c:macro:: PW_LOG_FLAGS 194 195 Log flags to use for the ``PW_LOG_<level>`` macros. Different flags may be 196 applied when using the ``PW_LOG`` macro directly. 197 198 Log backends use flags to change how they handle individual log messages. 199 Potential uses include assigning logs priority or marking them as containing 200 personal information. Defaults to ``PW_LOG_FLAGS_DEFAULT``. 201 202.. c:macro:: PW_LOG_LEVEL 203 204 Filters logs by level. Source files that define ``PW_LOG_LEVEL`` will display 205 only logs at or above the chosen level. Log statements below this level will 206 be compiled out of optimized builds. Defaults to ``PW_LOG_LEVEL_DEFAULT``. 207 208 Example: 209 210 .. code-block:: cpp 211 212 #define PW_LOG_LEVEL PW_LOG_LEVEL_INFO 213 214 #include "pw_log/log.h" 215 216 void DoSomething() { 217 PW_LOG_DEBUG("This won't be logged at all"); 218 PW_LOG_INFO("This is INFO level, and will display"); 219 PW_LOG_WARN("This is above INFO level, and will display"); 220 } 221 222.. c:macro:: PW_LOG_ENABLE_IF(level, flags) 223 224 Filters logs by an arbitrary expression based on ``level`` and ``flags``. 225 Source files that define ``PW_LOG_ENABLE_IF(level, flags)`` will display if 226 the given expression evaluates true. Defaults to 227 ``PW_LOG_ENABLE_IF_DEFAULT``. 228 229 Example: 230 231 .. code-block:: cpp 232 233 // Pigweed's log facade will call this macro to decide to log or not. In 234 // this case, it will drop logs with the PII flag set if display of PII is 235 // not enabled for the application. 236 #define PW_LOG_ENABLE_IF(level, flags) \ 237 (level >= PW_LOG_LEVEL_INFO && \ 238 !((flags & MY_PRODUCT_PII_MASK) && MY_PRODUCT_LOG_PII_ENABLED) 239 240 #include "pw_log/log.h" 241 242 // This define might be supplied by the build system. 243 #define MY_PRODUCT_LOG_PII_ENABLED false 244 245 // This is the PII mask bit selected by the application. 246 #define MY_PRODUCT_PII_MASK (1 << 5) 247 248 void DoSomethingWithSensitiveInfo() { 249 PW_LOG_DEBUG("This won't be logged at all"); 250 PW_LOG_INFO("This is INFO level, and will display"); 251 252 // In this example, this will not be logged since logging with PII 253 // is disabled by the above macros. 254 PW_LOG(PW_LOG_LEVEL_INFO, 255 MY_PRODUCT_PII_MASK, 256 "Sensitive: %d", 257 sensitive_info); 258 } 259 260.. attention:: 261 262 At this time, only compile time filtering is supported. In the future, we 263 plan to add support for runtime filtering. 264 265------------------ 266Logging attributes 267------------------ 268The logging facade in Pigweed is designed to facilitate the capture of at least 269the following attributes: 270 271- *Level* - The log level; for example, INFO, DEBUG, ERROR, etc. Typically an 272 integer 273- *Flags* - Bitset for e.g. RELIABLE_DELIVERY, or HAS_PII, or BEST_EFFORT 274- *File* - The file where the log was triggered 275- *Line* - The line number in the file where the log line occured 276- *Function* - What function the log comes from. This is expensive in binary 277 size to use! 278- *Module* - The user-defined module name for the log statement; e.g. “BLE” or 279 “BAT” 280- *Message* - The message itself; with % format arguments 281- *Arguments* - The format arguments to message 282- *Thread* - For devices running with an RTOS, capturing the thread is very 283 useful 284- *Others* - Processor security level? Maybe Thread is a good proxy for this 285 286Each backend may decide to capture different attributes to balance the tradeoff 287between call site code size, call site run time, wire format size, logging 288complexity, and more. 289 290.. _module-pw_log-circular-deps: 291 292---------------------------------------------- 293Avoiding circular dependencies with ``PW_LOG`` 294---------------------------------------------- 295Because logs are so widely used, including in low-level libraries, it is 296common for the ``pw_log`` backend to cause circular dependencies. Because of 297this, log backends may avoid declaring explicit dependencies, instead relying 298on include paths to access header files. 299 300In GN, the ``pw_log`` backend's full implementation with true dependencies is 301made available through the ``$dir_pw_log:impl`` group. When ``pw_log_BACKEND`` 302is set, ``$dir_pw_log:impl`` must be listed in the ``pw_build_LINK_DEPS`` 303variable. See :ref:`module-pw_build-link-deps`. 304 305In the ``pw_log``, the backend's full implementation is placed in the 306``$pw_log_BACKEND.impl`` target. ``$dir_pw_log:impl`` depends on this 307backend target. The ``$pw_log_BACKEND.impl`` target may be an empty group if 308the backend target can use its dependencies directly without causing circular 309dependencies. 310 311In order to break dependency cycles, the ``pw_log_BACKEND`` target may need 312to directly provide dependencies through include paths only, rather than GN 313``public_deps``. In this case, GN header checking can be disabled with 314``check_includes = false``. 315 316---------------------- 317Google Logging Adapter 318---------------------- 319Pigweed provides a minimal C++ stream-style Google Log set of adapter 320macros around PW_LOG under ``pw_log/glog_adapter.h`` for compatibility with 321non-embedded code. While it is effective for porting server code to 322microcontrollers quickly, we do not advise embedded projects use that approach 323unless absolutely necessary. 324 325Configuration 326============== 327 328.. c:macro:: PW_LOG_CFG_GLOG_BUFFER_SIZE_BYTES 329 330 The size of the stack-allocated buffer used by the Google Logging (glog) 331 macros. This only affects the glog macros provided through pw_log/glog.h. 332 333 Pigweed strongly recommends sticking to printf-style logging instead 334 of C++ stream-style Google Log logging unless absolutely necessary. The glog 335 macros are only provided for compatibility with non-embedded code. See 336 :ref:`module-pw_log-design-discussion` for more details. 337 338 Undersizing this buffer will result in truncated log messages. 339 340----------------- 341Design discussion 342----------------- 343 344.. _module-pw_log-design-discussion: 345 346Why not use C++ style stream logging operators like Google Log? 347=============================================================== 348There are multiple reasons to avoid the C++ stream logging style in embedded, 349but the biggest reason is that C++ stream logging defeats log tokenization. By 350having the string literals broken up between ``<<`` operators, tokenization 351becomes impossible with current language features. 352 353Consider this example use of Google Log: 354 355.. code-block:: cpp 356 357 LOG(INFO) << "My temperature is " << temperature << ". State: " << state; 358 359This log statement has two string literals. It might seem like one could convert 360move to tokenization: 361 362.. code-block:: cpp 363 364 LOG(INFO) << TOKEN("My temperature is ") << temperature << TOKEN(". State: ") << state; 365 366However, this doesn't work. The key problem is that the tokenization system 367needs to allocate the string in a linker section that is excluded from the 368final binary, but is in the final ELF executable (and so can be extracted). 369Since there is no way to declare a string or array in a different section in 370the middle of an experession in C++, it is not possible to tokenize an 371expression like the above. 372 373In contrast, the ``printf``-style version is a single statement with a single 374string constant, which can be expanded by the preprocessor (as part of 375``pw_tokenizer``) into a constant array in a special section. 376 377.. code-block:: cpp 378 379 // Note: LOG_INFO can be tokenized behind the macro; transparent to users. 380 PW_LOG_INFO("My temperature is %d. State: %s", temperature, state); 381 382Additionally, while Pigweed is mostly C++, it a practical reality that at times 383projects using Pigweed will need to log from third-party libraries written in 384C. Thus, we also wanted to retain C compatibility. 385 386In summary, printf-style logging is better for Pigweed's target audience 387because it: 388 389- works with tokenization 390- is C compatibile 391- has smaller call sites 392 393See also :ref:`module-pw_log_tokenized` for details on leveraging Pigweed's 394tokenizer module for logging. 395 396See also :ref:`module-pw_tokenizer` for details on Pigweed's tokenizer, 397which is useful for more than just logging. 398 399Why does the facade use header redirection instead of C functions? 400================================================================== 401Without header redirection, it is not possible to do sophisticated macro 402transforms in the backend. For example, to apply tokenization to log strings, 403the backend must define the handling macros. Additionally, compile-time 404filtering by log level or flags is not possible without header redirection. 405While it may be possible to do the filtering in the facade, that would imply 406having the same filtering implementation for all log handling, which is a 407restriction we want to avoid. 408 409Why is the module name done as a preprocessor define rather than an argument? 410============================================================================= 411APIs are a balance between power and ease of use. In the practical cases we 412have seen over the years, most translation units only need to log to one 413module, like ``"BLE"``, ``"PWR"``, ``"BAT"`` and so on. Thus, adding the 414argument to each macro call seemed like too much. On the other hand, flags are 415something that are typically added on a per-log-statement basis, and is why the 416flags are added on a per-call basis (though hidden through the high-level 417macros). 418 419-------------- 420pw_log in Java 421-------------- 422``pw_log`` provides a thin Java logging class that uses Google's `Flogger 423<https://google.github.io/flogger/>`_ API. The purpose of this wrapper is to 424support logging on platforms that do not support Flogger. The main 425implementation in ``pw_log/java/main`` simply wraps a 426``com.google.common.flogger.FluentLogger``. An implementation that logs to 427Android's ``android.util.Log`` instead is provided in 428``pw_log/java/android_main``. 429