• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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