1 = Babeltrace's contributor's guide
2 Jérémie Galarneau, Philippe Proulx
8 This is a partial contributor's guide for the
9 http://diamon.org/babeltrace[Babeltrace] project. If you have any
10 questions that are not answered in this guide, please post them
11 on https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev[Babeltrace's mailing list].
14 == Object reference counting and lifetime
16 This section covers the rationale behind the design of Babeltrace's
17 object lifetime management.
19 Starting from Babeltrace 2.x, all publicly exposed objects inherit a
20 common base: `bt_object`. This base provides a number of facilities to
21 all objects, chief amongst which are lifetime management functions.
23 The reference count of all public objects is controlled by invoking the
24 `bt_get()` and `bt_put()` functions which respectively increment and
25 decrement an object's reference count.
27 As far as lifetime management in concerned, Babeltrace makes a clear
28 distinction between regular objects, which have a single parent, and
29 root objects, which don't.
34 Let us consider a problematic case to illustrate the need for this
37 A user of the CTF Writer library declares a trace, which *has* a
38 stream class (the declaration of a stream) and that stream class, in
39 turn, *has* an event class (the declaration of an event).
41 Nothing prevents this user from releasing his reference on any one of
42 these objects in any order. However, all objects in the
43 __trace--stream class--event class__ hierarchy can be retrieved
46 For instance, the user could discard his reference on both the event
47 class and the stream class, only keeping a reference on the trace. From
48 this trace reference, stream classes can be enumerated, providing the
49 user with a new reference to the stream class he discarded earlier.
50 event classes can also be enumerated from stream classes, providing the
51 user with references to the individual event classes.
53 Conversely, the user could also hold a reference to an event class and
54 retrieve its parent stream class. The trace, in turn, can then be
55 retrieved from the stream class.
57 This example illustrates what could be interpreted as a circular
58 reference dependency existing between these objects. Of course, if the
59 objects in such a scenario were to hold references to each other (in
60 both directions), we would be in presence of a circular ownership
61 resulting in a leak of both objects as their reference counts would
64 Nonetheless, the API must offer the guarantee that holding a node to any
65 node of the graph keeps all other reachable nodes alive.
70 The scheme employed in Babeltrace to break this cycle consists in the
71 "children" holding *reverse component references* to their parents. That
72 is, in the context of the trace IR, that event classes hold a reference
73 to their parent stream class and stream classes hold a reference to
76 On the other hand, parents hold *claiming aggregation references* to
77 their children. A claiming aggregation reference means that the object
78 being referenced should not be deleted as long as the reference still
79 exists. In this respect, it can be said that parents truly hold the
80 ownership of their children, since they control their lifetime.
81 Conversely, the reference counting mechanism is leveraged by children to
82 notify parents that no other child indirectly exposes the parent.
84 When a parented object's reference count reaches zero, it invokes
85 `bt_put()` on its parent and does **not** free itself. However, from
86 that point, the object depends on its parent to signal the moment when
87 it can be safely reclaimed.
89 The invocation of `bt_put()` by the last children holding a reference to
90 its parent might trigger a cascade of `bt_put()` from child to parent.
91 Eventually, a **root** object is reached. At that point, if this
92 orphaned object's reference count reaches zero, the object invokes the
93 destructor method defined by everyone of its children as part of their
94 base `struct bt_object`. The key point here is that the cascade of
95 destructor will necessarily originate from the root and propagate in
96 preorder to the children. These children will propagate the destruction
97 to their own children before reclaiming their own memory. This ensures
98 that a node's pointer to its parent is *always* valid since the parent
99 has the responsibility of tearing-down their children before cleaning
102 Assuming a reference to an object is *acquired* by calling `bt_get()`
103 while its reference count is zero, the object acquires, in turn, a
104 reference on its parent using `bt_get()`. At that point, the child can
105 be thought of as having converted its weak reference to its parent into
106 a regular reference. That is why this reference is referred to as a
107 *claiming* aggregation reference.
112 This scheme imposes a number of strict rules defining the relation
115 * Objects may only have one parent.
116 * Objects, beside the root, are only retrievable from their direct
122 The initial situation is rather simple: **User A** is holding a
123 reference to a trace, **TC1**. As per the rules previously enounced,
124 stream classes **SC1** and **SC2** don't hold a reference to **TC1**
125 since their own reference counts are zero. The same holds true for
126 **EC1**, **EC2** and **EC3** with respect to **SC1** and **SC2**.
128 image::doc/contributing-images/bt-ref01.png[]
130 In this second step, we can see that **User A** has acquired a reference
131 on **SC2** through the trace, **TC1**.
133 The stream class's reference count transitions from zero to one,
134 triggering the acquisition of a strong reference on **TC1** from
137 Hence, at this point, the trace's ownership is shared by **User A** and
140 image::doc/contributing-images/bt-ref02.png[]
142 Next, **User A** acquires a reference on the **EC3** event class through
143 its parent stream class, **SC2**. Again, the transition of an object's
144 reference count from 0 to 1 triggers the acquisition of a reference on
147 Note that SC2's reference count was incremented to 2. The trace's
148 reference count remains unchanged.
150 image::doc/contributing-images/bt-ref03.png[]
152 **User A** decides to drop its reference on **SC2**. **SC2**'s reference
153 count returns back to 1, everything else remaining unchanged.
155 image::doc/contributing-images/bt-ref04.png[]
157 **User A** can then decide to drop its reference on the trace. This
158 results in a reversal of the initial situation: **User A** now owns an
159 event, **EC3**, which is keeping everything else alive and reachable.
161 image::doc/contributing-images/bt-ref05.png[]
163 If another object, **User B**, enters the picture and acquires a
164 reference on the **SC1** stream class, we see that **SC1**'s reference
165 count transitioned from 0 to 1, triggering the acquisition of a
166 reference on **TC1**.
168 image::doc/contributing-images/bt-ref06.png[]
170 **User B** hands off a reference to **EC1**, acquired through **SC1**,
171 to another object, **User C**. The acquisition of a reference on
172 **EC1**, which transitions from 0 to 1, triggers the acquisition of a
173 reference on its parent, **SC1**.
175 image::doc/contributing-images/bt-ref07.png[]
177 At some point, **User A** releases its reference on **EC3**. Since
178 **EC3**'s reference count transitions to zero, it releases its reference
179 on **SC2**. **SC2**'s reference count, in turn, reaches zero and it
180 releases its reference to **TC1**.
182 **TC1**'s reference count is now 1 and no further action is taken.
184 image::doc/contributing-images/bt-ref08.png[]
186 **User B** releases its reference on **SC1**. **User C** becomes the
187 sole owner of the whole hierarchy through his ownership of **EC1**.
189 image::doc/contributing-images/bt-ref09.png[]
191 Finally, **User C** releases his ownership of **EC1**, triggering the
192 release of the whole hierarchy. Let's walk through the reclamation of
195 Mirroring what happened when **User A** released its last reference on
196 **EC3**, the release of **EC1** by **User C** causes its reference count
199 This transition to zero causes **EC1** to release its reference on
200 **SC1**. **SC1**'s reference count reaching zero causes it to release
201 its reference on **TC1**.
203 image::doc/contributing-images/bt-ref10.png[]
205 Since the reference count of **TC1**, a root object, has reached zero,
206 it invokes the destructor method on its children. This method is
207 recursive and causes the stream classes to call the destructor method on
210 The event classes are reached and, having no children of their own, are
213 image::doc/contributing-images/bt-ref11.png[]
215 The stream classes having destroyed their children, are then reclaimed
218 image::doc/contributing-images/bt-ref12.png[]
220 Finally, the stream classes having been reclaimed, **TC1** is reclaimed.
222 image::doc/contributing-images/bt-ref13.png[]
227 To use Valgrind on an application (for example, the CLI or a test) which
228 loads libbabeltrace, use:
230 $ G_SLICE=always-malloc G_DEBUG=gc-friendly PYTHONMALLOC=malloc \
231 BABELTRACE_NO_DLCLOSE=1 valgrind --leak-check=full \
232 --suppressions=/path/to/babeltrace/extras/valgrind/popt.supp app
234 `G_SLICE=always-malloc` and `G_DEBUG=gc-friendly` is for GLib and
235 `PYTHONMALLOC=malloc` is for the Python interpreter, if it is used by
236 the Python plugin provider (Valgrind will probably show a lot of errors
237 which originate from Python interpreter anyway).
239 `BABELTRACE_NO_DLCLOSE=1` makes libbabeltrace not close the shared
240 libraries (plugins) which it loads. This is needed to see the
241 appropriate backtrace when Valgrind shows errors.
246 Logging is a great instrument for a developer to be able to collect
247 information about a running software.
249 Babeltrace is a complex software with many layers. When a Babeltrace
250 graph fails to run, what caused the failure? It could be caused by any
251 component, any notification iterator, and any deeply nested validation
252 of a CTR IR object, for example. With the appropriate logging statements
253 manually placed in the source code, we can find the cause of a bug
256 While <<log-level,care must be taken>> when placing _INFO_ to _FATAL_
257 logging statements, you should liberally instrument your Babeltrace
258 module with _DEBUG_ and _VERBOSE_ logging statements to help future you
259 and other developers understand what's happening at run-time.
264 The Babeltrace logging API is internal: it is not exposed to the users
265 of the library, only to their developers. The only thing that a library
266 user can control is the current log level of the library itself with
267 `bt_logging_set_global_level()` and the initial library's log level with
268 the `BABELTRACE_LOGGING_GLOBAL_LEVEL` environment variable.
270 This API is based on https://github.com/wonder-mice/zf_log[zf_log], a
271 lightweight, yet featureful, MIT-licensed core logging library for C and
272 $$C++$$. The zf_log source files were modified to have the `BT_` and
273 `bt_` prefixes, and other small changes, like color support.
275 The logging functions are implemented in the logging convenience
276 library (`logging` directory).
281 The logging API headers are:
283 `<babeltrace/logging.h>`::
284 Public header which a library user can use to control and read
285 libbabeltrace's current log level.
287 `<babeltrace/logging-internal.h>`::
288 Internal, generic logging API which you can use in any Babeltrace
289 subproject. This is the translation of `zf_log.h`.
291 `<babeltrace/lib-logging-internal.h>`::
292 Specific internal header to use within the library. This header
293 defines `BT_LOG_OUTPUT_LEVEL` to a custom, library-wide hidden
294 symbol which is the library's current log level before including
295 `<babeltrace/logging-internal.h>`.
297 Do not include `<babeltrace/logging-internal.h>` or
298 `<babeltrace/lib-logging-internal.h>` in a header which contains logging
299 statements: this header could be included in source files which define a
300 different <<choose-a-tag,tag>>, for example. See
301 <<logging-instrument-header, Instrument a C header file>>.
306 The API offers the following log levels:
315 See <<log-level,how to decide which one to use>> below.
317 There are two important log level variables:
319 [[build-time-log-level]]Build-time, minimal log level::
320 The minimal log level, or build-time log level, is set at build
321 time and determines the minimal log level which can be executed.
322 This applies to all the subprojects and modules (CLI, library,
325 All the logging statements with a level below this level are **not built
326 at all**. All the logging statements with a level equal to or greater
327 than this level _can_ be executed, depending on the
328 <<run-time-log-level,run-time log level>>.
330 You can set this level at configuration time with the
331 `BABELTRACE_MINIMAL_LOG_LEVEL` environment variable, for example:
335 $ BABELTRACE_MINIMAL_LOG_LEVEL=WARN ./configure
339 The default build-time log level is `VERBOSE`. For optimal performance,
340 set it to `NONE`, which effectively disables all logging in all the
341 Babeltrace subprojects.
343 The library's public API provides `bt_logging_get_minimal_level()` to
344 get the configured minimal log level.
346 [[run-time-log-level]]Run-time, dynamic log level::
347 The dynamic log level is set at run-time and determines the current,
348 active log level. All the logging statements with a level below this
349 level are not executed, but they evaluate the condition. All the
350 logging statements with a level equal to or greater than this level
351 are executed, provided that their level is also
352 <<build-time-log-level,enabled at build time>>.
354 `zf_log` has a concept of a global run-time log level which uses the
355 `_bt_log_global_output_lvl` symbol. In practice, we never use this
356 symbol, and always make sure that `BT_LOG_OUTPUT_LEVEL` is defined to a
357 module-wise or subproject-wise hidden symbol before including
358 `<babeltrace/logging-internal.h>`. In the library,
359 `<babeltrace/lib-logging-internal.h>` does this job: just include this
360 header which defines `BT_LOG_OUTPUT_LEVEL` to the appropriate symbol
361 before it includes `<babeltrace/logging-internal.h>`. In plugins, for
362 example, there is one log level per component class, which makes log
363 filtering easier during execution.
365 In libbabeltrace, the user can set the current run-time log level with
366 the `bt_logging_set_global_level()` function, for example:
371 bt_logging_set_global_level(BT_LOGGING_LEVEL_INFO);
375 The library's initial run-time log level is defined by the
376 `BABELTRACE_LOGGING_GLOBAL_LEVEL` environment variable (`VERBOSE`, `DEBUG`,
377 `INFO`, `WARN`, `ERROR`, `FATAL`, or `NONE`), or set to _NONE_ if this
378 environment variable is undefined.
380 Other subprojects have their own way of setting their run-time log
381 level. For example, the CLI uses the `BABELTRACE_CLI_LOG_LEVEL`
382 environment variable, and the `filter.utils.muxer` component class
383 initializes its log level thanks to the
384 `BABELTRACE_PLUGIN_UTILS_MUXER_FLT_LOG_LEVEL` environment variable
385 (also _NONE_ by default).
387 Make sure that there is a documented way to initialize or modify the
388 log level of your subproject or module, and that it's set to _NONE_
392 [[logging-statements]]
393 ==== Logging statement macros
395 The Babeltrace logging statement macros work just like `printf()` and
396 contain their log level in their name:
398 `BT_LOGV("format string", ...)`::
399 Standard verbose logging statement.
401 `BT_LOGD("format string", ...)`::
402 Standard debug logging statement.
404 `BT_LOGI("format string", ...)`::
405 Standard info logging statement.
407 `BT_LOGW("format string", ...)`::
408 Standard warning logging statement.
410 `BT_LOGE("format string", ...)`::
411 Standard error logging statement.
413 `BT_LOGF("format string", ...)`::
414 Standard fatal logging statement.
416 `BT_LOGV_MEM(data_ptr, data_size, "format string", ...)`::
417 Memory verbose logging statement.
419 `BT_LOGD_MEM(data_ptr, data_size, "format string", ...)`::
420 Memory debug logging statement.
422 `BT_LOGI_MEM(data_ptr, data_size, "format string", ...)`::
423 Memory info logging statement.
425 `BT_LOGW_MEM(data_ptr, data_size, "format string", ...)`::
426 Memory warning logging statement.
428 `BT_LOGE_MEM(data_ptr, data_size, "format string", ...)`::
429 Memory error logging statement.
431 `BT_LOGF_MEM(data_ptr, data_size, "format string", ...)`::
432 Memory fatal logging statement.
434 `BT_LOGV_ERRNO("initial message", "format string", ...)`::
435 `errno` string verbose logging statement.
437 `BT_LOGD_ERRNO("initial message", "format string", ...)`::
438 `errno` string debug logging statement.
440 `BT_LOGI_ERRNO("initial message", "format string", ...)`::
441 `errno` string info logging statement.
443 `BT_LOGW_ERRNO("initial message", "format string", ...)`::
444 `errno` string warning logging statement.
446 `BT_LOGE_ERRNO("initial message", "format string", ...)`::
447 `errno` string error logging statement.
449 `BT_LOGF_ERRNO("initial message", "format string", ...)`::
450 `errno` string fatal logging statement.
452 `BT_LOGV_STR("preformatted string")`::
453 Preformatted string verbose logging statement.
455 `BT_LOGD_STR("preformatted string")`::
456 Preformatted string debug logging statement.
458 `BT_LOGI_STR("preformatted string")`::
459 Preformatted string info logging statement.
461 `BT_LOGW_STR("preformatted string")`::
462 Preformatted string warning logging statement.
464 `BT_LOGE_STR("preformatted string")`::
465 Preformatted string error logging statement.
467 `BT_LOGF_STR("preformatted string")`::
468 Preformatted string fatal logging statement.
471 ==== Conditional logging
473 `BT_LOG_IF(cond, statement)`::
474 Execute `statement` only if `cond` is true.
481 BT_LOG_IF(i < count / 2, BT_LOGD("Log this: i=%d", i));
485 To check the <<build-time-log-level,build-time log level>>:
489 #if BT_LOG_ENABLED_DEBUG
494 This tests if the _DEBUG_ level was enabled at build-time. This means
495 that the current, <<run-time-log-level,dynamic log level>> _could_ be
496 _DEBUG_, but it could also be higher. The rule of thumb is to use only
497 logging statements at the same level in a `BT_LOG_ENABLED_*` conditional
500 The available definitions for build-time conditions are:
502 * `BT_LOG_ENABLED_VERBOSE`
503 * `BT_LOG_ENABLED_DEBUG`
504 * `BT_LOG_ENABLED_INFO`
505 * `BT_LOG_ENABLED_WARN`
506 * `BT_LOG_ENABLED_ERROR`
507 * `BT_LOG_ENABLED_FATAL`
509 To check the current, <<run-time-log-level,run-time log level>>:
513 if (BT_LOG_ON_DEBUG) {
518 This tests if the _DEBUG_ log level is dynamically turned on
519 (implies that it's also enabled at build-time). This check could have a
520 noticeable impact on performance.
522 The available definitions for run-time conditions are:
524 * `BT_LOG_ON_VERBOSE`
531 Those macros check the subproject-specific or module-specific log level
532 symbol (defined by `BT_LOG_OUTPUT_LEVEL`).
534 Never, ever write code which would be executed only to compute the
535 fields of a logging statement outside a conditional logging scope,
540 int number = get_number_of_event_classes_with_property_x(...);
541 BT_LOGD("Bla bla: number=%d", number);
548 if (BT_LOG_ON_DEBUG) {
549 int number = get_number_of_event_classes_with_property_x(...);
550 BT_LOGD("Bla bla: number=%d", number);
558 BT_LOGD("Bla bla: number=%d", get_number_of_event_classes_with_property_x(...));
563 === Instrument a module
565 Follow those steps to make your module loggable:
567 . In your module's root directory, create a `logging.c` file with
574 * Copyright (c) 2017 EfficiOS Inc. <http://efficios.com/>
576 * Permission is hereby granted, free of charge, to any person obtaining a copy
577 * of this software and associated documentation files (the "Software"), to deal
578 * in the Software without restriction, including without limitation the rights
579 * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
580 * copies of the Software, and to permit persons to whom the Software is
581 * furnished to do so, subject to the following conditions:
583 * The above copyright notice and this permission notice shall be included in
584 * all copies or substantial portions of the Software.
586 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
587 * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
588 * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
589 * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
590 * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
591 * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
595 #define BT_LOG_OUTPUT_LEVEL my_module_log_level
596 #include <babeltrace/logging-internal.h>
598 BT_LOG_INIT_LOG_LEVEL(my_module_log_level, "BABELTRACE_MY_MODULE_LOG_LEVEL");
602 Replace `my_module_log_level` with the name of the symbol which holds
603 the log level for your module (should be unique amongst all the log level
604 symbols of the project). Replace `BABELTRACE_MY_MODULE_LOG_LEVEL` with
605 the name of the environment variable from which to initialize your
606 module's log level at construction time. `BT_LOG_INIT_LOG_LEVEL()`
607 defines both the hidden log level symbol and a constructor which reads
608 the environment variable and sets the log level symbol accordingly.
610 . In your module's root directory, create a `logging.h` file with
616 #ifndef BABELTRACE_MY_MODULE_LOGGING_H
617 #define BABELTRACE_MY_MODULE_LOGGING_H
620 * Copyright (c) 2017 EfficiOS Inc. <http://efficios.com/>
622 * Permission is hereby granted, free of charge, to any person obtaining a copy
623 * of this software and associated documentation files (the "Software"), to deal
624 * in the Software without restriction, including without limitation the rights
625 * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
626 * copies of the Software, and to permit persons to whom the Software is
627 * furnished to do so, subject to the following conditions:
629 * The above copyright notice and this permission notice shall be included in
630 * all copies or substantial portions of the Software.
632 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
633 * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
634 * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
635 * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
636 * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
637 * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
641 #define BT_LOG_OUTPUT_LEVEL my_module_log_level
642 #include <babeltrace/logging-internal.h>
644 BT_LOG_LEVEL_EXTERN_SYMBOL(my_module_log_level);
646 #endif /* BABELTRACE_MY_MODULE_LOGGING_H */
650 Replace `my_module_log_level` with the name of your module's
653 . Include the `logging.c` and `logging.h` in the `_SOURCES` variable
654 of your module's object in your module's root `Makefile.am`.
656 . Add the log level initializing environment variable name to the
657 `log_level_env_var_names` array in `cli/babeltrace.c`.
660 [[logging-instrument-source]]
661 ==== Instrument a C source file
663 To instrument a C source file (`.c`):
665 . At the top of the file, before the first `#include` line (if any),
666 define your file's tag name and include the local `logging.h`:
671 #define BT_LOG_TAG "MY-MODULE-MY-FILE"
676 A logging tag name is a namespace for a specific source file. Its name
677 is part of every log message generated by the statements of the file. A
678 logging tag name _must_ be only uppercase letters, digits, and the
679 hyphen (`-`) character. See <<choose-a-tag,Choose a tag>> for
680 a list of standard tags.
682 . Use the <<logging-statements,logging statement macros>> in the file's
683 functions to instrument it.
686 [[logging-instrument-header]]
687 ==== Instrument a C header file
689 To instrument a C header file (`.h`), if you have `static inline`
692 . Do not include any logging header.
693 . Use the <<logging-statements,logging statement macros>> in the file's
694 functions to instrument it, making each of them conditional to the
695 existence of the macro you're using:
701 void some_function(void)
720 The C source files which include this header file determine if logging
721 is enabled or not for them (if the source file is instrumented itself),
722 and the tag of the included header's logging statement is the same as
723 the including C source file.
729 For plugins, the format of the tag name for a given source file _must_
733 PLUGIN-__PNAME__-__CCNAME__-__CCTYPE__[-__FILE__]
739 Component class's name.
742 Component class's type (`SRC`, `FLT`, or `SINK`).
745 Additional information to specify the source file name or module.
749 * `PLUGIN-CTF-LTTNG-LIVE-SRC`
750 * `PLUGIN-CTF-LTTNG-LIVE-SRC-VIEWER`
751 * `PLUGIN-UTILS-MUXER-FLT`
755 === Choose a log level
757 Choosing the appropriate level for your logging statement is very
760 [options="header,autowidth",cols="default,default,asciidoc,default"]
762 |Log level |Description |Use cases |Impact on performance
765 |The program, library, or plugin cannot continue to work in this
766 condition: it must be terminated immediately.
768 A _FATAL_-level logging statement should always be followed by
771 * Unexpected return values from system calls.
772 * Logic error in internal code, for example an unexpected value in a
774 |Almost none: should be executed in production.
777 |An important error which is somewhat not fatal, that is, the program,
778 library, or plugin can continue to work after this, but you judge that
779 it should be reported to the user.
781 Usually, the program cannot recover from such an error, but it can at
784 * Memory allocation errors.
785 * Failed to perform an operation which should work considering the
786 implementation and the satisfied preconditions. For example, the
787 failure to create an empty object (no parameters): most probably
788 failed internally because of an allocation error.
789 * Almost any error in terminal elements: CLI and plugins.
790 |Almost none: should be executed in production.
793 |A logic error which still allows the execution to continue.
795 _WARN_-level logging statements are for any error or weird action that
796 is directly or indirectly caused by the user. For example, not having
797 enough memory is considered beyond the user's control, so we always
798 log memory errors with an _ERROR_ level (not _FATAL_ because we usually
799 don't abort in this condition).
801 Almost all the library's errors are logged as warnings because they are
804 * Not honoring a public function's preconditions (NULL parameters,
805 index out of bounds, etc.).
806 * Adding an invalid event class to a stream class which is already
809 For example, the caller tries to set a property of a frozen stream
811 |Almost none: can be executed in production.
814 |Any useful information which a non-developer user would understand.
816 * Successful loading of a plugin (with name, version, etc.).
817 * Successful connection to or disconnection from another system.
818 * An _optional_ subsystem cannot be loaded.
819 |Very little: can be executed in production if
820 _INFO_ level information is desired.
823 |Something that only Babeltrace developers would be interested into.
825 * High-level function entry/exit.
826 * Object creation, destruction, copying, and freezing.
827 * The result of some computation/validation which does not
828 occur in a tight loop.
829 |Noticeable, but not as much as the _VERBOSE_ level: not executed in
833 |Low-level debugging context information. More appropriate for tracing
836 * Reference count change.
837 * Status of each iteration of a loop.
838 * State machine's state change.
839 * Data structure lookup/modification.
840 * List of ELF sections found in a plugin.
841 * Get or set an object's property.
842 * Object comparison's intermediate results.
843 |Huge: not executed in production.
846 Make sure not to use a _WARN_ (or higher) log level when the condition
847 leading to the logging statement can occur under normal circumstances.
848 For example, a public function to get some object or property from an
849 object by name or key that fails to find the value is not a warning: the
850 user could legitimately use this function to check if the name/key
851 exists in the object. In this case, use the _VERBOSE_ level (or do not
852 log at all). If a numeric index is out of bounds, however, this
853 qualifies for a _WARN_ level: such API functions have documented
854 preconditions that the index must be in bounds (the user can always
855 check with a count or size function).
859 === Write an appropriate message
861 Follow those rules when you write a logging statement's message:
863 * Use an english sentence which starts with a capital letter. Start the
864 sentence with the appropriate verb tense depending on the context. For
868 ** Beginning of operation (present continuous): _Creating ..._,
869 _Copying ..._, _Serializing ..._, _Freezing ..._, _Destroying ..._
870 ** End of operation (simple past): _Created ..._, _Successfully created ..._,
871 _Failed to create ..._, _Set ..._ (simple past of _to set_ which is
875 For warning and error messages, you can start the message with _Cannot_
876 or _Failed to_ followed by a verb if it's appropriate.
878 * Do not include the log level in the message itself. For example,
879 do not start the message with _Error while_ or _Warning:_.
881 * Do not put newlines, tabs, or other special characters in the
882 message, unless you want to log a string with such characters. Note
883 that multiline log messages can be hard to parse, analyze, and filter,
884 however, so prefer multiple `BT_LOG*()` statements over a single
885 statement with newlines.
887 * **If there are fields that your logging statement must record**,
888 follow the message with `:` followed by a space, then with the list of
889 fields (more about this below). If there are no fields, end the
890 sentence with a period.
892 The statement's fields _must_ be a comma-separated list of
893 +__name__=__value__+ tokens. Keep +__name__+ as simple as possible
894 (lowercase if possible). If +__value__+ is a non-alphanumeric string,
895 put it between double quotes. Always use the `PRId64` and `PRIu64`
896 specifiers when logging `int64_t` and `uint64_t` values.
900 "Cannot add event class to stream class: stream-class-addr=%p, "
901 "stream-class-name=\"%s\", stream-class-id=%" PRId64 ", "
902 "event-class-addr=%p, event-class-name=\"%s\", event-class-id=%" PRId64
904 By following a standard format for the statement fields, it is easier
905 to use tools like https://www.elastic.co/products/logstash[Logstash]
906 to split fields and analyze logs.
908 Prefer the following suffixes in field names:
910 [options="header,autowidth"]
912 |Field name suffix |Description |Format specifier
914 |`-addr` |Memory address |`%p`
915 |`-fd` |File descriptor |`%d`
916 |`-fp` |File stream (`FILE *`) |`%p`
917 |`-id` |Object's ID |`%" PRId64 "` or `%" PRIu64 "`
918 |`-name` |Object's name |`\"%s\"`
924 The log is printed to the standard error stream. A log line contains the
925 time, the process and thread IDs, the <<log-level,log level>>, the
926 <<choose-a-tag,tag>>, the source's function name, file name and
927 line number, and the <<message,message>>.
929 When Babeltrace supports terminal color codes (depends on the
930 `BABELTRACE_TERM_COLOR` environment variable's value and what the
931 standard output and error streams are plugged into), _INFO_-level lines
932 are blue, _WARN_-level lines are yellow, and _ERROR_-level and
933 _FATAL_-level lines are red.
937 05-11 00:58:03.691 23402 23402 D VALUES bt_value_destroy@values.c:498 Destroying value: addr=0xb9c3eb0
939 You can easily filter the log with `grep` or `ag`. For example, to
940 keep only the _WARN_-level log messages that the `VALUES` module
943 $ export BABELTRACE_LOGGING_GLOBAL_LEVEL=VERBOSE
944 $ ./test_ctf_writer_complete 2>&1 | ag 'W VALUES'