bt_port_output_notification_iterator_create(): remove colander comp. name
[babeltrace.git] / CONTRIBUTING.adoc
CommitLineData
f9ded0e0
PP
1= Babeltrace's contributor's guide
2Jérémie Galarneau, Philippe Proulx
3v0.1, 6 September 2017
beb0fb75
PP
4:toc:
5:toclevels: 5
6
beb0fb75 7
f9ded0e0
PP
8This is a partial contributor's guide for the
9http://diamon.org/babeltrace[Babeltrace] project. If you have any
10questions that are not answered in this guide, please post them
11on https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev[Babeltrace's mailing list].
beb0fb75 12
f9ded0e0
PP
13
14== Object reference counting and lifetime
15
16This section covers the rationale behind the design of Babeltrace's
17object lifetime management.
18
19Starting from Babeltrace 2.x, all publicly exposed objects inherit a
20common base: `bt_object`. This base provides a number of facilities to
21all objects, chief amongst which are lifetime management functions.
22
23The reference count of all public objects is controlled by invoking the
24`bt_get()` and `bt_put()` functions which respectively increment and
25decrement an object's reference count.
26
27As far as lifetime management in concerned, Babeltrace makes a clear
28distinction between regular objects, which have a single parent, and
29root objects, which don't.
30
31
32=== The problem
33
34Let us consider a problematic case to illustrate the need for this
35distinction.
36
37A user of the CTF Writer library declares a trace, which *has* a
38stream class (the declaration of a stream) and that stream class, in
39turn, *has* an event class (the declaration of an event).
40
41Nothing prevents this user from releasing his reference on any one of
42these objects in any order. However, all objects in the
43__trace--stream class--event class__ hierarchy can be retrieved
44from any other.
45
46For instance, the user could discard his reference on both the event
47class and the stream class, only keeping a reference on the trace. From
48this trace reference, stream classes can be enumerated, providing the
49user with a new reference to the stream class he discarded earlier.
50event classes can also be enumerated from stream classes, providing the
51user with references to the individual event classes.
52
53Conversely, the user could also hold a reference to an event class and
54retrieve its parent stream class. The trace, in turn, can then be
55retrieved from the stream class.
56
57This example illustrates what could be interpreted as a circular
58reference dependency existing between these objects. Of course, if the
59objects in such a scenario were to hold references to each other (in
60both directions), we would be in presence of a circular ownership
61resulting in a leak of both objects as their reference counts would
62never reach zero.
63
64Nonetheless, the API must offer the guarantee that holding a node to any
65node of the graph keeps all other reachable nodes alive.
66
67
68=== The solution
69
70The scheme employed in Babeltrace to break this cycle consists in the
71"children" holding *reverse component references* to their parents. That
56e18c4c
PP
72is, in the context of the trace IR, that event classes hold a reference
73to their parent stream class and stream classes hold a reference to
74their parent trace.
f9ded0e0
PP
75
76On the other hand, parents hold *claiming aggregation references* to
77their children. A claiming aggregation reference means that the object
78being referenced should not be deleted as long as the reference still
79exists. In this respect, it can be said that parents truly hold the
80ownership of their children, since they control their lifetime.
81Conversely, the reference counting mechanism is leveraged by children to
82notify parents that no other child indirectly exposes the parent.
83
84When a parented object's reference count reaches zero, it invokes
85`bt_put()` on its parent and does **not** free itself. However, from
86that point, the object depends on its parent to signal the moment when
87it can be safely reclaimed.
88
89The invocation of `bt_put()` by the last children holding a reference to
90its parent might trigger a cascade of `bt_put()` from child to parent.
91Eventually, a **root** object is reached. At that point, if this
92orphaned object's reference count reaches zero, the object invokes the
93destructor method defined by everyone of its children as part of their
94base `struct bt_object`. The key point here is that the cascade of
95destructor will necessarily originate from the root and propagate in
96preorder to the children. These children will propagate the destruction
97to their own children before reclaiming their own memory. This ensures
98that a node's pointer to its parent is *always* valid since the parent
99has the responsibility of tearing-down their children before cleaning
100themselves up.
101
102Assuming a reference to an object is *acquired* by calling `bt_get()`
103while its reference count is zero, the object acquires, in turn, a
104reference on its parent using `bt_get()`. At that point, the child can
105be thought of as having converted its weak reference to its parent into
106a regular reference. That is why this reference is referred to as a
107*claiming* aggregation reference.
108
109
110=== Caveats
111
112This scheme imposes a number of strict rules defining the relation
113between objects:
114
115* Objects may only have one parent.
116* Objects, beside the root, are only retrievable from their direct
117 parent or children.
118
119
120=== Example
121
122The initial situation is rather simple: **User A** is holding a
123reference to a trace, **TC1**. As per the rules previously enounced,
124stream classes **SC1** and **SC2** don't hold a reference to **TC1**
125since their own reference counts are zero. The same holds true for
126**EC1**, **EC2** and **EC3** with respect to **SC1** and **SC2**.
127
128image::doc/contributing-images/bt-ref01.png[]
129
130In this second step, we can see that **User A** has acquired a reference
131on **SC2** through the trace, **TC1**.
132
133The stream class's reference count transitions from zero to one,
134triggering the acquisition of a strong reference on **TC1** from
135**SC2**.
136
137Hence, at this point, the trace's ownership is shared by **User A** and
138**SC2**.
139
140image::doc/contributing-images/bt-ref02.png[]
141
142Next, **User A** acquires a reference on the **EC3** event class through
143its parent stream class, **SC2**. Again, the transition of an object's
144reference count from 0 to 1 triggers the acquisition of a reference on
145its parent.
146
147Note that SC2's reference count was incremented to 2. The trace's
148reference count remains unchanged.
149
150image::doc/contributing-images/bt-ref03.png[]
151
152**User A** decides to drop its reference on **SC2**. **SC2**'s reference
153count returns back to 1, everything else remaining unchanged.
154
155image::doc/contributing-images/bt-ref04.png[]
156
157**User A** can then decide to drop its reference on the trace. This
158results in a reversal of the initial situation: **User A** now owns an
159event, **EC3**, which is keeping everything else alive and reachable.
160
161image::doc/contributing-images/bt-ref05.png[]
162
163If another object, **User B**, enters the picture and acquires a
164reference on the **SC1** stream class, we see that **SC1**'s reference
165count transitioned from 0 to 1, triggering the acquisition of a
166reference on **TC1**.
167
168image::doc/contributing-images/bt-ref06.png[]
169
170**User B** hands off a reference to **EC1**, acquired through **SC1**,
171to another object, **User C**. The acquisition of a reference on
172**EC1**, which transitions from 0 to 1, triggers the acquisition of a
173reference on its parent, **SC1**.
174
175image::doc/contributing-images/bt-ref07.png[]
176
177At some point, **User A** releases its reference on **EC3**. Since
178**EC3**'s reference count transitions to zero, it releases its reference
179on **SC2**. **SC2**'s reference count, in turn, reaches zero and it
180releases its reference to **TC1**.
181
182**TC1**'s reference count is now 1 and no further action is taken.
183
184image::doc/contributing-images/bt-ref08.png[]
185
186**User B** releases its reference on **SC1**. **User C** becomes the
187sole owner of the whole hierarchy through his ownership of **EC1**.
188
189image::doc/contributing-images/bt-ref09.png[]
190
191Finally, **User C** releases his ownership of **EC1**, triggering the
192release of the whole hierarchy. Let's walk through the reclamation of
193the whole graph.
194
195Mirroring what happened when **User A** released its last reference on
196**EC3**, the release of **EC1** by **User C** causes its reference count
197to fall to zero.
198
199This transition to zero causes **EC1** to release its reference on
200**SC1**. **SC1**'s reference count reaching zero causes it to release
201its reference on **TC1**.
202
203image::doc/contributing-images/bt-ref10.png[]
204
205Since the reference count of **TC1**, a root object, has reached zero,
206it invokes the destructor method on its children. This method is
207recursive and causes the stream classes to call the destructor method on
208their event classes.
209
210The event classes are reached and, having no children of their own, are
211reclaimed.
212
213image::doc/contributing-images/bt-ref11.png[]
214
215The stream classes having destroyed their children, are then reclaimed
216by the trace.
217
218image::doc/contributing-images/bt-ref12.png[]
219
220Finally, the stream classes having been reclaimed, **TC1** is reclaimed.
221
222image::doc/contributing-images/bt-ref13.png[]
223
224
225== Valgrind
226
227To use Valgrind on an application (for example, the CLI or a test) which
228loads libbabeltrace, use:
229
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
233
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
236the Python plugin provider (Valgrind will probably show a lot of errors
237which originate from Python interpreter anyway).
238
239`BABELTRACE_NO_DLCLOSE=1` makes libbabeltrace not close the shared
240libraries (plugins) which it loads. This is needed to see the
241appropriate backtrace when Valgrind shows errors.
242
243
244== Logging
beb0fb75
PP
245
246Logging is a great instrument for a developer to be able to collect
247information about a running software.
248
249Babeltrace is a complex software with many layers. When a Babeltrace
250graph fails to run, what caused the failure? It could be caused by any
251component, any notification iterator, and any deeply nested validation
252of a CTR IR object, for example. With the appropriate logging statements
253manually placed in the source code, we can find the cause of a bug
254faster.
255
f9ded0e0
PP
256While <<log-level,care must be taken>> when placing _INFO_ to _FATAL_
257logging statements, you should liberally instrument your Babeltrace
258module with _DEBUG_ and _VERBOSE_ logging statements to help future you
259and other developers understand what's happening at run-time.
beb0fb75
PP
260
261
f9ded0e0 262=== Logging API
beb0fb75
PP
263
264The Babeltrace logging API is internal: it is not exposed to the users
265of the library, only to their developers. The only thing that a library
4a41523d 266user can control is the current log level of the library itself with
beb0fb75
PP
267`bt_logging_set_global_level()` and the initial library's log level with
268the `BABELTRACE_LOGGING_GLOBAL_LEVEL` environment variable.
269
270This API is based on https://github.com/wonder-mice/zf_log[zf_log], a
271lightweight, yet featureful, MIT-licensed core logging library for C and
272$$C++$$. The zf_log source files were modified to have the `BT_` and
f9ded0e0 273`bt_` prefixes, and other small changes, like color support.
beb0fb75
PP
274
275The logging functions are implemented in the logging convenience
276library (`logging` directory).
277
278
f9ded0e0 279==== Headers
beb0fb75
PP
280
281The logging API headers are:
282
283`<babeltrace/logging.h>`::
284 Public header which a library user can use to control and read
285 libbabeltrace's current log level.
286
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`.
290
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>`.
296
297Do not include `<babeltrace/logging-internal.h>` or
298`<babeltrace/lib-logging-internal.h>` in a header which contains logging
299statements: this header could be included in source files which define a
f9ded0e0
PP
300different <<choose-a-tag,tag>>, for example. See
301<<logging-instrument-header, Instrument a C header file>>.
beb0fb75 302
b4b9064d 303
f9ded0e0 304==== Log levels
beb0fb75
PP
305
306The API offers the following log levels:
307
308* _VERBOSE_
309* _DEBUG_
310* _INFO_
311* _WARN_
312* _ERROR_
313* _FATAL_
314
f9ded0e0 315See <<log-level,how to decide which one to use>> below.
beb0fb75
PP
316
317There are two important log level variables:
318
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,
323 plugins, etc.).
324+
325All the logging statements with a level below this level are **not built
326at all**. All the logging statements with a level equal to or greater
f9ded0e0
PP
327than this level _can_ be executed, depending on the
328<<run-time-log-level,run-time log level>>.
beb0fb75
PP
329+
330You can set this level at configuration time with the
331`BABELTRACE_MINIMAL_LOG_LEVEL` environment variable, for example:
332+
333--
334----
335$ BABELTRACE_MINIMAL_LOG_LEVEL=WARN ./configure
336----
337--
338+
f9ded0e0 339The default build-time log level is `VERBOSE`. For optimal performance,
beb0fb75
PP
340set it to `NONE`, which effectively disables all logging in all the
341Babeltrace subprojects.
342+
343The library's public API provides `bt_logging_get_minimal_level()` to
344get the configured minimal log level.
345
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
f9ded0e0
PP
351 are executed, provided that their level is also
352 <<build-time-log-level,enabled at build time>>.
beb0fb75 353+
f9ded0e0
PP
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
356symbol, and always make sure that `BT_LOG_OUTPUT_LEVEL` is defined to a
357module-wise or subproject-wise hidden symbol before including
beb0fb75 358`<babeltrace/logging-internal.h>`. In the library,
f9ded0e0
PP
359`<babeltrace/lib-logging-internal.h>` does this job: just include this
360header which defines `BT_LOG_OUTPUT_LEVEL` to the appropriate symbol
361before it includes `<babeltrace/logging-internal.h>`. In plugins, for
362example, there is one log level per component class, which makes log
363filtering easier during execution.
beb0fb75
PP
364+
365In libbabeltrace, the user can set the current run-time log level with
366the `bt_logging_set_global_level()` function, for example:
367+
368--
369[source,c]
370----
371bt_logging_set_global_level(BT_LOGGING_LEVEL_INFO);
372----
373--
374+
375The 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
378environment variable is undefined.
379+
380Other subprojects have their own way of setting their run-time log
381level. For example, the CLI uses the `BABELTRACE_CLI_LOG_LEVEL`
f9ded0e0 382environment variable, and the `filter.utils.muxer` component class
beb0fb75 383initializes its log level thanks to the
f9ded0e0 384`BABELTRACE_PLUGIN_UTILS_MUXER_FLT_LOG_LEVEL` environment variable
beb0fb75
PP
385(also _NONE_ by default).
386+
387Make sure that there is a documented way to initialize or modify the
388log level of your subproject or module, and that it's set to _NONE_
389by default.
390
391
4a41523d 392[[logging-statements]]
f9ded0e0 393==== Logging statement macros
beb0fb75
PP
394
395The Babeltrace logging statement macros work just like `printf()` and
396contain their log level in their name:
397
398`BT_LOGV("format string", ...)`::
399 Standard verbose logging statement.
400
401`BT_LOGD("format string", ...)`::
402 Standard debug logging statement.
403
404`BT_LOGI("format string", ...)`::
405 Standard info logging statement.
406
407`BT_LOGW("format string", ...)`::
408 Standard warning logging statement.
409
410`BT_LOGE("format string", ...)`::
411 Standard error logging statement.
412
413`BT_LOGF("format string", ...)`::
414 Standard fatal logging statement.
415
416`BT_LOGV_MEM(data_ptr, data_size, "format string", ...)`::
417 Memory verbose logging statement.
418
419`BT_LOGD_MEM(data_ptr, data_size, "format string", ...)`::
420 Memory debug logging statement.
421
422`BT_LOGI_MEM(data_ptr, data_size, "format string", ...)`::
423 Memory info logging statement.
424
425`BT_LOGW_MEM(data_ptr, data_size, "format string", ...)`::
426 Memory warning logging statement.
427
428`BT_LOGE_MEM(data_ptr, data_size, "format string", ...)`::
429 Memory error logging statement.
430
431`BT_LOGF_MEM(data_ptr, data_size, "format string", ...)`::
432 Memory fatal logging statement.
433
b81626f9
PP
434`BT_LOGV_ERRNO("initial message", "format string", ...)`::
435 `errno` string verbose logging statement.
436
437`BT_LOGD_ERRNO("initial message", "format string", ...)`::
438 `errno` string debug logging statement.
439
440`BT_LOGI_ERRNO("initial message", "format string", ...)`::
441 `errno` string info logging statement.
442
443`BT_LOGW_ERRNO("initial message", "format string", ...)`::
444 `errno` string warning logging statement.
445
446`BT_LOGE_ERRNO("initial message", "format string", ...)`::
447 `errno` string error logging statement.
448
449`BT_LOGF_ERRNO("initial message", "format string", ...)`::
450 `errno` string fatal logging statement.
451
beb0fb75
PP
452`BT_LOGV_STR("preformatted string")`::
453 Preformatted string verbose logging statement.
454
455`BT_LOGD_STR("preformatted string")`::
456 Preformatted string debug logging statement.
457
458`BT_LOGI_STR("preformatted string")`::
459 Preformatted string info logging statement.
460
461`BT_LOGW_STR("preformatted string")`::
462 Preformatted string warning logging statement.
463
464`BT_LOGE_STR("preformatted string")`::
465 Preformatted string error logging statement.
466
467`BT_LOGF_STR("preformatted string")`::
468 Preformatted string fatal logging statement.
469
470
f9ded0e0 471==== Conditional logging
beb0fb75
PP
472
473`BT_LOG_IF(cond, statement)`::
474 Execute `statement` only if `cond` is true.
475+
476Example:
477+
478--
479[source,c]
480----
481BT_LOG_IF(i < count / 2, BT_LOGD("Log this: i=%d", i));
482----
483--
484
485To check the <<build-time-log-level,build-time log level>>:
486
487[source,c]
488----
489#if BT_LOG_ENABLED_DEBUG
490...
491#endif
492----
493
f9ded0e0
PP
494This tests if the _DEBUG_ level was enabled at build-time. This means
495that 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
497logging statements at the same level in a `BT_LOG_ENABLED_*` conditional
498block.
beb0fb75
PP
499
500The available definitions for build-time conditions are:
501
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`
508
509To check the current, <<run-time-log-level,run-time log level>>:
510
511[source,c]
512----
513if (BT_LOG_ON_DEBUG) {
514 ...
515}
516----
517
518This 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
520noticeable impact on performance.
521
522The available definitions for run-time conditions are:
523
524* `BT_LOG_ON_VERBOSE`
525* `BT_LOG_ON_DEBUG`
526* `BT_LOG_ON_INFO`
527* `BT_LOG_ON_WARN`
528* `BT_LOG_ON_ERROR`
529* `BT_LOG_ON_FATAL`
530
531Those macros check the subproject-specific or module-specific log level
532symbol (defined by `BT_LOG_OUTPUT_LEVEL`).
533
534Never, ever write code which would be executed only to compute the
535fields of a logging statement outside a conditional logging scope,
536for example:
537
538[source,c]
539----
540int number = get_number_of_event_classes_with_property_x(...);
541BT_LOGD("Bla bla: number=%d", number);
542----
543
544Do this instead:
545
546[source,c]
547----
548if (BT_LOG_ON_DEBUG) {
549 int number = get_number_of_event_classes_with_property_x(...);
550 BT_LOGD("Bla bla: number=%d", number);
551}
552----
553
554Or even this:
555
556[source,c]
557----
558BT_LOGD("Bla bla: number=%d", get_number_of_event_classes_with_property_x(...));
559----
560
561
4a41523d
PP
562[[how-to]]
563=== Instrument a module
beb0fb75 564
4a41523d 565Follow those steps to make your module loggable:
beb0fb75 566
4a41523d
PP
567. In your module's root directory, create a `logging.c` file with
568 this content:
569+
570--
571[source,c]
572----
573/*
574 * Copyright (c) 2017 EfficiOS Inc. <http://efficios.com/>
575 *
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:
582 *
583 * The above copyright notice and this permission notice shall be included in
584 * all copies or substantial portions of the Software.
585 *
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
592 * SOFTWARE.
593 */
594
595#define BT_LOG_OUTPUT_LEVEL my_module_log_level
596#include <babeltrace/logging-internal.h>
beb0fb75 597
4a41523d
PP
598BT_LOG_INIT_LOG_LEVEL(my_module_log_level, "BABELTRACE_MY_MODULE_LOG_LEVEL");
599----
600--
601+
602Replace `my_module_log_level` with the name of the symbol which holds
603the log level for your module (should be unique amongst all the log level
604symbols of the project). Replace `BABELTRACE_MY_MODULE_LOG_LEVEL` with
605the name of the environment variable from which to initialize your
606module's log level at construction time. `BT_LOG_INIT_LOG_LEVEL()`
607defines both the hidden log level symbol and a constructor which reads
608the environment variable and sets the log level symbol accordingly.
609
610. In your module's root directory, create a `logging.h` file with
611 this content:
612+
613--
beb0fb75
PP
614[source,c]
615----
971e1e8b
PP
616#ifndef BABELTRACE_MY_MODULE_LOGGING_H
617#define BABELTRACE_MY_MODULE_LOGGING_H
4a41523d
PP
618
619/*
620 * Copyright (c) 2017 EfficiOS Inc. <http://efficios.com/>
621 *
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:
628 *
629 * The above copyright notice and this permission notice shall be included in
630 * all copies or substantial portions of the Software.
631 *
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
638 * SOFTWARE.
639 */
640
641#define BT_LOG_OUTPUT_LEVEL my_module_log_level
beb0fb75 642#include <babeltrace/logging-internal.h>
4a41523d
PP
643
644BT_LOG_LEVEL_EXTERN_SYMBOL(my_module_log_level);
645
971e1e8b 646#endif /* BABELTRACE_MY_MODULE_LOGGING_H */
beb0fb75 647----
4a41523d
PP
648--
649+
f9ded0e0 650Replace `my_module_log_level` with the name of your module's
4a41523d
PP
651log level symbol.
652
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`.
beb0fb75 655
6470c171
PP
656. Add the log level initializing environment variable name to the
657 `log_level_env_var_names` array in `cli/babeltrace.c`.
658
f9ded0e0
PP
659
660[[logging-instrument-source]]
661==== Instrument a C source file
662
4a41523d
PP
663To instrument a C source file (`.c`):
664
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`:
667+
668--
669[source,c]
670----
671#define BT_LOG_TAG "MY-MODULE-MY-FILE"
672#include "logging.h"
673----
674--
675+
676A logging tag name is a namespace for a specific source file. Its name
677is part of every log message generated by the statements of the file. A
678logging tag name _must_ be only uppercase letters, digits, and the
f9ded0e0 679hyphen (`-`) character. See <<choose-a-tag,Choose a tag>> for
4a41523d
PP
680a list of standard tags.
681
682. Use the <<logging-statements,logging statement macros>> in the file's
683 functions to instrument it.
684
f9ded0e0
PP
685
686[[logging-instrument-header]]
687==== Instrument a C header file
688
4a41523d
PP
689To instrument a C header file (`.h`), if you have `static inline`
690functions in it:
691
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:
696+
697--
698[source,c]
699----
700static inline
701void some_function(void)
702{
703 /* ... */
704
705#ifdef BT_LOGV
706 BT_LOGV(...);
707#endif
708
709 /* ... */
710
711#ifdef BT_LOGW_STR
712 BT_LOGW_STR(...);
713#endif
714
715 /* ... */
716}
717----
718--
719+
720The C source files which include this header file determine if logging
721is enabled or not for them (if the source file is instrumented itself),
722and the tag of the included header's logging statement is the same as
f9ded0e0 723the including C source file.
beb0fb75
PP
724
725
f9ded0e0 726[[choose-a-tag]]
93841983 727=== Choose a tag
beb0fb75 728
93841983
PP
729For plugins, the format of the tag name for a given source file _must_
730be:
beb0fb75 731
93841983
PP
732[verse]
733PLUGIN-__PNAME__-__CCNAME__-__CCTYPE__[-__FILE__]
beb0fb75 734
93841983
PP
735__PNAME__::
736 Plugin's name.
beb0fb75 737
93841983
PP
738__CCNAME__::
739 Component class's name.
beb0fb75 740
93841983
PP
741__CCTYPE__::
742 Component class's type (`SRC`, `FLT`, or `SINK`).
beb0fb75 743
93841983
PP
744__FILE__::
745 Additional information to specify the source file name or module.
beb0fb75 746
93841983 747Examples:
beb0fb75 748
93841983
PP
749* `PLUGIN-CTF-LTTNG-LIVE-SRC`
750* `PLUGIN-CTF-LTTNG-LIVE-SRC-VIEWER`
751* `PLUGIN-UTILS-MUXER-FLT`
beb0fb75
PP
752
753
f9ded0e0
PP
754[[log-level]]
755=== Choose a log level
beb0fb75
PP
756
757Choosing the appropriate level for your logging statement is very
758important.
759
760[options="header,autowidth",cols="default,default,asciidoc,default"]
761|===
762|Log level |Description |Use cases |Impact on performance
763
764|_FATAL_
765|The program, library, or plugin cannot continue to work in this
766condition: it must be terminated immediately.
767
b4b9064d 768A _FATAL_-level logging statement should always be followed by
4a41523d 769`abort()`.
beb0fb75
PP
770|
771* Unexpected return values from system calls.
4a41523d
PP
772* Logic error in internal code, for example an unexpected value in a
773 `switch` statement.
beb0fb75
PP
774|Almost none: should be executed in production.
775
776|_ERROR_
777|An important error which is somewhat not fatal, that is, the program,
778library, or plugin can continue to work after this, but you judge that
779it should be reported to the user.
780
781Usually, the program cannot recover from such an error, but it can at
782least exit cleanly.
783|
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.
93841983 789* Almost any error in terminal elements: CLI and plugins.
beb0fb75
PP
790|Almost none: should be executed in production.
791
792|_WARN_
793|A logic error which still allows the execution to continue.
6c1b33a8
PP
794
795_WARN_-level logging statements are for any error or weird action that
796is directly or indirectly caused by the user. For example, not having
4a41523d
PP
797enough memory is considered beyond the user's control, so we always
798log memory errors with an _ERROR_ level (not _FATAL_ because we usually
799don't abort in this condition).
93841983
PP
800
801Almost all the library's errors are logged as warnings because they are
802caused by the user.
beb0fb75 803|
6c1b33a8
PP
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
807 part of a trace.
beb0fb75
PP
808+
809For example, the caller tries to set a property of a frozen stream
810class.
811|Almost none: can be executed in production.
812
813|_INFO_
814|Any useful information which a non-developer user would understand.
815|
816* Successful loading of a plugin (with name, version, etc.).
817* Successful connection to or disconnection from another system.
4a41523d 818* An _optional_ subsystem cannot be loaded.
beb0fb75
PP
819|Very little: can be executed in production if
820_INFO_ level information is desired.
821
822|_DEBUG_
823|Something that only Babeltrace developers would be interested into.
824|
825* High-level function entry/exit.
826* Object creation, destruction, copying, and freezing.
f9ded0e0
PP
827* The result of some computation/validation which does not
828 occur in a tight loop.
beb0fb75
PP
829|Noticeable, but not as much as the _VERBOSE_ level: not executed in
830production.
831
832|_VERBOSE_
833|Low-level debugging context information. More appropriate for tracing
834in general.
835|
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.
844|===
845
b4b9064d
PP
846Make sure not to use a _WARN_ (or higher) log level when the condition
847leading to the logging statement can occur under normal circumstances.
848For example, a public function to get some object or property from an
849object by name or key that fails to find the value is not a warning: the
850user could legitimately use this function to check if the name/key
851exists in the object. In this case, use the _VERBOSE_ level (or do not
852log at all). If a numeric index is out of bounds, however, this
853qualifies for a _WARN_ level: such API functions have documented
854preconditions that the index must be in bounds (the user can always
855check with a count or size function).
856
beb0fb75 857
b4b9064d 858[[message]]
f9ded0e0 859=== Write an appropriate message
beb0fb75
PP
860
861Follow those rules when you write a logging statement's message:
862
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
865 example:
866+
867--
b4b9064d
PP
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
872 also _set_)
beb0fb75
PP
873--
874+
875For warning and error messages, you can start the message with _Cannot_
b4b9064d 876or _Failed to_ followed by a verb if it's appropriate.
beb0fb75
PP
877
878* Do not include the log level in the message itself. For example,
879 do not start the message with _Error while_ or _Warning:_.
880
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,
b4b9064d
PP
884 however, so prefer multiple `BT_LOG*()` statements over a single
885 statement with newlines.
beb0fb75
PP
886
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.
891
892The statement's fields _must_ be a comma-separated list of
893+__name__=__value__+ tokens. Keep +__name__+ as simple as possible
b4b9064d
PP
894(lowercase if possible). If +__value__+ is a non-alphanumeric string,
895put it between double quotes. Always use the `PRId64` and `PRIu64`
896specifiers when logging `int64_t` and `uint64_t` values.
beb0fb75
PP
897
898Example:
899
900 "Cannot add event class to stream class: stream-class-addr=%p, "
b4b9064d 901 "stream-class-name=\"%s\", stream-class-id=%" PRId64 ", "
beb0fb75
PP
902 "event-class-addr=%p, event-class-name=\"%s\", event-class-id=%" PRId64
903
904By following a standard format for the statement fields, it is easier
905to use tools like https://www.elastic.co/products/logstash[Logstash]
906to split fields and analyze logs.
907
908Prefer the following suffixes in field names:
909
910[options="header,autowidth"]
911|===
912|Field name suffix |Description |Format specifier
913
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\"`
beb0fb75
PP
919|===
920
921
f9ded0e0 922=== Output
beb0fb75
PP
923
924The log is printed to the standard error stream. A log line contains the
f9ded0e0
PP
925time, the process and thread IDs, the <<log-level,log level>>, the
926<<choose-a-tag,tag>>, the source's function name, file name and
927line number, and the <<message,message>>.
beb0fb75 928
f9ded0e0
PP
929When Babeltrace supports terminal color codes (depends on the
930`BABELTRACE_TERM_COLOR` environment variable's value and what the
931standard output and error streams are plugged into), _INFO_-level lines
932are blue, _WARN_-level lines are yellow, and _ERROR_-level and
933_FATAL_-level lines are red.
934
935Log line example:
beb0fb75
PP
936
937 05-11 00:58:03.691 23402 23402 D VALUES bt_value_destroy@values.c:498 Destroying value: addr=0xb9c3eb0
938
939You can easily filter the log with `grep` or `ag`. For example, to
940keep only the _WARN_-level log messages that the `VALUES` module
941generates:
942
943 $ export BABELTRACE_LOGGING_GLOBAL_LEVEL=VERBOSE
944 $ ./test_ctf_writer_complete 2>&1 | ag 'W VALUES'
This page took 0.068687 seconds and 4 git commands to generate.