1 // Render with Asciidoctor
3 = Babeltrace{nbsp}2 contributor's guide
4 Jérémie Galarneau, Philippe Proulx
8 :bt2: Babeltrace{nbsp}2
10 This is a partial contributor's guide for the
11 https://babeltrace.org[{bt2}] project. If you have any
12 questions that are not answered by this guide, please post them on
13 https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev[Babeltrace's
18 === Object reference counting and lifetime
20 This section covers the rationale behind the design of {bt2}'s
21 object lifetime management. This applies to the {bt2} library, as
22 well as to the CTF writer library (although the public reference
23 counting functions are not named the same way).
25 Starting from Babeltrace{nbsp}2.0, all publicly exposed objects inherit
26 a common base: `bt_object`. This base provides a number of facilities to
27 all objects, chief amongst which are lifetime management functions.
29 The lifetime of some public objects is managed by reference counting. In
30 this case, the API offers the `+bt_*_get_ref()+` and `+bt_*_put_ref()+`
31 functions which respectively increment and decrement an object's
34 As far as lifetime management in concerned, {bt2} makes a clear
35 distinction between regular objects, which have a single parent, and
36 root objects, which don't.
40 Let us consider a problematic case to illustrate the need for this
43 A user of the {bt2} library creates a trace class, which _has_ a
44 stream class (the class of a stream) and that stream class, in turn,
45 _has_ an event class (the class of an event).
47 Nothing prevents this user from releasing his reference on any one of
48 these objects in any order. However, all objects in the
49 __trace--stream class--event class__ hierarchy can be retrieved
52 For instance, the user could discard his reference on both the event
53 class and the stream class, only keeping a reference on the trace class.
54 From this trace class reference, stream classes can be enumerated,
55 providing the user with a new reference to the stream class he discarded
56 earlier. Event classes can also be enumerated from stream classes,
57 providing the user with references to the individual event classes.
59 Conversely, the user could also hold a reference to an event class and
60 retrieve its parent stream class. The trace class, in turn, can then be
61 retrieved from the stream class.
63 This example illustrates what could be interpreted as a circular
64 reference dependency existing between these objects. Of course, if the
65 objects in such a scenario were to hold references to each other (in
66 both directions), we would be in presence of a circular ownership
67 resulting in a leak of both objects as their reference counts would
70 Nonetheless, the API must offer the guarantee that holding a node to any
71 node of the graph keeps all other reachable nodes alive.
75 The scheme employed in {bt2} to break this cycle consists in the
76 "children" holding _reverse component references_ to their parents. That
77 is, in the context of the trace IR, that event classes hold a reference
78 to their parent stream class and stream classes hold a reference to
79 their parent trace class.
81 On the other hand, parents hold _claiming aggregation references_ to
82 their children. A claiming aggregation reference means that the object
83 being referenced should not be deleted as long as the reference still
84 exists. In this respect, it can be said that parents truly hold the
85 ownership of their children, since they control their lifetime.
86 Conversely, the reference counting mechanism is leveraged by children to
87 notify parents that no other child indirectly exposes the parent.
89 When a parented object's reference count reaches zero, it invokes
90 `+bt_*_put_ref()+` on its parent and does _not_ free itself. However,
91 from that point, the object depends on its parent to signal the moment
92 when it can be safely reclaimed.
94 The invocation of `+bt_*_put_ref()+` by the last children holding a
95 reference to its parent might trigger a cascade of `+bt_*_put_ref()+`
96 from child to parent. Eventually, a **root** object is reached. At that
97 point, if this orphaned object's reference count reaches zero, the
98 object invokes the destructor method defined by everyone of its children
99 as part of their base `struct bt_object`. The key point here is that the
100 cascade of destructor will necessarily originate from the root and
101 propagate in preorder to the children. These children will propagate the
102 destruction to their own children before reclaiming their own memory.
103 This ensures that a node's pointer to its parent is _always_ valid since
104 the parent has the responsibility of tearing-down their children before
105 cleaning themselves up.
107 Assuming a reference to an object is _acquired_ by calling
108 `+bt_*_get_ref()+` while its reference count is zero, the object
109 acquires, in turn, a reference on its parent using `+bt_*_get_ref()+`.
110 At that point, the child can be thought of as having converted its weak
111 reference to its parent into a regular reference. That is why this
112 reference is referred to as a _claiming_ aggregation reference.
116 This scheme imposes a number of strict rules defining the relation
119 * Objects may only have one parent.
120 * Objects, beside the root, are only retrievable from their direct
125 The initial situation is rather simple: **User{nbsp}A** is holding a
126 reference to a trace class, **TC1**. As per the rules previously
127 enounced, stream classes **SC1** and **SC2** don't hold a reference to
128 **TC1** since their own reference counts are zero. The same holds true
129 for **EC1**, **EC2** and **EC3** with respect to **SC1** and **SC2**.
131 image::doc/contributing-images/bt-ref01.png[]
133 In this second step, we can see that **User{nbsp}A** has acquired a
134 reference on **SC2** through the trace class, **TC1**.
136 The stream class's reference count transitions from zero to one,
137 triggering the acquisition of a strong reference on **TC1** from
140 Hence, at this point, the trace class's ownership is shared by
141 **User{nbsp}A** and **SC2**.
143 image::doc/contributing-images/bt-ref02.png[]
145 Next, **User{nbsp}A** acquires a reference on the **EC3** event class
146 through its parent stream class, **SC2**. Again, the transition of an
147 object's reference count from 0 to 1 triggers the acquisition of a
148 reference on its parent.
150 Note that SC2's reference count was incremented to 2. The trace class's
151 reference count remains unchanged.
153 image::doc/contributing-images/bt-ref03.png[]
155 **User{nbsp}A** decides to drop its reference on **SC2**. **SC2**'s
156 reference count returns back to 1, everything else remaining unchanged.
158 image::doc/contributing-images/bt-ref04.png[]
160 **User{nbsp}A** can then decide to drop its reference on the trace
161 class. This results in a reversal of the initial situation:
162 **User{nbsp}A** now owns an event, **EC3**, which is keeping everything
163 else alive and reachable.
165 image::doc/contributing-images/bt-ref05.png[]
167 If another object, **User{nbsp}B**, enters the picture and acquires a
168 reference on the **SC1** stream class, we see that **SC1**'s reference
169 count transitioned from 0 to 1, triggering the acquisition of a
170 reference on **TC1**.
172 image::doc/contributing-images/bt-ref06.png[]
174 **User{nbsp}B** hands off a reference to **EC1**, acquired through
175 **SC1**, to another object, **User{nbsp}C**. The acquisition of a
176 reference on **EC1**, which transitions from 0 to 1, triggers the
177 acquisition of a reference on its parent, **SC1**.
179 image::doc/contributing-images/bt-ref07.png[]
181 At some point, **User{nbsp}A** releases its reference on **EC3**. Since
182 **EC3**'s reference count transitions to zero, it releases its reference
183 on **SC2**. **SC2**'s reference count, in turn, reaches zero and it
184 releases its reference to **TC1**.
186 **TC1**'s reference count is now 1 and no further action is taken.
188 image::doc/contributing-images/bt-ref08.png[]
190 **User{nbsp}B** releases its reference on **SC1**. **User{nbsp}C**
191 becomes the sole owner of the whole hierarchy through his ownership of
194 image::doc/contributing-images/bt-ref09.png[]
196 Finally, **User{nbsp}C** releases his ownership of **EC1**, triggering
197 the release of the whole hierarchy. Let's walk through the reclamation
200 Mirroring what happened when **User{nbsp}A** released its last reference
201 on **EC3**, the release of **EC1** by **User{nbsp}C** causes its
202 reference count to fall to zero.
204 This transition to zero causes **EC1** to release its reference on
205 **SC1**. **SC1**'s reference count reaching zero causes it to release
206 its reference on **TC1**.
208 image::doc/contributing-images/bt-ref10.png[]
210 Since the reference count of **TC1**, a root object, has reached zero,
211 it invokes the destructor method on its children. This method is
212 recursive and causes the stream classes to call the destructor method on
215 The event classes are reached and, having no children of their own, are
218 image::doc/contributing-images/bt-ref11.png[]
220 The stream classes having destroyed their children, are then reclaimed
223 image::doc/contributing-images/bt-ref12.png[]
225 Finally, the stream classes having been reclaimed, **TC1** is reclaimed.
227 image::doc/contributing-images/bt-ref13.png[]
232 Logging is a great instrument for a developer to be able to collect
233 information about a running software.
235 {bt2} is a complex software with many layers. When a {bt2}
236 graph fails to run, what caused the failure? It could be caused by any
237 component, any message iterator, and any deeply nested validation of a
238 CTF IR object (within the `ctf` plugin), for example. With the
239 appropriate logging statements manually placed in the source code, we
240 can find the cause of a bug faster.
242 While <<choose-a-log-level,care must be taken>> when placing _DEBUG_ to
243 _FATAL_ logging statements, you should liberally instrument your
244 {bt2} module with _TRACE_ logging statements to help future you
245 and other developers understand what's happening at run time.
249 The {bt2} logging API is internal: it is not exposed to the users
250 of the library; only to their developers. The only thing that a library
251 user can control is the current log level of the library itself with
252 `bt_logging_set_global_level()` and the initial library's log level with
253 the `LIBBABELTRACE2_INIT_LOG_LEVEL` environment variable.
255 This API is based on https://github.com/wonder-mice/zf_log[zf_log], a
256 lightweight, yet featureful, MIT-licensed core logging library for C and
257 pass:[C++]. The zf_log source files were modified to have the `BT_` and
258 `bt_` prefixes, and other small changes, like color support and using
259 the project's `BT_DEBUG_MODE` definition instead of the standard
262 The logging functions are implemented in the logging convenience
263 library (`src/logging` directory).
268 The logging API headers are:
270 `<babeltrace2/logging.h>`::
271 Public header which a library user can use to set and get
272 libbabeltrace2's current log level.
275 Internal, generic logging API which you can use in any {bt2}
276 module. This is the translation of `zf_log.h`.
278 This header offers the <<gen-logging-statements,generic logging
282 Specific internal header to use within the library.
284 This header defines `BT_LOG_OUTPUT_LEVEL` to a custom, library-wide
285 hidden symbol which is the library's current log level before including
288 This header offers the <<lib-logging-statements,library-specific logging
291 `"logging/comp-logging.h"`::
292 Specific internal header to use within a component class.
294 This header offers the <<comp-logging-statements,component-specific
295 logging statement macros>>.
300 The internal logging API offers the following log levels, in ascending
303 [options="header,autowidth",cols="4"]
306 |Log level short name
307 |Internal API enumerator
308 |Public API enumerator
313 |`BT_LOGGING_LEVEL_TRACE`
318 |`BT_LOGGING_LEVEL_DEBUG`
323 |`BT_LOGGING_LEVEL_INFO`
328 |`BT_LOGGING_LEVEL_WARNING`
333 |`BT_LOGGING_LEVEL_ERROR`
338 |`BT_LOGGING_LEVEL_FATAL`
343 |`BT_LOGGING_LEVEL_NONE`
346 The short name is accepted by the log level environment variables and by
347 the CLI's `--log-level` options.
349 See <<choose-a-log-level,how to decide which one to use>> below.
351 There are two important log level expressions:
353 [[build-time-log-level]]Build-time, minimal log level::
354 The minimal log level, or build-time log level, is set at build time
355 and determines the minimal log level of the logging statements which
356 can be executed. This applies to all the modules (CLI, library,
357 plugins, bindings, etc.).
359 All the logging statements with a level below this level are **not built
360 at all**. All the logging statements with a level equal to or greater
361 than this level _can_ be executed, depending on the
362 <<run-time-log-level,run-time log level>>.
364 You can set this level at configuration time with the
365 `BABELTRACE_MINIMAL_LOG_LEVEL` environment variable, for example:
369 $ BABELTRACE_MINIMAL_LOG_LEVEL=INFO ./configure
373 The default build-time log level is `DEBUG`. For optimal performance,
374 set it to `INFO`, which effectively disables all fast path logging in
375 all the {bt2} modules. You can't set it to `WARNING`, `ERROR`,
376 `FATAL`, or `NONE` because the impact on performance is minuscule
377 starting from the _INFO_ log level anyway and we want any {bt2}
378 build to always be able to print _INFO_-level logs.
380 The library's public API provides `bt_logging_get_minimal_level()` to
381 get the configured minimal log level.
383 [[run-time-log-level]]Run-time, dynamic log level::
384 The dynamic log level is set at run time and determines the current,
385 _active_ log level. All the logging statements with a level below
386 this level are not executed, **but they still evaluate the
387 condition**. All the logging statements with a level equal to or
388 greater than this level are executed, provided that their level is
389 also <<build-time-log-level,enabled at build time>>.
391 `zf_log` has a concept of a global run-time log level which uses the
392 `_bt_log_global_output_lvl` symbol. In practice, we never use this
393 symbol, and always make sure that `BT_LOG_OUTPUT_LEVEL` is defined to a
394 module-wise expression before including `"logging/log.h"`.
396 In the library, `"lib/logging.h"` defines its own
397 `BT_LOG_OUTPUT_LEVEL` to the library's log level symbol before it
398 includes `"logging/log.h"` itself.
400 In libbabeltrace2, the user can set the current run-time log level with
401 the `bt_logging_set_global_level()` function, for example:
406 bt_logging_set_global_level(BT_LOGGING_LEVEL_INFO);
410 The library's initial run-time log level is defined by the
411 `LIBBABELTRACE2_INIT_LOG_LEVEL` environment variable, or set to _NONE_
412 if this environment variable is undefined.
414 Other modules have their own way of setting their run-time log level.
416 For example, the CLI uses the `BABELTRACE_CLI_LOG_LEVEL` environment
417 variable, as well as its global `--log-level` option:
420 $ babeltrace2 --log-level=I ...
423 The components use their own log level (as returned by
424 `bt_component_get_logging_level()`). With the CLI, you can set a
425 specific component's log level with its own, position-dependent
426 `--log-level` option:
429 $ babeltrace2 /path/to/trace -c sink.ctf.fs --log-level=D
432 Code which is common to the whole project, for example `src/common`
433 and `src/compat`, use function parameters to get its run-time log
439 char *bt_common_get_home_plugin_path(int log_level);
442 Typically, when a logging-enabled module calls such a function, it
443 passes its own log level expression directly (`BT_LOG_OUTPUT_LEVEL`):
447 path = bt_common_get_home_plugin_path(BT_LOG_OUTPUT_LEVEL);
450 Otherwise, just pass `BT_LOG_NONE`:
453 path = bt_common_get_home_plugin_path(BT_LOG_NONE);
456 [[gen-logging-statements]]
457 ==== Generic logging statement macros
459 The {bt2} logging statement macros work just like `printf()`
460 (except the `+BT_LOG*_STR()+` ones) and contain their <<log-levels,log
461 level>> (short name) in their name.
463 Each of the following macros evaluate the
464 <<build-time-log-level,build-time log level>> definition and
465 <<run-time-log-level,run-time log level>> expression (as defined by
466 `BT_LOG_OUTPUT_LEVEL`) to log conditionally.
468 See <<logging-instrument-c-file-gen>> and
469 <<logging-instrument-h-file-gen>> to learn how to be able to use the
472 `+BT_LOGT("format string", ...)+`::
473 Generic trace logging statement.
475 `+BT_LOGD("format string", ...)+`::
476 Generic debug logging statement.
478 `+BT_LOGI("format string", ...)+`::
479 Generic info logging statement.
481 `+BT_LOGW("format string", ...)+`::
482 Generic warning logging statement.
484 `+BT_LOGE("format string", ...)+`::
485 Generic error logging statement.
487 `+BT_LOGF("format string", ...)+`::
488 Generic fatal logging statement.
490 `+BT_LOGT_STR("preformatted string")+`::
491 Generic preformatted string trace logging statement.
493 `+BT_LOGD_STR("preformatted string")+`::
494 Generic preformatted string debug logging statement.
496 `+BT_LOGI_STR("preformatted string")+`::
497 Generic preformatted string info logging statement.
499 `+BT_LOGW_STR("preformatted string")+`::
500 Generic preformatted string warning logging statement.
502 `+BT_LOGE_STR("preformatted string")+`::
503 Generic preformatted string error logging statement.
505 `+BT_LOGF_STR("preformatted string")+`::
506 Generic preformatted string fatal logging statement.
508 `+BT_LOGT_MEM(data_ptr, data_size, "format string", ...)+`::
509 Generic memory trace logging statement.
511 `+BT_LOGD_MEM(data_ptr, data_size, "format string", ...)+`::
512 Generic memory debug logging statement.
514 `+BT_LOGI_MEM(data_ptr, data_size, "format string", ...)+`::
515 Generic memory info logging statement.
517 `+BT_LOGW_MEM(data_ptr, data_size, "format string", ...)+`::
518 Generic memory warning logging statement.
520 `+BT_LOGE_MEM(data_ptr, data_size, "format string", ...)+`::
521 Generic memory error logging statement.
523 `+BT_LOGF_MEM(data_ptr, data_size, "format string", ...)+`::
524 Generic memory fatal logging statement.
526 `+BT_LOGT_ERRNO("initial message", "format string", ...)+`::
527 Generic `errno` string trace logging statement.
529 `+BT_LOGD_ERRNO("initial message", "format string", ...)+`::
530 Generic `errno` string debug logging statement.
532 `+BT_LOGI_ERRNO("initial message", "format string", ...)+`::
533 Generic `errno` string info logging statement.
535 `+BT_LOGW_ERRNO("initial message", "format string", ...)+`::
536 Generic `errno` string warning logging statement.
538 `+BT_LOGE_ERRNO("initial message", "format string", ...)+`::
539 Generic `errno` string error logging statement.
541 `+BT_LOGF_ERRNO("initial message", "format string", ...)+`::
542 Generic `errno` string fatal logging statement.
544 [[lib-logging-statements]]
545 ==== Library-specific logging statement macros
547 The {bt2} library contains an internal logging API based on the
548 generic logging framework. You can use it to log known {bt2}
549 objects without having to manually log each member.
551 See <<logging-instrument-c-file-lib>>
552 and <<logging-instrument-h-file-lib>> to
553 learn how to be able to use the following macros.
555 The library logging statement macros are named `+BT_LIB_LOG*()+` instead
558 `+BT_LIB_LOGT("format string", ...)+`::
559 Library trace logging statement.
561 `+BT_LIB_LOGD("format string", ...)+`::
562 Library debug logging statement.
564 `+BT_LIB_LOGI("format string", ...)+`::
565 Library info logging statement.
567 `+BT_LIB_LOGW("format string", ...)+`::
568 Library warning logging statement.
570 `+BT_LIB_LOGE("format string", ...)+`::
571 Library error logging statement.
573 `+BT_LIB_LOGF("format string", ...)+`::
574 Library fatal logging statement.
576 `+BT_LIB_LOGW_APPEND_CAUSE("format string", ...)+`::
577 Library warning logging statement, and unconditional error cause
580 `+BT_LIB_LOGE_APPEND_CAUSE("format string", ...)+`::
581 Library error logging statement, and unconditional error cause
584 `+BT_LIB_LOGF_APPEND_CAUSE("format string", ...)+`::
585 Library fatal logging statement, and unconditional error cause
588 The macros above accept the typical `printf()` conversion specifiers
589 with the following limitations:
591 * The `+*+` width specifier is not accepted.
592 * The `+*+` precision specifier is not accepted.
593 * The `j` and `t` length modifiers are not accepted.
594 * The `n` format specifier is not accepted.
595 * The format specifiers defined in `<inttypes.h>` are not accepted,
596 except for `PRId64`, `PRIu64`, `PRIx64`, `PRIX64`, `PRIo64`, and
599 The {bt2} library custom conversion specifier is accepted. Its
600 syntax is either `%!u` to format a UUID (`bt_uuid` type), or:
602 . Introductory `%!` sequence.
604 . **Optional**: `[` followed by a custom prefix for the printed fields
605 of this specifier, followed by `]`. The standard form is to end this
606 prefix with `-` so that, for example, with the prefix `tc-`, the
607 complete field name becomes `tc-addr`.
609 . **Optional**: `pass:[+]` to print extended object members. This
610 depends on the provided format specifier.
612 . Format specifier (see below).
614 The available format specifiers are:
616 [options="header,autowidth",cols="3"]
623 |Trace IR field class
624 |`+const struct bt_field_class *+`
628 |`+const struct bt_field *+`
632 |`+const struct bt_field_path *+`
635 |Trace IR event class
636 |`+const struct bt_event_class *+`
640 |`+const struct bt_event *+`
643 |Trace IR stream class.
644 |`+const struct bt_stream_class *+`
648 |`+const struct bt_stream *+`
652 |`+const struct bt_packet *+`
655 |Trace IR trace class
656 |`+const struct bt_trace_class *+`
660 |`+const struct bt_trace *+`
663 |Trace IR clock class
664 |`+const struct bt_clock_class *+`
667 |Trace IR clock snapshot
668 |`+const struct bt_clock_snapshot *+`
672 |`+const struct bt_value *+`
676 |`const struct bt_integer_range_set *`
680 |`+const struct bt_message *+`
683 |Message iterator class
684 |`struct bt_message_iterator_class *`
688 |`struct bt_message_iterator *`
692 |`struct bt_component_class *`
696 |`+const struct bt_component *+`
700 |`+const struct bt_port *+`
704 |`+const struct bt_connection *+`
708 |`+const struct bt_graph *+`
712 |`+struct bt_interrupter *+`
716 |`+const struct bt_plugin *+`
720 |`+const struct bt_error_cause *+`
724 |`+const struct bt_object_pool *+`
728 |`+const struct bt_object *+`
731 Conversion specifier examples:
738 The ``, `` string (comma and space) is printed between individual
739 fields, but **not after the last one**. Therefore, you must put this
740 separator in the format string between two conversion specifiers, for
745 BT_LIB_LOGW("Message: count=%u, %!E, %!+K", count, event_class, clock_class);
748 Example with a custom prefix:
752 BT_LIB_LOGI("Some message: %![ec-a-]e, %![ec-b-]+e", ec_a, ec_b);
755 It is safe to pass `NULL` as any {bt2} object parameter: the macros
756 only print its null address.
758 WARNING: Build-time `printf()` format checks are disabled for the
759 `+BT_LIB_LOG*()+` macros because there are custom conversion specifiers,
760 so make sure to test your logging statements.
762 [[comp-logging-statements]]
763 ==== Component-specific logging statement macros
765 There are available logging macros for components. They prepend a prefix
766 including the component's name to the logging message.
768 See <<logging-instrument-c-file-compcls>> and
769 <<logging-instrument-h-file-compcls>> to learn how to be able to use the
772 The component logging statement macros are named `+BT_COMP_LOG*()+`
773 instead of `+BT_LOG*()+`:
775 `+BT_COMP_LOGT("format string", ...)+`::
776 Component trace logging statement.
778 `+BT_COMP_LOGD("format string", ...)+`::
779 Component debug logging statement.
781 `+BT_COMP_LOGI("format string", ...)+`::
782 Component info logging statement.
784 `+BT_COMP_LOGW("format string", ...)+`::
785 Component warning logging statement.
787 `+BT_COMP_LOGE("format string", ...)+`::
788 Component error logging statement.
790 `+BT_COMP_LOGF("format string", ...)+`::
791 Component fatal logging statement.
793 `+BT_COMP_LOGT_STR("preformatted string")+`::
794 Component preformatted string trace logging statement.
796 `+BT_COMP_LOGD_STR("preformatted string")+`::
797 Component preformatted string debug logging statement.
799 `+BT_COMP_LOGI_STR("preformatted string")+`::
800 Component preformatted string info logging statement.
802 `+BT_COMP_LOGW_STR("preformatted string")+`::
803 Component preformatted string warning logging statement.
805 `+BT_COMP_LOGE_STR("preformatted string")+`::
806 Component preformatted string error logging statement.
808 `+BT_COMP_LOGF_STR("preformatted string")+`::
809 Component preformatted string fatal logging statement.
811 `+BT_COMP_LOGT_ERRNO("initial message", "format string", ...)+`::
812 Component `errno` string trace logging statement.
814 `+BT_COMP_LOGD_ERRNO("initial message", "format string", ...)+`::
815 Component `errno` string debug logging statement.
817 `+BT_COMP_LOGI_ERRNO("initial message", "format string", ...)+`::
818 Component `errno` string info logging statement.
820 `+BT_COMP_LOGW_ERRNO("initial message", "format string", ...)+`::
821 Component `errno` string warning logging statement.
823 `+BT_COMP_LOGE_ERRNO("initial message", "format string", ...)+`::
824 Component `errno` string error logging statement.
826 `+BT_COMP_LOGF_ERRNO("initial message", "format string", ...)+`::
827 Component `errno` string fatal logging statement.
829 `+BT_COMP_LOGT_MEM(data_ptr, data_size, "format string", ...)+`::
830 Component memory trace logging statement.
832 `+BT_COMP_LOGD_MEM(data_ptr, data_size, "format string", ...)+`::
833 Component memory debug logging statement.
835 `+BT_COMP_LOGI_MEM(data_ptr, data_size, "format string", ...)+`::
836 Component memory info logging statement.
838 `+BT_COMP_LOGW_MEM(data_ptr, data_size, "format string", ...)+`::
839 Component memory warning logging statement.
841 `+BT_COMP_LOGE_MEM(data_ptr, data_size, "format string", ...)+`::
842 Component memory error logging statement.
844 `+BT_COMP_LOGF_MEM(data_ptr, data_size, "format string", ...)+`::
845 Component memory fatal logging statement.
847 ==== Conditional logging
849 `+BT_LOG_IF(cond, statement)+`::
850 Execute `statement` only if `cond` is true.
857 BT_LOG_IF(i < count / 2, BT_LOGD("Log this: i=%d", i));
861 To check the <<build-time-log-level,build-time log level>>:
865 #if BT_LOG_ENABLED_DEBUG
870 This tests if the _DEBUG_ level was enabled at build time. This means
871 that the current, <<run-time-log-level,run-time log level>> _could_ be
872 _DEBUG_, but it could also be higher. The rule of thumb is to use only
873 logging statements at the same level in a `BT_LOG_ENABLED_*` conditional
876 The available definitions for build-time conditions are:
878 * `BT_LOG_ENABLED_TRACE`
879 * `BT_LOG_ENABLED_DEBUG`
880 * `BT_LOG_ENABLED_INFO`
881 * `BT_LOG_ENABLED_WARNING`
882 * `BT_LOG_ENABLED_ERROR`
883 * `BT_LOG_ENABLED_FATAL`
885 To check the current, <<run-time-log-level,run-time log level>>:
889 if (BT_LOG_ON_DEBUG) {
894 This tests if the _DEBUG_ log level is dynamically turned on
895 (implies that it's also enabled at build time). This check could have a
896 noticeable impact on performance.
898 The available definitions for run-time conditions are:
903 * `BT_LOG_ON_WARNING`
907 Those macros check the module-specific log level symbol (defined by
908 `BT_LOG_OUTPUT_LEVEL`).
910 Never, ever write code which would be executed only to compute the
911 fields of a logging statement outside a conditional logging scope,
916 int number = get_number_of_event_classes_with_property_x(...);
917 BT_LOGD("Bla bla: number=%d", number);
924 if (BT_LOG_ON_DEBUG) {
925 int number = get_number_of_event_classes_with_property_x(...);
926 BT_LOGD("Bla bla: number=%d", number);
934 BT_LOGD("Bla bla: number=%d", get_number_of_event_classes_with_property_x(...));
939 [[logging-instrument-c-file-gen]]
940 ==== Instrument a C source file (generic)
942 To instrument a C source file (`.c`):
944 . At the top of the file, before the first `#include` line (if any),
945 define your file's <<choose-a-logging-tag,logging tag>> name:
950 #define BT_LOG_TAG "SUBSYS/MY-MODULE/MY-FILE"
954 . Below the line above, define the source file's log level expression,
955 `BT_LOG_OUTPUT_LEVEL`. This expression is evaluated for each
956 <<gen-logging-statements,logging statement>> to know the current
957 <<run-time-log-level,run-time log level>>.
963 /* Global log level variable */
964 #define BT_LOG_OUTPUT_LEVEL module_global_log_level
969 /* Local log level variable; must exist where you use BT_LOG*() */
970 #define BT_LOG_OUTPUT_LEVEL log_level
975 /* Object's log level; `obj` must exist where you use BT_LOG*() */
976 #define BT_LOG_OUTPUT_LEVEL (obj->log_level)
979 . Include `"logging/log.h"`:
983 #include "logging/log.h"
986 . In the file, instrument your code with the
987 <<gen-logging-statements,generic logging statement macros>>.
989 [[logging-instrument-h-file-gen]]
990 ==== Instrument a C header file (generic)
992 To instrument a C header file (`.h`), if you have `static inline`
995 . Do not include `"logging/log.h"`!
999 .. In the file, instrument your code with the
1000 <<gen-logging-statements,generic logging statement macros>>, making
1001 each of them conditional to the existence of the macro you're using:
1006 int some_function(int x)
1024 The C source files which include this header file determine if logging
1025 is enabled or not for them, and if so, what is their
1026 <<choose-a-logging-tag,logging tag>> and <<run-time-log-level,run-time
1027 log level>> expression.
1029 .. Require that logging be enabled:
1033 /* Protection: this file uses BT_LOG*() macros directly */
1034 #ifndef BT_LOG_SUPPORTED
1035 # error Please include "logging/log.h" before including this file.
1039 Then, in the file, instrument your code with the
1040 <<gen-logging-statements,generic logging statement macros>>.
1042 [[logging-instrument-c-file-lib]]
1043 ==== Instrument a library C source file
1045 To instrument a library C source file (`.c`):
1047 . At the top of the file, before the first `#include` line (if any),
1048 define your file's <<choose-a-logging-tag,logging tag>> name (this
1049 tag must start with `LIB/`):
1054 #define BT_LOG_TAG "LIB/THE-FILE"
1058 . Include `"lib/logging.h"`:
1062 #include "lib/logging.h"
1065 . In the file, instrument your code with the
1066 <<lib-logging-statements,library logging statement macros>> or with
1067 the <<gen-logging-statements,generic logging statement macros>>.
1069 [[logging-instrument-h-file-lib]]
1070 ==== Instrument a library C header file
1072 To instrument a library C header file (`.h`), if you have `static
1073 inline` functions in it:
1075 . Do not include `"lib/logging.h"`!
1077 . Require that library logging be enabled:
1081 /* Protection: this file uses BT_LIB_LOG*() macros directly */
1082 #ifndef BT_LIB_LOG_SUPPORTED
1083 # error Please include "lib/logging.h" before including this file.
1087 . In the file, instrument your code with the
1088 <<lib-logging-statements,library logging statement macros>> or with
1089 the <<gen-logging-statements,generic logging statement macros>>.
1091 [[logging-instrument-c-file-compcls]]
1092 ==== Instrument a component class C source file
1094 To instrument a component class C source file (`.c`):
1096 . At the top of the file, before the first `#include` line (if any),
1097 define your file's <<choose-a-logging-tag,logging tag>> name (this tag
1098 must start with `PLUGIN/` followed by the component class identifier):
1103 #define BT_LOG_TAG "PLUGIN/SRC.MY-PLUGIN.MY-SRC"
1107 . Below the line above, define the source file's log level expression,
1108 `BT_LOG_OUTPUT_LEVEL`. This expression is evaluated for each
1109 <<comp-logging-statements,logging statement>> to know the current
1110 <<run-time-log-level,run-time log level>>.
1112 For a component class file, it is usually a member of a local component
1113 private structure variable:
1117 #define BT_LOG_OUTPUT_LEVEL (my_comp->log_level)
1120 . Below the line above, define `BT_COMP_LOG_SELF_COMP` to an expression
1121 which, evaluated in the context of the
1122 <<comp-logging-statements,logging statements>>, evaluates to the self
1123 component address (`+bt_self_component *+`) of the component.
1125 This is usually a member of a local component private structure
1130 #define BT_COMP_LOG_SELF_COMP (my_comp->self_comp)
1133 . Include `"logging/comp-logging.h"`:
1137 #include "logging/comp-logging.h"
1140 . In the component initialization method, make sure to set the
1141 component private structure's log level member to the initial
1142 component's log level:
1147 bt_logging_level log_level;
1152 bt_self_component_status my_comp_init(
1153 bt_self_component_source *self_comp_src,
1154 bt_value *params, void *init_method_data)
1156 struct my_comp *my_comp = g_new0(struct my_comp, 1);
1157 bt_self_component *self_comp =
1158 bt_self_component_source_as_self_component(self_comp_src);
1159 const bt_component *comp = bt_self_component_as_component(self_comp);
1162 my_comp->log_level = bt_component_get_logging_level(comp);
1168 . In the file, instrument your code with the
1169 <<comp-logging-statements,component logging statement macros>>.
1171 [[logging-instrument-h-file-compcls]]
1172 ==== Instrument a component class C header file
1174 To instrument a component class C header file (`.h`), if you have
1175 `static inline` functions in it:
1177 . Do not include `"logging/comp-logging.h"`!
1179 . Require that component logging be enabled:
1183 /* Protection: this file uses BT_COMP_LOG*() macros directly */
1184 #ifndef BT_COMP_LOG_SUPPORTED
1185 # error Please include "logging/comp-logging.h" before including this file.
1189 . In the file, instrument your code with the
1190 <<comp-logging-statements,component logging statement macros>>.
1192 [[choose-a-logging-tag]]
1193 ==== Choose a logging tag
1195 Each logging-enabled C source file must define `BT_LOG_TAG` to a logging
1196 tag. A logging tag is a namespace to identify the logging messages of
1197 this specific source file.
1199 In general, a logging tag name _must_ be only uppercase letters, digits,
1200 and the `-`, `.`, and `/` characters.
1202 Use `/` to show the subsystem to source file hierarchy.
1204 For the {bt2} library, start with `LIB/`.
1206 For the CTF writer library, start with `CTF-WRITER/`.
1208 For component classes, use:
1211 `PLUGIN/__CCTYPE__.__PNAME__.__CCNAME__[/__FILE__]`
1216 Component class's type (`SRC`, `FLT`, or `SINK`).
1222 Component class's name.
1225 Additional information to specify the source file name or module.
1227 For plugins (files common to many component classes), use:
1230 `PLUGIN/__PNAME__[/__FILE__]`
1238 Additional information to specify the source file name or module.
1240 [[choose-a-log-level]]
1241 ==== Choose a log level
1243 Choosing the appropriate level for your logging statement is very
1246 [options="header,autowidth",cols="1,2,3a,4"]
1248 |Log level |Description |Use cases |Expected impact on performance
1252 The program, library, or plugin cannot continue to work in this
1253 condition: it must be terminated immediately.
1255 A _FATAL_-level logging statement should always be followed by
1258 * Unexpected return values from system calls.
1259 * Logic error in internal code, for example an unexpected value in a
1261 * Failed assertion (within `BT_ASSERT()`).
1262 * Unsatisfied library precondition (within `BT_ASSERT_PRE()` or
1263 `BT_ASSERT_PRE_DEV()`).
1264 * Unsatisfied library postcondition (within `BT_ASSERT_POST()` or
1265 `BT_ASSERT_POST_DEV()`).
1266 |Almost none: always enabled.
1270 An important error which is somewhat not fatal, that is, the program,
1271 library, or plugin can continue to work after this, but you judge that
1272 it should be reported to the user.
1274 Usually, the program cannot recover from such an error, but it can at
1277 * Memory allocation errors.
1278 * Wrong component initialization parameters.
1279 * Corrupted, unrecoverable trace data.
1280 * Failed to perform an operation which should work considering the
1281 implementation and the satisfied preconditions. For example, the
1282 failure to create an empty object (no parameters): most probably
1283 failed internally because of an allocation error.
1284 * Almost any error in terminal elements: CLI and plugins.
1285 |Almost none: always enabled.
1289 An error which still allows the execution to continue, but you judge
1290 that it should be reported to the user.
1292 _WARNING_-level logging statements are for any error or weird action
1293 that is directly or indirectly caused by the user, often through some
1294 bad input data. For example, not having enough memory is considered
1295 beyond the user's control, so we always log memory errors with an
1296 _ERROR_ level (not _FATAL_ because we usually don't abort in this
1299 * Missing data within something that is expected to have it, but there's
1301 * Invalid file, but recoverable/fixable.
1302 |Almost none: always enabled.
1306 Any useful information which a non-developer user would possibly
1309 Anything logged with this level must _not_ happen repetitively on the
1310 fast path, that is, nothing related to each message, for example. This
1311 level is used for sporadic and one-shot events.
1313 * CLI or component configuration report.
1314 * Successful plugin, component, or message iterator initialization.
1315 * In the library: anything related to plugins, graphs, component
1316 classes, components, message iterators, connections, and ports which
1317 is not on the fast path.
1318 * Successful connection to or disconnection from another system.
1319 * An _optional_ subsystem cannot be loaded.
1320 * An _optional_ field/datum cannot be found.
1322 Very little: always enabled.
1326 Something that only {bt2} developers would be interested into,
1327 which can occur on the fast path, but not more often than once per
1330 The _DEBUG_ level is the default <<build-time-log-level,build-time log
1331 level>> as, since it's not _too_ verbose, the performance is similar to
1334 * Object construction and destruction.
1335 * Object recycling (except fields).
1336 * Object copying (except fields and values).
1337 * Object freezing (whatever the type, as freezing only occurs in
1339 * Object interruption.
1340 * Calling user methods and logging the result.
1341 * Setting object properties (except fields and values).
1343 Noticeable, but not as much as the _TRACE_ level: could be executed
1344 in production if you're going to need a thorough log for support
1345 tickets without having to rebuild the project.
1349 Low-level debugging context information (anything that does not fit the
1350 other log levels). More appropriate for tracing in general.
1352 * Reference count change.
1353 * Fast path, low level state machine's state change.
1354 * Get or set an object's property.
1355 * Object comparison's intermediate results.
1356 |Huge: not executed in production.
1361 Make sure not to use a _WARNING_ (or higher) log level when the
1362 condition leading to the logging statement can occur under normal
1365 For example, a public function to get some object or
1366 property from an object by name or key that fails to find the value is
1367 not a warning scenario: the user could legitimately use this function to
1368 check if the name/key exists in the object. In this case, use the
1369 _TRACE_ level (or do not log at all).
1373 ==== Write an appropriate message
1375 Follow those rules when you write a logging statement's message:
1377 * Use an English sentence which starts with a capital letter.
1379 * Start the sentence with the appropriate verb tense depending on the
1380 context. For example:
1383 ** Beginning of operation (present continuous): _Creating ..._,
1384 _Copying ..._, _Serializing ..._, _Freezing ..._, _Destroying ..._
1385 ** End of operation (simple past): _Created ..._, _Successfully created ..._,
1386 _Failed to create ..._, _Set ..._ (simple past of _to set_ which is
1390 For warning and error messages, you can start the message with _Cannot_
1391 or _Failed to_ followed by a verb if it's appropriate.
1393 * Do not include the log level in the message itself. For example,
1394 do not start the message with _Error while_ or _Warning:_.
1396 * Do not put newlines, tabs, or other special characters in the message,
1397 unless you want to log a string with such characters. Note that
1398 multiline logging messages can be hard to parse, analyze, and filter,
1399 however, so prefer multiple logging statements over a single statement
1402 * **If there are fields that your logging statement must record**,
1403 follow the message with `:` followed by a space, then with the list of
1404 fields (more about this below). If there are no fields, end the
1405 sentence with a period.
1407 The statement's fields _must_ be a comma-separated list of
1408 `__name__=__value__` tokens. Keep `__name__` as simple as possible; use
1409 kebab case if possible. If `__value__` is a non-alphanumeric string, put
1410 it between double quotes (`"%s"` specifier). Always use the `PRId64` and
1411 `PRIu64` specifiers to log an `int64_t` or an `uint64_t` value. Use `%d`
1412 to log a boolean value.
1416 "Cannot read stream data for indexing: path=\"%s\", name=\"%s\", "
1417 "stream-id=%" PRIu64 ", stream-fd=%d, "
1418 "index=%" PRIu64 ", status=%s, is-mapped=%d"
1420 By following a standard format for the statement fields, it is easier to
1421 use tools like https://www.elastic.co/products/logstash[Logstash] or
1422 even https://www.splunk.com/[Splunk] to split fields and analyze logs.
1424 Prefer the following suffixes in field names:
1426 [options="header,autowidth"]
1428 |Field name suffix |Description |Format specifier
1430 |`-addr` |Memory address |`%p`
1431 |`-fd` |File descriptor |`%d`
1432 |`-fp` |File stream (`+FILE *+`) |`%p`
1433 |`-id` |Object's ID |`%" PRIu64 "`
1434 |`-index` |Index |`%" PRIu64 "`
1435 |`-name` |Object's name |`\"%s\"`
1440 The log is printed to the standard error stream. A log line contains the
1441 time, the process and thread IDs, the <<log-levels,log level>>, the
1442 <<choose-a-logging-tag,logging tag>>, the source's function name, file
1443 name and line number, and the <<message,message>>.
1445 When {bt2} supports terminal color codes (depends on the
1446 `BABELTRACE_TERM_COLOR` environment variable's value and what the
1447 standard output and error streams are plugged into), _INFO_-level lines
1448 are blue, _WARNING_-level lines are yellow, and _ERROR_-level and
1449 _FATAL_-level lines are red.
1454 05-11 00:58:03.691 23402 23402 D VALUES bt_value_destroy@values.c:498 Destroying value: addr=0xb9c3eb0
1457 You can easily filter the log with `grep` or `ag`. For example, to keep
1458 only the _DEBUG_-level logging messages that the `FIELD-CLASS` module
1462 $ babeltrace2 --log-level=D /path/to/trace |& ag 'D FIELD-CLASS'
1467 To use Valgrind on an application (for example, the CLI or a test) which
1468 loads libbabeltrace2, use:
1471 $ G_SLICE=always-malloc G_DEBUG=gc-friendly PYTHONMALLOC=malloc \
1472 LIBBABELTRACE2_NO_DLCLOSE=1 valgrind --leak-check=full app
1475 `G_SLICE=always-malloc` and `G_DEBUG=gc-friendly` is for GLib and
1476 `PYTHONMALLOC=malloc` is for the Python interpreter, if it is used by
1477 the Python plugin provider (Valgrind will probably show a lot of errors
1478 which originate from the Python interpreter anyway).
1480 `LIBBABELTRACE2_NO_DLCLOSE=1` makes libbabeltrace2 not close the shared
1481 libraries (plugins) which it loads. You need this to see the appropriate
1482 backtrace when Valgrind shows errors.
1489 `tests/utils/utils.sh` sets the environment variables for any {bt2}
1492 `utils.sh` only needs to know the path to the `tests` directory within
1493 the source and the build directories. By default, `utils.sh` assumes the
1494 build is in tree, that is, you ran `./configure` from the source's root
1495 directory, and sets the `BT_TESTS_SRCDIR` and `BT_TESTS_BUILDDIR`
1496 environment variables accordingly. You can override those variables, for
1497 example if you build out of tree.
1499 All test scripts eventually do something like this to source `utils.sh`,
1500 according to where they are located relative to the `tests` directory:
1504 if [ "x${BT_TESTS_SRCDIR:-}" != "x" ]; then
1505 UTILSSH="$BT_TESTS_SRCDIR/utils/utils.sh"
1507 UTILSSH="$(dirname "$0")/../utils/utils.sh"
1513 You can use the `tests/utils/run_python_bt2` script to run any command
1514 within an environment making the build's `bt2` Python package available.
1516 `run_python_bt2` uses <<test-env,`utils.sh`>> which needs to know the
1517 build directory, so make sure you set the `BT_TESTS_BUILDDIR`
1518 environment variable correctly _if you build out of tree_, for example:
1521 $ export BT_TESTS_BUILDDIR=/path/to/build/babeltrace/tests
1524 You can run any command which needs the `bt2` Python package through
1525 `run_python_bt2`, for example:
1528 $ ./tests/utils/run_python_bt2 ipython3
1533 All test scripts output the test results following the
1534 https://testanything.org/[Test Anything Protocol] (TAP) format.
1536 The TAP format has two mechanisms to print additional information about
1539 * Print a line starting with `#` to the standard output.
1541 This is usually done with the `diag()` C function or the `diag` shell
1544 * Print to the standard error.
1548 The `bt2` Python package tests are located in
1549 `tests/bindings/python/bt2`.
1551 ==== Python test runner
1553 `tests/utils/python/testrunner.py` is {bt2}'s Python test runner
1554 which loads Python files containing unit tests, finds all the test
1555 cases, and runs the tests, producing a TAP report.
1557 You can see the test runner command's help with:
1560 $ python3 ./tests/utils/python/testrunner.py --help
1563 By default, the test runner reports failing tests (TAP's `not{nbsp}ok`
1564 line), but continues to run other tests. You can use the `--failfast`
1565 option to make the test runner fail as soon as a test fails.
1569 To run all the `bt2` Python package tests:
1574 $ ./tests/utils/run_python_bt2 ./tests/bindings/python/bt2/test_python_bt2
1580 $ ./tests/utils/run_python_bt2 python3 ./tests/utils/python/testrunner.py \
1581 ./tests/bindings/python/bt2/ -p '*.py'
1584 To run **all the tests** in a test module (for example,
1590 $ ./tests/utils/run_python_bt2 python3 ./tests/utils/python/testrunner.py \
1591 ./tests/bindings/python/bt2 -t test_value
1594 To run a **specific test case** (for example, `RealValueTestCase` within
1600 $ ./tests/utils/run_python_bt2 python3 ./tests/utils/python/testrunner.py \
1601 ./tests/bindings/python/bt2/ -t test_value.RealValueTestCase
1604 To run a **specific test** (for example,
1605 `RealValueTestCase.test_assign_pos_int` within `test_value.py`):
1610 $ ./tests/utils/run_python_bt2 python3 ./tests/utils/python/testrunner.py \
1611 ./tests/bindings/python/bt2/ -t test_value.RealValueTestCase.test_assign_pos_int