Commit | Line | Data |
---|---|---|
beb0fb75 PP |
1 | = Babeltrace logging guide |
2 | Philippe Proulx | |
4a41523d | 3 | 31 May 2017 |
beb0fb75 PP |
4 | :toc: |
5 | :toclevels: 5 | |
6 | ||
7 | This guide explains to the Babeltrace developer how to insert logging | |
8 | statements in Babeltrace's CLI, library, and plugins. | |
9 | ||
10 | ||
11 | == Motive | |
12 | ||
13 | Logging is a great instrument for a developer to be able to collect | |
14 | information about a running software. | |
15 | ||
16 | Babeltrace is a complex software with many layers. When a Babeltrace | |
17 | graph fails to run, what caused the failure? It could be caused by any | |
18 | component, any notification iterator, and any deeply nested validation | |
19 | of a CTR IR object, for example. With the appropriate logging statements | |
20 | manually placed in the source code, we can find the cause of a bug | |
21 | faster. | |
22 | ||
23 | While <<level,care must be taken>> when placing _INFO_ to _FATAL_ | |
24 | logging statements, you should deliberately instrument your Babeltrace | |
25 | module with _DEBUG_ and _VERBOSE_ logging statements to help future | |
26 | you and other developers understand what's happening at run-time. | |
27 | ||
28 | ||
29 | == API | |
30 | ||
31 | The Babeltrace logging API is internal: it is not exposed to the users | |
32 | of the library, only to their developers. The only thing that a library | |
4a41523d | 33 | user can control is the current log level of the library itself with |
beb0fb75 PP |
34 | `bt_logging_set_global_level()` and the initial library's log level with |
35 | the `BABELTRACE_LOGGING_GLOBAL_LEVEL` environment variable. | |
36 | ||
37 | This API is based on https://github.com/wonder-mice/zf_log[zf_log], a | |
38 | lightweight, yet featureful, MIT-licensed core logging library for C and | |
39 | $$C++$$. The zf_log source files were modified to have the `BT_` and | |
40 | `bt_` prefixes, and other small changes. | |
41 | ||
42 | The logging functions are implemented in the logging convenience | |
43 | library (`logging` directory). | |
44 | ||
45 | ||
46 | === Headers | |
47 | ||
48 | The logging API headers are: | |
49 | ||
50 | `<babeltrace/logging.h>`:: | |
51 | Public header which a library user can use to control and read | |
52 | libbabeltrace's current log level. | |
53 | ||
54 | `<babeltrace/logging-internal.h>`:: | |
55 | Internal, generic logging API which you can use in any Babeltrace | |
56 | subproject. This is the translation of `zf_log.h`. | |
57 | ||
58 | `<babeltrace/lib-logging-internal.h>`:: | |
59 | Specific internal header to use within the library. This header | |
60 | defines `BT_LOG_OUTPUT_LEVEL` to a custom, library-wide hidden | |
61 | symbol which is the library's current log level before including | |
62 | `<babeltrace/logging-internal.h>`. | |
63 | ||
64 | Do not include `<babeltrace/logging-internal.h>` or | |
65 | `<babeltrace/lib-logging-internal.h>` in a header which contains logging | |
66 | statements: this header could be included in source files which define a | |
67 | different <<tag,tag>>, for example. | |
68 | ||
69 | ||
b4b9064d | 70 | |
beb0fb75 PP |
71 | === Log levels === |
72 | ||
73 | The API offers the following log levels: | |
74 | ||
75 | * _VERBOSE_ | |
76 | * _DEBUG_ | |
77 | * _INFO_ | |
78 | * _WARN_ | |
79 | * _ERROR_ | |
80 | * _FATAL_ | |
81 | ||
82 | See <<level,how to decide which one to use>> below. | |
83 | ||
84 | There are two important log level variables: | |
85 | ||
86 | [[build-time-log-level]]Build-time, minimal log level:: | |
87 | The minimal log level, or build-time log level, is set at build | |
88 | time and determines the minimal log level which can be executed. | |
89 | This applies to all the subprojects and modules (CLI, library, | |
90 | plugins, etc.). | |
91 | + | |
92 | All the logging statements with a level below this level are **not built | |
93 | at all**. All the logging statements with a level equal to or greater | |
94 | than this level _can_ be executed, depending on the run-time log level | |
95 | (see below). | |
96 | + | |
97 | You can set this level at configuration time with the | |
98 | `BABELTRACE_MINIMAL_LOG_LEVEL` environment variable, for example: | |
99 | + | |
100 | -- | |
101 | ---- | |
102 | $ BABELTRACE_MINIMAL_LOG_LEVEL=WARN ./configure | |
103 | ---- | |
104 | -- | |
105 | + | |
106 | The default build-time log level is `DEBUG`. For optimal performance, | |
107 | set it to `NONE`, which effectively disables all logging in all the | |
108 | Babeltrace subprojects. | |
109 | + | |
110 | The library's public API provides `bt_logging_get_minimal_level()` to | |
111 | get the configured minimal log level. | |
112 | ||
113 | [[run-time-log-level]]Run-time, dynamic log level:: | |
114 | The dynamic log level is set at run-time and determines the current, | |
115 | active log level. All the logging statements with a level below this | |
116 | level are not executed, but they evaluate the condition. All the | |
117 | logging statements with a level equal to or greater than this level | |
118 | are executed, provided that their level is also enabled at build | |
119 | time (see above). | |
120 | + | |
121 | In `zf_log`, there is a concept of a global run-time log level which | |
122 | uses the `_bt_log_global_output_lvl` symbol. In practice, we never use | |
123 | this symbol, and always make sure that `BT_LOG_OUTPUT_LEVEL` is defined | |
124 | to a module-wise or subproject-wise hidden symbol before including | |
125 | `<babeltrace/logging-internal.h>`. In the library, | |
126 | `<babeltrace/lib-logging-internal.h>` does this job: just include | |
127 | this header which defines `BT_LOG_OUTPUT_LEVEL` to the appropriate | |
128 | symbol before it includes `<babeltrace/logging-internal.h>`. In plugins, | |
129 | for example, there is one log level per component class, which makes | |
130 | log filtering easier during execution. | |
131 | + | |
132 | In libbabeltrace, the user can set the current run-time log level with | |
133 | the `bt_logging_set_global_level()` function, for example: | |
134 | + | |
135 | -- | |
136 | [source,c] | |
137 | ---- | |
138 | bt_logging_set_global_level(BT_LOGGING_LEVEL_INFO); | |
139 | ---- | |
140 | -- | |
141 | + | |
142 | The library's initial run-time log level is defined by the | |
143 | `BABELTRACE_LOGGING_GLOBAL_LEVEL` environment variable (`VERBOSE`, `DEBUG`, | |
144 | `INFO`, `WARN`, `ERROR`, `FATAL`, or `NONE`), or set to _NONE_ if this | |
145 | environment variable is undefined. | |
146 | + | |
147 | Other subprojects have their own way of setting their run-time log | |
148 | level. For example, the CLI uses the `BABELTRACE_CLI_LOG_LEVEL` | |
149 | environment variable, and the `text.pretty` sink component class | |
150 | initializes its log level thanks to the | |
151 | `BABELTRACE_PLUGIN_TEXT_PRETTY_SINK_LOG_LEVEL` environment variable | |
152 | (also _NONE_ by default). | |
153 | + | |
154 | Make sure that there is a documented way to initialize or modify the | |
155 | log level of your subproject or module, and that it's set to _NONE_ | |
156 | by default. | |
157 | ||
158 | ||
4a41523d | 159 | [[logging-statements]] |
beb0fb75 PP |
160 | === Logging statement macros |
161 | ||
162 | The Babeltrace logging statement macros work just like `printf()` and | |
163 | contain their log level in their name: | |
164 | ||
165 | `BT_LOGV("format string", ...)`:: | |
166 | Standard verbose logging statement. | |
167 | ||
168 | `BT_LOGD("format string", ...)`:: | |
169 | Standard debug logging statement. | |
170 | ||
171 | `BT_LOGI("format string", ...)`:: | |
172 | Standard info logging statement. | |
173 | ||
174 | `BT_LOGW("format string", ...)`:: | |
175 | Standard warning logging statement. | |
176 | ||
177 | `BT_LOGE("format string", ...)`:: | |
178 | Standard error logging statement. | |
179 | ||
180 | `BT_LOGF("format string", ...)`:: | |
181 | Standard fatal logging statement. | |
182 | ||
183 | `BT_LOGV_MEM(data_ptr, data_size, "format string", ...)`:: | |
184 | Memory verbose logging statement. | |
185 | ||
186 | `BT_LOGD_MEM(data_ptr, data_size, "format string", ...)`:: | |
187 | Memory debug logging statement. | |
188 | ||
189 | `BT_LOGI_MEM(data_ptr, data_size, "format string", ...)`:: | |
190 | Memory info logging statement. | |
191 | ||
192 | `BT_LOGW_MEM(data_ptr, data_size, "format string", ...)`:: | |
193 | Memory warning logging statement. | |
194 | ||
195 | `BT_LOGE_MEM(data_ptr, data_size, "format string", ...)`:: | |
196 | Memory error logging statement. | |
197 | ||
198 | `BT_LOGF_MEM(data_ptr, data_size, "format string", ...)`:: | |
199 | Memory fatal logging statement. | |
200 | ||
201 | `BT_LOGV_STR("preformatted string")`:: | |
202 | Preformatted string verbose logging statement. | |
203 | ||
204 | `BT_LOGD_STR("preformatted string")`:: | |
205 | Preformatted string debug logging statement. | |
206 | ||
207 | `BT_LOGI_STR("preformatted string")`:: | |
208 | Preformatted string info logging statement. | |
209 | ||
210 | `BT_LOGW_STR("preformatted string")`:: | |
211 | Preformatted string warning logging statement. | |
212 | ||
213 | `BT_LOGE_STR("preformatted string")`:: | |
214 | Preformatted string error logging statement. | |
215 | ||
216 | `BT_LOGF_STR("preformatted string")`:: | |
217 | Preformatted string fatal logging statement. | |
218 | ||
219 | ||
220 | === Conditional logging | |
221 | ||
222 | `BT_LOG_IF(cond, statement)`:: | |
223 | Execute `statement` only if `cond` is true. | |
224 | + | |
225 | Example: | |
226 | + | |
227 | -- | |
228 | [source,c] | |
229 | ---- | |
230 | BT_LOG_IF(i < count / 2, BT_LOGD("Log this: i=%d", i)); | |
231 | ---- | |
232 | -- | |
233 | ||
234 | To check the <<build-time-log-level,build-time log level>>: | |
235 | ||
236 | [source,c] | |
237 | ---- | |
238 | #if BT_LOG_ENABLED_DEBUG | |
239 | ... | |
240 | #endif | |
241 | ---- | |
242 | ||
243 | This tests if the _DEBUG_ level was enabled at build-time. This | |
244 | means that the current, dynamic log level _could_ be _DEBUG_, but it | |
245 | could also be higher. The rule of thumb is to use only logging | |
246 | statements at the same level in a `BT_LOG_ENABLED_*` conditional block. | |
247 | ||
248 | The available definitions for build-time conditions are: | |
249 | ||
250 | * `BT_LOG_ENABLED_VERBOSE` | |
251 | * `BT_LOG_ENABLED_DEBUG` | |
252 | * `BT_LOG_ENABLED_INFO` | |
253 | * `BT_LOG_ENABLED_WARN` | |
254 | * `BT_LOG_ENABLED_ERROR` | |
255 | * `BT_LOG_ENABLED_FATAL` | |
256 | ||
257 | To check the current, <<run-time-log-level,run-time log level>>: | |
258 | ||
259 | [source,c] | |
260 | ---- | |
261 | if (BT_LOG_ON_DEBUG) { | |
262 | ... | |
263 | } | |
264 | ---- | |
265 | ||
266 | This tests if the _DEBUG_ log level is dynamically turned on | |
267 | (implies that it's also enabled at build-time). This check could have a | |
268 | noticeable impact on performance. | |
269 | ||
270 | The available definitions for run-time conditions are: | |
271 | ||
272 | * `BT_LOG_ON_VERBOSE` | |
273 | * `BT_LOG_ON_DEBUG` | |
274 | * `BT_LOG_ON_INFO` | |
275 | * `BT_LOG_ON_WARN` | |
276 | * `BT_LOG_ON_ERROR` | |
277 | * `BT_LOG_ON_FATAL` | |
278 | ||
279 | Those macros check the subproject-specific or module-specific log level | |
280 | symbol (defined by `BT_LOG_OUTPUT_LEVEL`). | |
281 | ||
282 | Never, ever write code which would be executed only to compute the | |
283 | fields of a logging statement outside a conditional logging scope, | |
284 | for example: | |
285 | ||
286 | [source,c] | |
287 | ---- | |
288 | int number = get_number_of_event_classes_with_property_x(...); | |
289 | BT_LOGD("Bla bla: number=%d", number); | |
290 | ---- | |
291 | ||
292 | Do this instead: | |
293 | ||
294 | [source,c] | |
295 | ---- | |
296 | if (BT_LOG_ON_DEBUG) { | |
297 | int number = get_number_of_event_classes_with_property_x(...); | |
298 | BT_LOGD("Bla bla: number=%d", number); | |
299 | } | |
300 | ---- | |
301 | ||
302 | Or even this: | |
303 | ||
304 | [source,c] | |
305 | ---- | |
306 | BT_LOGD("Bla bla: number=%d", get_number_of_event_classes_with_property_x(...)); | |
307 | ---- | |
308 | ||
309 | ||
4a41523d PP |
310 | [[how-to]] |
311 | === Instrument a module | |
beb0fb75 | 312 | |
4a41523d | 313 | Follow those steps to make your module loggable: |
beb0fb75 | 314 | |
4a41523d PP |
315 | . In your module's root directory, create a `logging.c` file with |
316 | this content: | |
317 | + | |
318 | -- | |
319 | [source,c] | |
320 | ---- | |
321 | /* | |
322 | * Copyright (c) 2017 EfficiOS Inc. <http://efficios.com/> | |
323 | * | |
324 | * Permission is hereby granted, free of charge, to any person obtaining a copy | |
325 | * of this software and associated documentation files (the "Software"), to deal | |
326 | * in the Software without restriction, including without limitation the rights | |
327 | * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell | |
328 | * copies of the Software, and to permit persons to whom the Software is | |
329 | * furnished to do so, subject to the following conditions: | |
330 | * | |
331 | * The above copyright notice and this permission notice shall be included in | |
332 | * all copies or substantial portions of the Software. | |
333 | * | |
334 | * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR | |
335 | * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, | |
336 | * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE | |
337 | * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER | |
338 | * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, | |
339 | * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE | |
340 | * SOFTWARE. | |
341 | */ | |
342 | ||
343 | #define BT_LOG_OUTPUT_LEVEL my_module_log_level | |
344 | #include <babeltrace/logging-internal.h> | |
beb0fb75 | 345 | |
4a41523d PP |
346 | BT_LOG_INIT_LOG_LEVEL(my_module_log_level, "BABELTRACE_MY_MODULE_LOG_LEVEL"); |
347 | ---- | |
348 | -- | |
349 | + | |
350 | Replace `my_module_log_level` with the name of the symbol which holds | |
351 | the log level for your module (should be unique amongst all the log level | |
352 | symbols of the project). Replace `BABELTRACE_MY_MODULE_LOG_LEVEL` with | |
353 | the name of the environment variable from which to initialize your | |
354 | module's log level at construction time. `BT_LOG_INIT_LOG_LEVEL()` | |
355 | defines both the hidden log level symbol and a constructor which reads | |
356 | the environment variable and sets the log level symbol accordingly. | |
357 | ||
358 | . In your module's root directory, create a `logging.h` file with | |
359 | this content: | |
360 | + | |
361 | -- | |
beb0fb75 PP |
362 | [source,c] |
363 | ---- | |
4a41523d PP |
364 | #ifndef MY_MODULE_LOGGING_H |
365 | #define MY_MODULE_LOGGING_H | |
366 | ||
367 | /* | |
368 | * Copyright (c) 2017 EfficiOS Inc. <http://efficios.com/> | |
369 | * | |
370 | * Permission is hereby granted, free of charge, to any person obtaining a copy | |
371 | * of this software and associated documentation files (the "Software"), to deal | |
372 | * in the Software without restriction, including without limitation the rights | |
373 | * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell | |
374 | * copies of the Software, and to permit persons to whom the Software is | |
375 | * furnished to do so, subject to the following conditions: | |
376 | * | |
377 | * The above copyright notice and this permission notice shall be included in | |
378 | * all copies or substantial portions of the Software. | |
379 | * | |
380 | * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR | |
381 | * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, | |
382 | * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE | |
383 | * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER | |
384 | * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, | |
385 | * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE | |
386 | * SOFTWARE. | |
387 | */ | |
388 | ||
389 | #define BT_LOG_OUTPUT_LEVEL my_module_log_level | |
beb0fb75 | 390 | #include <babeltrace/logging-internal.h> |
4a41523d PP |
391 | |
392 | BT_LOG_LEVEL_EXTERN_SYMBOL(my_module_log_level); | |
393 | ||
394 | #endif /* MY_MODULE_LOGGING_H */ | |
beb0fb75 | 395 | ---- |
4a41523d PP |
396 | -- |
397 | + | |
398 | Again, replace `my_module_log_level` with the name of your module's | |
399 | log level symbol. | |
400 | ||
401 | . Include the `logging.c` and `logging.h` in the `_SOURCES` variable | |
402 | of your module's object in your module's root `Makefile.am`. | |
beb0fb75 | 403 | |
4a41523d PP |
404 | To instrument a C source file (`.c`): |
405 | ||
406 | . At the top of the file, before the first `#include` line (if any), | |
407 | define your file's tag name and include the local `logging.h`: | |
408 | + | |
409 | -- | |
410 | [source,c] | |
411 | ---- | |
412 | #define BT_LOG_TAG "MY-MODULE-MY-FILE" | |
413 | #include "logging.h" | |
414 | ---- | |
415 | -- | |
416 | + | |
417 | A logging tag name is a namespace for a specific source file. Its name | |
418 | is part of every log message generated by the statements of the file. A | |
419 | logging tag name _must_ be only uppercase letters, digits, and the | |
420 | hyphen (`-`) character. See <<tags,Babeltrace standard tags>> for | |
421 | a list of standard tags. | |
422 | ||
423 | . Use the <<logging-statements,logging statement macros>> in the file's | |
424 | functions to instrument it. | |
425 | ||
426 | To instrument a C header file (`.h`), if you have `static inline` | |
427 | functions in it: | |
428 | ||
429 | . Do not include any logging header. | |
430 | . Use the <<logging-statements,logging statement macros>> in the file's | |
431 | functions to instrument it, making each of them conditional to the | |
432 | existence of the macro you're using: | |
433 | + | |
434 | -- | |
435 | [source,c] | |
436 | ---- | |
437 | static inline | |
438 | void some_function(void) | |
439 | { | |
440 | /* ... */ | |
441 | ||
442 | #ifdef BT_LOGV | |
443 | BT_LOGV(...); | |
444 | #endif | |
445 | ||
446 | /* ... */ | |
447 | ||
448 | #ifdef BT_LOGW_STR | |
449 | BT_LOGW_STR(...); | |
450 | #endif | |
451 | ||
452 | /* ... */ | |
453 | } | |
454 | ---- | |
455 | -- | |
456 | + | |
457 | The C source files which include this header file determine if logging | |
458 | is enabled or not for them (if the source file is instrumented itself), | |
459 | and the tag of the included header's logging statement is the same as | |
460 | the C source file. | |
beb0fb75 PP |
461 | |
462 | ||
4a41523d PP |
463 | [[tags]] |
464 | === Babeltrace standard tags | |
beb0fb75 PP |
465 | |
466 | ==== CTF IR (library) | |
467 | ||
468 | [options="header,autowidth"] | |
469 | |=== | |
470 | |Subsystem/object |Tag name | |
471 | ||
472 | |Attributes |`ATTRS` | |
473 | |Clock class and values |`CLOCK-CLASS` | |
474 | |Event class |`EVENT-CLASS` | |
475 | |Event |`EVENT` | |
476 | |Field path |`FIELD-PATH` | |
477 | |Field types |`FIELD-TYPES` | |
478 | |Fields |`FIELDS` | |
479 | |Packet |`PACKET` | |
480 | |Resolver |`RESOLVE` | |
481 | |Stream class |`STREAM-CLASS` | |
482 | |Stream |`STREAM` | |
483 | |Trace |`TRACE` | |
484 | |Validation |`VALIDATION` | |
485 | |Visitor |`VISITOR` | |
486 | |=== | |
487 | ||
488 | ||
489 | ==== CTF writer (library) | |
490 | ||
491 | [options="header,autowidth"] | |
492 | |=== | |
493 | |Subsystem/object |Tag name | |
494 | ||
495 | |Clock |`CTF-WRITER-CLOCK` | |
496 | |CTF writer |`CTF-WRITER` | |
497 | |Serialization |`CTF-WRITER-SER` | |
498 | |=== | |
499 | ||
500 | ||
501 | ==== Graph (library) | |
502 | ||
503 | [options="header,autowidth"] | |
504 | |=== | |
505 | |Subsystem/object |Tag name | |
506 | ||
507 | |Clock class priority map |`CC-PRIO-MAP` | |
508 | |Component (common) |`COMP` | |
509 | |Component class |`COMP-CLASS` | |
510 | |Connection |`CONNECTION` | |
511 | |Filter component |`COMP-FILTER` | |
512 | |Graph |`GRAPH` | |
513 | |Notification iterator |`NOTIF-ITER` | |
514 | |Port |`PORT` | |
515 | |Sink component |`COMP-SINK` | |
516 | |Source component |`COMP-SOURCE` | |
517 | |=== | |
518 | ||
519 | ==== Notifications (library) | |
520 | ||
521 | [options="header,autowidth"] | |
522 | |=== | |
523 | |Subsystem/object |Tag name | |
524 | ||
525 | |Event notification |`NOTIF-EVENT` | |
526 | |Inacitivity notification |`NOTIF-INACTIVITY` | |
527 | |Notification |`NOTIF` | |
528 | |Packet notification |`NOTIF-PACKET` | |
529 | |Stream notification |`NOTIF-STREAM` | |
530 | |=== | |
531 | ||
532 | ||
533 | ==== Plugin (library) | |
534 | ||
535 | [options="header,autowidth"] | |
536 | |=== | |
537 | |Subsystem/object |Tag name | |
538 | ||
539 | |Plugin |`PLUGIN` | |
540 | |Python plugin provider |`PLUGIN-PY` | |
541 | |Shared object plugin provider |`PLUGIN-SO` | |
542 | |=== | |
543 | ||
544 | ||
545 | ==== Values (library) | |
546 | ||
547 | [options="header,autowidth"] | |
548 | |=== | |
549 | |Subsystem/object |Tag name | |
550 | ||
551 | |Values |`VALUES` | |
552 | |=== | |
553 | ||
554 | ||
555 | ==== Reference counting (library) | |
556 | ||
557 | [options="header,autowidth"] | |
558 | |=== | |
559 | |Subsystem/object |Tag name | |
560 | ||
561 | |Reference counting |`REF` | |
562 | |=== | |
563 | ||
564 | ||
565 | ==== Common (library) | |
566 | ||
567 | [options="header,autowidth"] | |
568 | |=== | |
569 | |Subsystem/object |Tag name | |
570 | ||
571 | |Common |`COMMON` | |
572 | |=== | |
573 | ||
574 | ||
575 | ==== CLI | |
576 | ||
577 | [options="header,autowidth"] | |
578 | |=== | |
579 | |Subsystem/object |Tag name | |
580 | ||
581 | |CLI (main) |`CLI` | |
582 | |CLI configuration (common) |`CLI-CFG` | |
583 | |CLI configuration from CLI arguments |`CLI-CFG-ARGS` | |
584 | |CLI connection configuration from CLI arguments |`CLI-CFG-ARGS-CONNECT` | |
585 | |=== | |
586 | ||
587 | ||
588 | ==== libctfcopytrace (plugin convenience library) | |
589 | ||
590 | [options="header,autowidth"] | |
591 | |=== | |
592 | |Subsystem/object |Tag name | |
593 | ||
594 | |Clock fields |`LIBCTFCOPYTRACE-CLOCK-FIELDS` | |
595 | |libctfcopytrace |`LIBCTFCOPYTRACE` | |
596 | |=== | |
597 | ||
598 | ||
599 | ==== `ctf` plugin | |
600 | ||
601 | [options="header,autowidth"] | |
602 | |=== | |
603 | |Subsystem/object |Tag name | |
604 | ||
605 | |Plugin (main) |`PLUGIN-CTF` | |
606 | |Common: BTR |`PLUGIN-CTF-BTR` | |
607 | |Common: CTF IR generation metadata visitor |`PLUGIN-CTF-METADATA-IR-VISITOR` | |
608 | |Common: Metadata decoder |`PLUGIN-CTF-METADATA-DECODER` | |
609 | |Common: Metadata lexer |`PLUGIN-CTF-METADATA-LEXER` | |
610 | |Common: Metadata parser |`PLUGIN-CTF-METADATA-PARSER` | |
611 | |Common: Notification iterator |`PLUGIN-CTF-NOTIF-ITER` | |
612 | |`fs` sink (main) |`PLUGIN-CTF-FS-SINK` | |
613 | |`fs` sink: write |`PLUGIN-CTF-FS-SINK-WRITE` | |
614 | |`fs` source (main) |`PLUGIN-CTF-FS-SRC` | |
615 | |`fs` source: data stream |`PLUGIN-CTF-FS-SRC-DS` | |
616 | |`fs` source: file |`PLUGIN-CTF-FS-SRC-FILE` | |
617 | |`fs` source: metadata |`PLUGIN-CTF-FS-SRC-METADATA` | |
4a41523d PP |
618 | |`lttng-live` source (main) |`PLUGIN-CTF-LTTNG-LIVE-SRC` |
619 | |`lttng-live` source: data stream |`PLUGIN-CTF-LTTNG-LIVE-SRC-DS` | |
620 | |`lttng-live` source: metadata |`PLUGIN-CTF-LTTNG-LIVE-SRC-METADATA` | |
621 | |`lttng-live` source: viewer connection |`PLUGIN-CTF-LTTNG-LIVE-SRC-VIEWER` | |
beb0fb75 PP |
622 | |=== |
623 | ||
624 | ||
625 | ==== `lttng-utils` plugin | |
626 | ||
627 | [options="header,autowidth"] | |
628 | |=== | |
629 | |Subsystem/object |Tag name | |
630 | ||
631 | |Plugin (main) |`PLUGIN-LTTNG-UTILS` | |
4a41523d PP |
632 | |`debug-info` filter (main) |`PLUGIN-LTTNG-UTILS-DBG-INFO-FILT` |
633 | |`debug-info` filter: binary info |`PLUGIN-LTTNG-UTILS-DBG-INFO-FILT-BIN-INFO` | |
634 | |`debug-info` filter: copy |`PLUGIN-LTTNG-UTILS-DBG-INFO-FILT-COPY` | |
635 | |`debug-info` filter: CRC32 |`PLUGIN-LTTNG-UTILS-DBG-INFO-FILT-CRC32` | |
636 | |`debug-info` filter: DWARF |`PLUGIN-LTTNG-UTILS-DBG-INFO-FILT-DWARF` | |
beb0fb75 PP |
637 | |=== |
638 | ||
639 | ||
640 | ==== `text` plugin | |
641 | ||
642 | [options="header,autowidth"] | |
643 | |=== | |
644 | |Subsystem/object |Tag name | |
645 | ||
646 | |Plugin (main) |`PLUGIN-TEXT` | |
4a41523d PP |
647 | |`pretty` filter (main) |`PLUGIN-TEXT-PRETTY-SINK` |
648 | |`pretty` filter: print |`PLUGIN-TEXT-PRETTY-SINK-PRINT` | |
beb0fb75 PP |
649 | |=== |
650 | ||
651 | ||
652 | ==== `utils` plugin | |
653 | ||
654 | [options="header,autowidth"] | |
655 | |=== | |
656 | |Subsystem/object |Tag name | |
657 | ||
658 | |Plugin (main) |`PLUGIN-UTILS` | |
4a41523d PP |
659 | |`dummy` sink (main) |`PLUGIN-UTILS-DUMMY-SINK` |
660 | |`muxer` filter (main) |`PLUGIN-UTILS-MUXER-FILT` | |
661 | |`trimmer` filter (main) |`PLUGIN-UTILS-TRIMMER-FILT` | |
662 | |`trimmer` filter: copy |`PLUGIN-UTILS-TRIMMER-FILT-COPY` | |
663 | |`trimmer` filter: iterator |`PLUGIN-UTILS-TRIMMER-FILT-ITER` | |
beb0fb75 PP |
664 | |=== |
665 | ||
666 | ||
667 | [[level]] | |
b4b9064d | 668 | == Choose a log level |
beb0fb75 PP |
669 | |
670 | Choosing the appropriate level for your logging statement is very | |
671 | important. | |
672 | ||
673 | [options="header,autowidth",cols="default,default,asciidoc,default"] | |
674 | |=== | |
675 | |Log level |Description |Use cases |Impact on performance | |
676 | ||
677 | |_FATAL_ | |
678 | |The program, library, or plugin cannot continue to work in this | |
679 | condition: it must be terminated immediately. | |
680 | ||
b4b9064d | 681 | A _FATAL_-level logging statement should always be followed by |
4a41523d | 682 | `abort()`. |
beb0fb75 PP |
683 | | |
684 | * Unexpected return values from system calls. | |
4a41523d PP |
685 | * Logic error in internal code, for example an unexpected value in a |
686 | `switch` statement. | |
beb0fb75 PP |
687 | |Almost none: should be executed in production. |
688 | ||
689 | |_ERROR_ | |
690 | |An important error which is somewhat not fatal, that is, the program, | |
691 | library, or plugin can continue to work after this, but you judge that | |
692 | it should be reported to the user. | |
693 | ||
694 | Usually, the program cannot recover from such an error, but it can at | |
695 | least exit cleanly. | |
696 | | | |
697 | * Memory allocation errors. | |
698 | * Failed to perform an operation which should work considering the | |
699 | implementation and the satisfied preconditions. For example, the | |
700 | failure to create an empty object (no parameters): most probably | |
701 | failed internally because of an allocation error. | |
702 | |Almost none: should be executed in production. | |
703 | ||
704 | |_WARN_ | |
705 | |A logic error which still allows the execution to continue. | |
6c1b33a8 PP |
706 | |
707 | _WARN_-level logging statements are for any error or weird action that | |
708 | is directly or indirectly caused by the user. For example, not having | |
4a41523d PP |
709 | enough memory is considered beyond the user's control, so we always |
710 | log memory errors with an _ERROR_ level (not _FATAL_ because we usually | |
711 | don't abort in this condition). | |
beb0fb75 | 712 | | |
6c1b33a8 PP |
713 | * Not honoring a public function's preconditions (NULL parameters, |
714 | index out of bounds, etc.). | |
715 | * Adding an invalid event class to a stream class which is already | |
716 | part of a trace. | |
beb0fb75 PP |
717 | + |
718 | For example, the caller tries to set a property of a frozen stream | |
719 | class. | |
720 | |Almost none: can be executed in production. | |
721 | ||
722 | |_INFO_ | |
723 | |Any useful information which a non-developer user would understand. | |
724 | | | |
725 | * Successful loading of a plugin (with name, version, etc.). | |
726 | * Successful connection to or disconnection from another system. | |
4a41523d | 727 | * An _optional_ subsystem cannot be loaded. |
beb0fb75 PP |
728 | |Very little: can be executed in production if |
729 | _INFO_ level information is desired. | |
730 | ||
731 | |_DEBUG_ | |
732 | |Something that only Babeltrace developers would be interested into. | |
733 | | | |
734 | * High-level function entry/exit. | |
735 | * Object creation, destruction, copying, and freezing. | |
736 | * The result of some computation/validation. | |
737 | |Noticeable, but not as much as the _VERBOSE_ level: not executed in | |
738 | production. | |
739 | ||
740 | |_VERBOSE_ | |
741 | |Low-level debugging context information. More appropriate for tracing | |
742 | in general. | |
743 | | | |
744 | * Reference count change. | |
745 | * Status of each iteration of a loop. | |
746 | * State machine's state change. | |
747 | * Data structure lookup/modification. | |
748 | * List of ELF sections found in a plugin. | |
749 | * Get or set an object's property. | |
750 | * Object comparison's intermediate results. | |
751 | |Huge: not executed in production. | |
752 | |=== | |
753 | ||
b4b9064d PP |
754 | Make sure not to use a _WARN_ (or higher) log level when the condition |
755 | leading to the logging statement can occur under normal circumstances. | |
756 | For example, a public function to get some object or property from an | |
757 | object by name or key that fails to find the value is not a warning: the | |
758 | user could legitimately use this function to check if the name/key | |
759 | exists in the object. In this case, use the _VERBOSE_ level (or do not | |
760 | log at all). If a numeric index is out of bounds, however, this | |
761 | qualifies for a _WARN_ level: such API functions have documented | |
762 | preconditions that the index must be in bounds (the user can always | |
763 | check with a count or size function). | |
764 | ||
beb0fb75 | 765 | |
b4b9064d PP |
766 | [[message]] |
767 | == Write an appropriate message | |
beb0fb75 PP |
768 | |
769 | Follow those rules when you write a logging statement's message: | |
770 | ||
771 | * Use an english sentence which starts with a capital letter. Start the | |
772 | sentence with the appropriate verb tense depending on the context. For | |
773 | example: | |
774 | + | |
775 | -- | |
b4b9064d PP |
776 | ** Beginning of operation (present continuous): _Creating ..._, |
777 | _Copying ..._, _Serializing ..._, _Freezing ..._, _Destroying ..._ | |
778 | ** End of operation (simple past): _Created ..._, _Successfully created ..._, | |
779 | _Failed to create ..._, _Set ..._ (simple past of _to set_ which is | |
780 | also _set_) | |
beb0fb75 PP |
781 | -- |
782 | + | |
783 | For warning and error messages, you can start the message with _Cannot_ | |
b4b9064d | 784 | or _Failed to_ followed by a verb if it's appropriate. |
beb0fb75 PP |
785 | |
786 | * Do not include the log level in the message itself. For example, | |
787 | do not start the message with _Error while_ or _Warning:_. | |
788 | ||
789 | * Do not put newlines, tabs, or other special characters in the | |
790 | message, unless you want to log a string with such characters. Note | |
791 | that multiline log messages can be hard to parse, analyze, and filter, | |
b4b9064d PP |
792 | however, so prefer multiple `BT_LOG*()` statements over a single |
793 | statement with newlines. | |
beb0fb75 PP |
794 | |
795 | * **If there are fields that your logging statement must record**, | |
796 | follow the message with `:` followed by a space, then with the list of | |
797 | fields (more about this below). If there are no fields, end the | |
798 | sentence with a period. | |
799 | ||
800 | The statement's fields _must_ be a comma-separated list of | |
801 | +__name__=__value__+ tokens. Keep +__name__+ as simple as possible | |
b4b9064d PP |
802 | (lowercase if possible). If +__value__+ is a non-alphanumeric string, |
803 | put it between double quotes. Always use the `PRId64` and `PRIu64` | |
804 | specifiers when logging `int64_t` and `uint64_t` values. | |
beb0fb75 PP |
805 | |
806 | Example: | |
807 | ||
808 | "Cannot add event class to stream class: stream-class-addr=%p, " | |
b4b9064d | 809 | "stream-class-name=\"%s\", stream-class-id=%" PRId64 ", " |
beb0fb75 PP |
810 | "event-class-addr=%p, event-class-name=\"%s\", event-class-id=%" PRId64 |
811 | ||
812 | By following a standard format for the statement fields, it is easier | |
813 | to use tools like https://www.elastic.co/products/logstash[Logstash] | |
814 | to split fields and analyze logs. | |
815 | ||
816 | Prefer the following suffixes in field names: | |
817 | ||
818 | [options="header,autowidth"] | |
819 | |=== | |
820 | |Field name suffix |Description |Format specifier | |
821 | ||
822 | |`-addr` |Memory address |`%p` | |
823 | |`-fd` |File descriptor |`%d` | |
824 | |`-fp` |File stream (`FILE *`) |`%p` | |
825 | |`-id` |Object's ID |`%" PRId64 "` or `%" PRIu64 "` | |
826 | |`-name` |Object's name |`\"%s\"` | |
beb0fb75 PP |
827 | |=== |
828 | ||
829 | ||
830 | == Output | |
831 | ||
832 | The log is printed to the standard error stream. A log line contains the | |
4a41523d | 833 | time, the process and thread IDs, the <<level,log level>>, the tag name, |
b4b9064d PP |
834 | the source's function name, file name and line number, and the |
835 | <<message,message>>. | |
beb0fb75 PP |
836 | |
837 | Example: | |
838 | ||
839 | 05-11 00:58:03.691 23402 23402 D VALUES bt_value_destroy@values.c:498 Destroying value: addr=0xb9c3eb0 | |
840 | ||
841 | You can easily filter the log with `grep` or `ag`. For example, to | |
842 | keep only the _WARN_-level log messages that the `VALUES` module | |
843 | generates: | |
844 | ||
845 | $ export BABELTRACE_LOGGING_GLOBAL_LEVEL=VERBOSE | |
846 | $ ./test_ctf_writer_complete 2>&1 | ag 'W VALUES' |