1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
|
Title: Message Logging
# Message Logging
The `g_return` family of macros (`g_return_if_fail()`,
`g_return_val_if_fail()`, `g_return_if_reached()`,
`g_return_val_if_reached()`) should only be used for programming errors, a
typical use case is checking for invalid parameters at the beginning of a
public function. They should not be used if you just mean "if (error)
return", they should only be used if you mean "if (bug in program) return".
The program behavior is generally considered undefined after one of these
checks fails. They are not intended for normal control flow, only to give a
perhaps-helpful warning before giving up.
Structured logging output is supported using `g_log_structured()`. This
differs from the traditional `g_log()` API in that log messages are handled
as a collection of key–value pairs representing individual pieces of
information, rather than as a single string containing all the information
in an arbitrary format.
The convenience macros `g_info()`, `g_message()`, `g_debug()`, `g_warning()`
and `g_error()` will use the traditional `g_log()` API unless you define the
symbol `G_LOG_USE_STRUCTURED` before including `glib.h`. But note that even
messages logged through the traditional `g_log()` API are ultimatively
passed to `g_log_structured()`, so that all log messages end up in same
destination. If `G_LOG_USE_STRUCTURED` is defined, `g_test_expect_message()`
will become ineffective for the wrapper macros `g_warning()` and friends
(see [Testing for Messages](#testing-for-messages).)
The support for structured logging was motivated by the following needs
(some of which were supported previously; others weren’t):
- Support for multiple logging levels.
- Structured log support with the ability to add `MESSAGE_ID`s (see
`g_log_structured()`).
- Moving the responsibility for filtering log messages from the program to
the log viewer — instead of libraries and programs installing log handlers
(with `g_log_set_handler()`) which filter messages before output, all log
messages are outputted, and the log viewer program (such as
[`journalctl`](https://www.freedesktop.org/software/systemd/man/journalctl.html))
must filter them. This is based on the idea that bugs are sometimes hard
to reproduce, so it is better to log everything possible and then use
tools to analyse the logs than it is to not be able to reproduce a bug to
get additional log data. Code which uses logging in performance-critical
sections should compile out the `g_log_structured()` calls in release
builds, and compile them in in debugging builds.
- A single writer function which handles all log messages in a process, from
all libraries and program code; rather than multiple log handlers with
poorly defined interactions between them. This allows a program to easily
change its logging policy by changing the writer function, for example to
log to an additional location or to change what logging output fallbacks
are used. The log writer functions provided by GLib are exposed publicly
so they can be used from programs’ log writers. This allows log writer
policy and implementation to be kept separate.
- If a library wants to add standard information to all of its log messages
(such as library state) or to redact private data (such as passwords or
network credentials), it should use a wrapper function around its
`g_log_structured()` calls or implement that in the single log writer
function.
- If a program wants to pass context data from a `g_log_structured()` call
to its log writer function so that, for example, it can use the correct
server connection to submit logs to, that user data can be passed as a
zero-length `GLogField` to `g_log_structured_array()`.
- Color output needed to be supported on the terminal, to make reading
through logs easier.
## Using Structured Logging
To use structured logging (rather than the old-style logging), either use
the `g_log_structured()` and `g_log_structured_array()` functions; or define
`G_LOG_USE_STRUCTURED` before including any GLib header, and use the
`g_message()`, `g_debug()`, `g_error()` (etc.) macros.
You do not need to define `G_LOG_USE_STRUCTURED` to use
`g_log_structured()`, but it is a good idea to avoid confusion.
## Log Domains
Log domains may be used to broadly split up the origins of log messages.
Typically, there are one or a few log domains per application or library.
`G_LOG_DOMAIN` should be used to define the default log domain for the current
compilation unit — it is typically defined at the top of a source file, or
in the preprocessor flags for a group of source files.
Log domains must be unique, and it is recommended that they are the
application or library name, optionally followed by a hyphen and a
sub-domain name. For example, `bloatpad` or `bloatpad-io`.
## Debug Message Output
The default log functions (`g_log_default_handler()` for the old-style API
and `g_log_writer_default()` for the structured API) both drop debug and
informational messages by default, unless the log domains of those messages
are listed in the `G_MESSAGES_DEBUG` environment variable (or it is set to
`all`), or `DEBUG_INVOCATION=1` is set in the environment.
It is recommended that custom log writer functions re-use the
`G_MESSAGES_DEBUG` and `DEBUG_INVOCATION` environment variables, rather than
inventing a custom one, so that developers can re-use the same debugging
techniques and tools across projects. Since GLib 2.68, this can be implemented
by dropping messages for which `g_log_writer_default_would_drop()` returns
`TRUE`.
## Testing for Messages
With the old `g_log()` API, `g_test_expect_message()` and
`g_test_assert_expected_messages()` could be used in simple cases to check
whether some code under test had emitted a given log message. These
functions have been deprecated with the structured logging API, for several
reasons:
- They relied on an internal queue which was too inflexible for many use
cases, where messages might be emitted in several orders, some messages
might not be emitted deterministically, or messages might be emitted by
unrelated log domains.
- They do not support structured log fields.
- Examining the log output of code is a bad approach to testing it, and
while it might be necessary for legacy code which uses `g_log()`, it
should be avoided for new code using `g_log_structured()`.
They will continue to work as before if `g_log()` is in use (and
`G_LOG_USE_STRUCTURED` is not defined). They will do nothing if used with
the structured logging API.
Examining the log output of code is discouraged: libraries should not emit
to stderr during defined behaviour, and hence this should not be tested. If
the log emissions of a library during undefined behaviour need to be tested,
they should be limited to asserting that the library aborts and prints a
suitable error message before aborting. This should be done with
`g_test_trap_assert_stderr()`.
If it is really necessary to test the structured log messages emitted by a
particular piece of code – and the code cannot be restructured to be more
suitable to more conventional unit testing – you should write a custom log
writer function (see `g_log_set_writer_func()`) which appends all log
messages to a queue. When you want to check the log messages, examine and
clear the queue, ignoring irrelevant log messages (for example, from log
domains other than the one under test).
|
