phosphor-logging/docs/structured-logging.md

4 [log](../lib/include/phosphor-logging/log.hpp) and
5 [lg2](../lib/include/phosphor-logging/lg2.hpp). If your code is C++20 (or later)
12 logging where logged events are free-form strings.
14 The principal logging daemon in OpenBMC (systemd-journald) natively supports
22 of various failure-analysis operations, either on the part of a system
23 manufacturer or an end-user, to need to interrogate the system logs to determine
39 accepted log-levels and their definition is historically documented in
44 The pre-C++20 logging APIs presented by phosphor-logging are
52 such as 'debug', 'info', 'emergency', a free-form message string, and any number
53 of entries, which are key-value pairs of data.
55 The 'key' of an entry is an upper-case tag for the data along with a
56 printf-style format string for the data. Journald imposes some restrictions on
59 or the printf string is invalid for the data, the code will compile but journald
62 It is highly discouraged to dynamically create the free-form message string
67 The post-C++20 logging APIs presented by phosphor-logging are `lg2::log`. The
76 free-form message string and any number of entries indicated by 2 or 3 argument
79 - key name (with the same `[_A-Z0-9]` requirements imposed by journald).
80 - [optional] set of format flags
81 - data value
83 The free-form message may also optionally contain brace-wrapped key names, for
85 place of the `{KEY}`. This enables human-friendly message strings to be formed
88 Note: Since a free-form message with data can be created using the `{KEY}`
90 Avoiding the `{KEY}` feature causes the journal messages to become unstructured.
95 - `bin`, `dec`, `hex`
96   - The [integer] data should be formatted in the requested manner.
97   - Decimal is the default.
98   - Examples:
99     - `bin, 0xabcd` -> `0b1010101111001101`
100     - `hex, 1234` -> `0x4d2`
101 - `field8`, `field16`, `field32`, `field64`
102   - The [integer] data should be padded as if it were a field of specified
103     bit-length (useful only for `bin` or `hex` data).
104   - Examples:
105     - `(bin | field8), 0xff` -> `0b11111111`
106     - `(hex | field16), 10` -> `0x000a`
112 (C-strings, std::strings, or `std::string_views`), `std::filesystem::paths`,
117 The APIs also perform compile-time analysis of the arguments to give descriptive
120 - `(dec | hex)` yields:
121   - `error: static assertion failed: Conflicting flags found for value type.`
122 - `dec` applied to a string yields:
123   - `error: static assertion failed: Prohibited flag found for value type.`
124 - Missing a key yields:
125   - `error: static assertion failed: Found value without expected header field.`
126 - Missing data yields:
127   - `error: static assertion failed: Found header field without expected data.`
128 - Missing a message yields:
129   - `error: use of deleted function ‘lg2::debug<>::debug()’`
131 Debug-level messages are only sent to journald if the `DEBUG_INVOCATION`
134 ### LOG2_FMTMSG key
136 The API adds an extra journald key to represent the original message prior to
137 `{KEY}` replacement, which is saved with the `LOG2_FMTMSG` key. This is done to
141 ### Key format checking
144 contain underscore, uppercase letters, or numbers (`[_A-Z0-9]`) and may not
146 silently drops journal requests. In order to prevent silent bugs, the code
147 performs compile-time checking of these requirements.
149 The code that enables compile-time header checking imposes two constraints:
151 1. Keys / headers must be passed as constant C-string values.
152    - `"KEY"` is valid; `"KEY"s` or `variable_key` is not.
153 2. Any constant C-string may be interpreted as a key and give non-obvious
155    - Constant C-strings (`"a string"`) should be passed as a C++ literal
169 environment variable to the desired maximum log level (0-7). Messages with a
176 - `%%` : a `'%'` literal
177 - `%f` : the logging function's name
178 - `%F` : the logging function's file
179 - `%l` : the log level as an integer
180 - `%L` : the logging function's line number
181 - `%m` : the lg2 message
190 1. The mixture of template and temporary-constructed `entry` parameters is
192 2. The printf format-strings were error prone and potentially missed in code
195 3. `logging::log` generates incorrect code location information (see
197    generate correct code location info and can optionally be passed a
198    non-defaulted `source_location` for rare but appropriate cases.
199 4. The previous APIs had no mechanism to generate dynamic user-friendly strings
201    `{fmt}`. `{KEY}` replacement is now a core feature of the new API.
203    silent. This resulted in some applications creating custom code to write some
221 techniques with templated-class partial-specialization and overloading. Those
235 capable and especially apt for human-facing string formatting. That is not the
236 typical use-case for our logging. Instead we prioritized the following:
239 2. Simple, consistent, machine parse-able data contents.
240 3. Sufficient human-facing messages for developer-level debug.
241 4. Very tight code generation at logging call sites and reasonably performant
242    code.
245 ergonomics, but significantly better compile-time error proofing than the others
252 hardware-facing usage is implemented (hex, binary, field-size).
254 (3) The `{HEADER}` placeholders allow data to be placed in a human-friendly
257 (4) The call-site code generated by this API is almost identical to a `printf`
258 and the journal-facing code is on similar performance footing to the
260 providing the source-code information, compared to the older `logging` APIs and
261 have similar formatting performance to the printf-style formatting that
266 overheads. Either we insert the `{fmt}` calls at the call-site (N calls plus N
268 side where we lose the compile-time format checking. Also, the performance of
270 the formatting library-side.
272 Logging is done often. Shifting a few values onto the stack for a printf-type
273 call compared to a kilobyte+ of generated code for inline `{fmt}` calls is a
274 significant trade-off. And one with the only major advantage being more
283 done without impacting existing code usage. Also, an ambitious developer could
284 write a Clang-Tidy code upgrader to transition from format flags to something
292 are identical in content, and very near each other in the on-disk format, they
293 compress exceptionally well. Likely on the order of 1-2 bytes per structured
306 string instead of putting it in-place. The consensus was that this did not
307 create as human-friendly messages as developers desired so the placeholder
310 `{fmt}` can use shorter placeholders of `{}` or `{3}`. The non-indexed syntax
312 prone with code maintenance. The indexed syntax is similarly error prone and