A log library#
Let’s use all the tricks learned so far to write our first macros.
It will be the occasion to introduce more tricks, and to create a logging utility header that may be used in real projects.
Objective#
We want logging functions
that display debug information like the location of the log in the source (file, function, line)
that have a log level associated, and be able to filter out the most verbose levels if desired
whose output format can be configured, and have a markdown output format to be rendered here
We will write something like:
log_debug("Hello world !");
log_error("Failed to open `%s`: %s", file_name, strerror(errno));
And want something of the form:
| DEBUG | `folder/file.c` | `main` | 12 | Hello world ! |
| ERROR | `folder/file.c` | `foobar` | 42 | Failed to open `baz.csv`: No such file or directory |
Details about the markdown syntax
Because a program may output thousands upon thousands of log lines when running, it might be preferable not to print characters that have no effect.
In our instance, there is no need for spaces around |, and the two outer | can be omitted, so what we actually want to be output is:
DEBUG|`folder/file.c`|`main`|12|Hello world !
ERROR|`folder/file.c`|`foobar`|42|Failed to open `baz.csv`: No such file or directory
That will be rendered here as:
Mardown table rendered
Level |
File |
Function |
Line |
Message |
|---|---|---|---|---|
DEBUG |
|
|
12 |
Hello world ! |
ERROR |
|
|
42 |
Failed to open |
The simplest and most direct way to achieve the desired output is to print it literally:
printf("DEBUG|`folder/file.c`|`main`|12|Hello world !\n");
printf("ERROR|`folder/file.c`|`foobar`|42|Failed to open `%s`: %s\n", file_name, strerror(errno));
Starting from this, let’s use increasingly andvanced tricks to end-up with the desired interface, while remaining functionnaly equivalent to the simplest solution.
Bonus feature
It could be useful to have a way to automatically include in the log what the computation was, in addition to its result.
An example would be to write:
log_eval(2 + 2);
log_eval(strlen(a) - strlen(b));
and expect logs that contain:
2 + 2 = 4
strlen(a) - strlen(b) = 8
Split string literals#
The first trick we can use is not specific to macros: we have seen, in the list of phases of translation, that during phase 6, “Adjacent string literals are concatenated”.
What that means is that "Hello" " World" becomes "Hello World". More interestingly, it allows to split a string literal on multiple lines, without the need for a way to escape new lines:
const char help[] =
"Usage:\n"
" command [OPTION...] FILE\n\n"
"Options:\n"
" -h, --help Print this help\n"
" -p, --port=INT Specify the port to listen to\n";
This allows us to split the boiler-plate from the “variable” parts of the string:
printf("DEBUG" "|`" "folder/file.c" "`|`" "main" "`|" "12" "|" "Hello world !" "\n");
printf("ERROR" "|`" "folder/file.c" "`|`" "foobar" "`|" "42" "|" "Failed to open `%s`: %s" "\n", file_name, strerror(errno));
Current file name#
In addition to the user-provided string, a variable part of the log output is the name of the file the log is from.
We don’t want the user to have to provide it, as it would then have no guarantee of being up to date and would therefore be useless.
Luckily, the compiler can provide this information, as we have seen in the last chapter. Most conveniently, it is provided as a string literal, allowing us to concatenate it with the rest of the string at compile-time:
printf("DEBUG" "|`" __FILE__ "`|`" "main" "`|" "12" "|" "Hello world !" "\n");
printf("ERROR" "|`" __FILE__ "`|`" "foobar" "`|" "42" "|" "Failed to open `%s`: %s" "\n", file_name, strerror(errno));
Note
In this instance, we use __FILE__ and not __FILE_NAME__, to be able to differentiate files that have the same name in different directories, like arrays/push.c and deque/push.c.
Current function and line#
OK, the file name was easy, but what about the function name ?
As seen in the last chapter, the name of the function is provided by a magic constant __func__.
But as it is not a string literal, it cannot be concatenated at compile-time.
So we have to do that at run-time, and we are already using printf, so let’s use the %s flag:
printf("DEBUG" "|`" __FILE__ "`|`%s`|" "12" "|" "Hello world !" "\n", __func__);
printf("ERROR" "|`" __FILE__ "`|`%s`|" "42" "|" "Failed to open `%s`: %s" "\n", __func__, file_name, strerror(errno));
As you can see, it is slightly less trivial than the previous step, as it involves adding an argument to printf, before the user provided arguments, if any.
Note
__func__ and __FUNCTION__ are two names of the exact same variable, so they can be used interchangably. But the lower case __func__ emphasize the fact that it is not a compile-time macro, as opposed to __FILE__.
Next, we have the line number to display. By using the same trick as the function name, we can include it at run-time:
printf("DEBUG" "|`" __FILE__ "`|`%s`|%i|" "Hello world !" "\n", __func__, __LINE__);
printf("ERROR" "|`" __FILE__ "`|`%s`|%i|" "Failed to open `%s`: %s" "\n", __func__, __LINE__, file_name, strerror(errno));
Define a simple macro#
We can now place the boiler-plate in a macro to be reused:
Step 5 - Single-parameter macros
1#include <stdio.h> // printf
2
3#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
4
5#define log_log(LEVEL, MESSAGE) \
6 printf("|" LEVEL "|`" __FILE__ "`|`%s`|%i|" MESSAGE "\n", __func__, __LINE__)
7
8#define log_debug(MESSAGE) log_log("DEBUG", MESSAGE)
9#define log_error(MESSAGE) log_log("ERROR", MESSAGE)
10
11int main()
12{
13 printf(MARKDOWN_HEADER);
14 log_debug("Hello world !");
15 log_error("Failed to open");
16}
int main()
{
printf("|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n");
printf("|"
"DEBUG"
"|`"
"samples/03_simple_macro.c"
"`|`%s`|%i|"
"Hello world !"
"\n",
__func__,
14);
printf("|"
"ERROR"
"|`"
"samples/03_simple_macro.c"
"`|`%s`|%i|"
"Failed to open"
"\n",
__func__,
15);
}
Level |
File |
Function |
Line |
Message |
|---|---|---|---|---|
DEBUG |
|
|
14 |
Hello world ! |
ERROR |
|
|
15 |
Failed to open |
That is nice, but we also want to be able to pass additional arguments to printf, to include values of run-time variables.
Printf can take a variable number of arguments, making it what is called a “variadic function”. It is made possible by a language feature, that affects how parameters are placed on the stack and accessed by the callee.
Fortunatly, the C language also features a way for macros to be variadic, which is the next trick we’ll be using.
Define a variadic macro#
How to define and use variadic macros ?
A variadic macro is a function-like macro that takes a variable number of arguments.
To define a variadic macro we just need to add an ellipsis (...) after the mandatory arguments, if any:
1#define FOO(A, B, ...) A + B
2#define NOOP(...)
3
4int main()
5{
6 int n = FOO(1, 2, 3, 4);
7 int m = NOOP(1, 2, 3) - FOO(8, 2, 0);
8}
int main()
{
int n = 1 + 2;
int m = -8 + 2;
}
The extra arguments can then be pasted using the __VA_ARGS__ identifier:
1#define ROTATE(A, ...) __VA_ARGS__, A
2#define TWICE(...) __VA_ARGS__, __VA_ARGS__
3
4int main()
5{
6 const short rotate[] = {ROTATE(1, 2, 3, 4)};
7 const short twice[] = {TWICE(1, 2, 3)};
8}
int main()
{
const short rotate[] = { 2, 3, 4, 1 };
const short twice[] = { 1, 2, 3, 1, 2, 3 };
}
The magic macro __VA_OPT__ can be used to remove certain characters when __VA_ARGS__ is empty:
1#define INTEGERS(I, ...) __VA_OPT__({) I __VA_OPT__(, __VA_ARGS__ })
2
3int main()
4{
5 int i = INTEGERS(4);
6 int s[] = INTEGERS(2, 5, 8);
7}
int main()
{
int i = 4;
int s[] = { 2, 5, 8 };
}
Let’s not rush it, as it is tempting to simply add ... and __VA_ARGS__ like so:
#define log_log(LEVEL, MESSAGE, ...) \
printf("|" LEVEL "|`" __FILE__ "`|`%s`|%i|" MESSAGE "\n", __func__, __LINE__, __VA_ARGS__)
#define log_error(MESSAGE, ...) log_log("ERROR", MESSAGE, __VA_ARGS__)
log_error("Failed to open %s: %s", filename, error);
This code causes a compilation error when passing no additional parameters: log_error("Out of memory"); expands to printf("[...]", __func__, __LINE__, ); with an extraneous comma !
To solve this issue we will use the magic macro __VA_OPT__ to remove the comma when __VA_ARGS__ is empty:
Step 6 - Variadic macro
1#include <stdio.h> // printf
2
3#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
4
5#define log_log(LEVEL, MESSAGE, ...) \
6 printf("|" LEVEL "|`" __FILE__ "`|`%s`|%i|" MESSAGE "\n", __func__, __LINE__ __VA_OPT__(,) __VA_ARGS__)
7
8#define log_debug(MESSAGE, ...) log_log("DEBUG", MESSAGE __VA_OPT__(,) __VA_ARGS__)
9#define log_error(MESSAGE, ...) log_log("ERROR", MESSAGE __VA_OPT__(,) __VA_ARGS__)
10
11int main()
12{
13 printf(MARKDOWN_HEADER);
14 log_debug("Hello world !");
15 log_error("Failed to open `%s`: %s", "bar.csv", "no such file");
16}
1#include <stdio.h> // printf
2
3#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
4
5#define log_log(LEVEL, MESSAGE, ...) \
6 printf("|" LEVEL "|`" __FILE__ "`|`%s`|%i|" MESSAGE "\n", __func__, __LINE__ __VA_OPT__(,) __VA_ARGS__)
7
8#define log_debug(MESSAGE, ...) log_log("DEBUG", MESSAGE __VA_OPT__(,) __VA_ARGS__)
9#define log_error(MESSAGE, ...) log_log("ERROR", MESSAGE __VA_OPT__(,) __VA_ARGS__)
10
11int main()
12{
13 printf(MARKDOWN_HEADER);
14 log_debug("Hello world !");
15 log_error("Failed to open `%s`: %s", "bar.csv", "no such file");
16}
int main()
{
printf("|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n");
printf("|"
"DEBUG"
"|`"
"samples/03_variadic_macro.c"
"`|`%s`|%i|"
"Hello world !"
"\n",
__func__,
14);
printf("|"
"ERROR"
"|`"
"samples/03_variadic_macro.c"
"`|`%s`|%i|"
"Failed to open `%s`: %s"
"\n",
__func__,
15,
"bar.csv",
"no such file");
}
Level |
File |
Function |
Line |
Message |
|---|---|---|---|---|
DEBUG |
|
|
14 |
Hello world ! |
ERROR |
|
|
15 |
Failed to open |
History lesson
__VA_OPT__ was introduced in C23. Before that, there was no portable way to remove characters when __VA_ARGS__ is empty.
But because removing a comma when there are no arguments is such a common need, GNU introduced a syntax to specifically remove a comma before __VA_ARGS__ (and nothing else !)
1#include <stdio.h> // printf
2
3#define logger(MESSAGE, ...) printf("[log] " MESSAGE "\n", ##__VA_ARGS__)
4#define TWICE(...) __VA_ARGS__, ##__VA_ARGS__
5
6int main()
7{
8 logger("Hello");
9 logger("Hello %s", "World");
10 int zero[] = {TWICE()};
11 int four[] = {TWICE(2, 4)};
12}
int main()
{
printf("[log] "
"Hello"
"\n");
printf("[log] "
"Hello %s"
"\n",
"World");
int zero[] = {};
int four[] = { 2, 4, 2, 4 };
}
Source: GNU
A portable workaround was to always have at least one mandatory argument, and not giving it a name:
1#include <stdio.h> // printf
2
3#define logger(...) printf("[log] " __VA_ARGS__)
4
5int main(int ac, char** av)
6{
7 logger("Hello\n");
8 logger("argument count: %i\n", ac);
9 logger("program name : %s\n", *av);
10}
int main(int ac, char** av)
{
printf("[log] "
"Hello\n");
printf("[log] "
"argument count: %i\n",
ac);
printf("[log] "
"program name : %s\n",
*av);
}
[log] Hello
[log] argument count: 1
[log] program name : ./cache/03_vm_portable.exe
But as you can tell, it adds a lot of limitations.
Bonus feature: Log an expression and its result#
With the logging macros of the previous section, we can already log the value of a variable with its name:
int answer = 12;
log_debug("answer = %i", answer);
But that requires repeating the name of the variable twice, could there be a way to obtain a string from an identifier ?
Well of course ! We’ve seen it here, the preprocessor has the # operator, that turns an identifer into a string literal.
Important
We have to keep in mind that this operator can only be applied to a parameter of a function-like macro.
Transforming an identifier into a string
1#include <stdio.h> // printf
2
3#define log_eval_integer(VARIABLE) printf("%s = %i\n", #VARIABLE, VARIABLE)
4
5int main(int arg_count, char** arg_values)
6{
7 log_eval_integer(arg_count);
8}
int main(int arg_count, char** arg_values)
{
printf("%s = %i\n", "arg_count", arg_count);
}
arg_count = 1
How does it work ?
Consider the following line of code:
printf("%s = %i\n", arg_count, arg_count);
It would be tokenized like this:
Preprocessing input
printf ( %s = %i\n , arg_count , arg_count ) ;
What the # operator can do is change the token type of arg_count to string literal, arg_count, resulting in:
printf("%s = %i\n", "arg_count", arg_count);
OK that is working as expected, what about a computation ?
Transforming arbitrary code into a string
1#include <stdio.h> // printf
2#include <string.h> // strlen
3
4#define log_eval_integer(EXPRESSION) printf("%s = %i\n", #EXPRESSION, EXPRESSION)
5
6int main(int arg_count, char** arg_values)
7{
8 log_eval_integer(2 + 2);
9 log_eval_integer(strlen(*arg_values));
10}
int main(int arg_count, char** arg_values)
{
printf("%s = %i\n", "2 + 2", 2 + 2);
printf("%s = %i\n", "strlen(*arg_values)", strlen(*arg_values));
}
2 + 2 = 4
strlen(*arg_values) = 20
How does it work ?
To be exact, the # operator applies to the VARIABLE identifier, and creates a string literal from whatever it expands to, which doesn’t even need to be valid C !
Works out of the box, very nice.
Now that it is clear, we can concatenate the string literals at compile time:
#define log_eval_integer(VARIABLE) printf(#VARIABLE " = %i", VARIABLE)
And of course we do not want to have a different macro for every different type, so the macro will take a printf flag as argument:
#define log_eval(FLAG, VARIABLE) printf(#VARIABLE " = %" FLAG, VARIABLE);
Tip
The standard header inttypes.h defines macros that expand to a printf flag, that are useful when using fixed-width integer types like int32_t, uint64_t or intmax_t.
Source: cppreference
Let’s finish this feature and integrate it with the logging macros:
1#include <inttypes.h> // PRI*
2#include <stdio.h> // printf
3
4#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
5
6#define log_log(LEVEL, MESSAGE, ...) \
7 printf("|" LEVEL "|`" __FILE__ "`|`%s`|%i|" MESSAGE "\n", \
8 __func__, __LINE__ __VA_OPT__(,) __VA_ARGS__)
9
10#define log_debug(MESSAGE, ...) \
11 log_log("DEBUG", MESSAGE __VA_OPT__(,) __VA_ARGS__)
12
13#define log_debug_eval(FLAG, EXPRESSION) \
14 log_debug(#EXPRESSION " = %" FLAG, EXPRESSION)
15
16void foo(uint8_t answer)
17{
18 log_debug_eval(PRIu8, answer);
19}
20
21int main(int arg_count, char** arg_values)
22{
23 printf(MARKDOWN_HEADER);
24 log_debug_eval("i", arg_count);
25 foo('*');
26 log_debug_eval("p", arg_values);
27}
1#include <inttypes.h> // PRI*
2#include <stdio.h> // printf
3
4#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
5
6#define log_log(LEVEL, MESSAGE, ...) \
7 printf("|" LEVEL "|`" __FILE__ "`|`%s`|%i|" MESSAGE "\n", \
8 __func__, __LINE__ __VA_OPT__(,) __VA_ARGS__)
9
10#define log_debug(MESSAGE, ...) \
11 log_log("DEBUG", MESSAGE __VA_OPT__(,) __VA_ARGS__)
12
13#define log_debug_eval(FLAG, EXPRESSION) \
14 log_debug(#EXPRESSION " = %" FLAG, EXPRESSION)
15
16void foo(uint8_t answer)
17{
18 log_debug_eval(PRIu8, answer);
19}
20
21int main(int arg_count, char** arg_values)
22{
23 printf(MARKDOWN_HEADER);
24 log_debug_eval("i", arg_count);
25 foo('*');
26 log_debug_eval("p", arg_values);
27}
void foo(uint8_t answer)
{
printf("|"
"DEBUG"
"|`"
"samples/03_eval3.c"
"`|`%s`|%i|"
"answer"
" = %"
"u"
"\n",
__func__,
18,
answer);
}
int main(int arg_count, char** arg_values)
{
printf("|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n");
printf("|"
"DEBUG"
"|`"
"samples/03_eval3.c"
"`|`%s`|%i|"
"arg_count"
" = %"
"i"
"\n",
__func__,
24,
arg_count);
foo('*');
printf("|"
"DEBUG"
"|`"
"samples/03_eval3.c"
"`|`%s`|%i|"
"arg_values"
" = %"
"p"
"\n",
__func__,
26,
arg_values);
}
Level |
File |
Function |
Line |
Message |
|---|---|---|---|---|
DEBUG |
|
|
24 |
arg_count = 1 |
DEBUG |
|
|
18 |
answer = 42 |
DEBUG |
|
|
26 |
arg_values = 0x7ffeda6a1848 |
Convert the line number to a string literal#
Currently, the line number of each log entry is placed at run-time, using the "%i" printf format.
But why do it at run-time ? __LINE__ is a macro that expands to an integer literal, meaning its value is accessible at compile-time. It just isn’t a string, so we cannot concatenate it as-is.
We’ve just seen how the # operator can create a string literal from arbitrary code, let’s use it !
__LINE__ is not an argument of our log_log macro, so we can’t write # __LINE__ directly. Instead we’ll define a STRINGIZE macro that applies # to its argument:
1#include <stdio.h> // printf
2
3#define STRINGIZE(ARG) #ARG
4
5int main(int arg_count, char** arg_values)
6{
7 printf("Line as integer: %i\n", __LINE__);
8 printf("Line as string: %s\n", STRINGIZE(__LINE__));
9 printf("Concatenated: " STRINGIZE(__LINE__) "\n");
10}
int main(int arg_count, char** arg_values)
{
printf("Line as integer: %i\n", 7);
printf("Line as string: %s\n", "__LINE__");
printf("Concatenated: "
"__LINE__"
"\n");
}
Line as integer: 7
Line as string: __LINE__
Concatenated: __LINE__
Wait, that is not what we wanted ! We wanted __LINE__ to be expanded to 8 before being converted to a string !
Turns out using the # and ## operators changes how macro arguments are expanded:
Macro arguments are completely macro-expanded before they are substituted into a macro body, unless they are stringized or pasted with other tokens.
—GCC Documentation
And so, the solution is to have a macro that:
takes
__LINE__as an argumentbut does not apply the
#operator on it, for the argument to be expandedand then passes the result to
STRINGIZE, so that it is converted to a string literal
1#include <stdio.h> // printf
2
3#define STRINGIZE(ARG) #ARG
4#define STRINGIZE_WRAPPER(ARG) STRINGIZE(ARG)
5
6int main(int arg_count, char** arg_values)
7{
8 printf("Line as integer: %i\n", __LINE__);
9 printf("Line as string: %s\n", STRINGIZE_WRAPPER(__LINE__));
10 printf("Concatenated: " STRINGIZE_WRAPPER(__LINE__) "\n");
11}
int main(int arg_count, char** arg_values)
{
printf("Line as integer: %i\n", 8);
printf("Line as string: %s\n", "9");
printf("Concatenated: "
"10"
"\n");
}
Line as integer: 8
Line as string: 9
Concatenated: 10
Success ! We can integrate this in our logging macros:
Step 7 - Line number concaternated at compile-time
1#include <fcntl.h> // open, O_*
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define STRINGIZE_LITERAL(TEXT) #TEXT
8#define STRINGIZE_EVALUATED(EXPR) STRINGIZE_LITERAL(EXPR)
9
10#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
11
12#define log_log(LEVEL, MESSAGE, ...) \
13 printf("|" LEVEL "|`" __FILE__ "`|`%s`|" STRINGIZE_EVALUATED(__LINE__) "|" MESSAGE "\n", \
14 __func__ __VA_OPT__(,) __VA_ARGS__)
15
16#define log_debug(MESSAGE, ...) log_log("DEBUG", MESSAGE __VA_OPT__(,) __VA_ARGS__)
17#define log_error(MESSAGE, ...) log_log("ERROR", MESSAGE __VA_OPT__(,) __VA_ARGS__)
18
19void foobar(const char* file_name)
20{
21 if (open(file_name, O_RDONLY) < 0)
22 log_error("Failed to open `%s`: %s", file_name, strerror(errno));
23}
24
25int main()
26{
27 printf(MARKDOWN_HEADER);
28 log_debug("Hello World !");
29 foobar("bar.csv");
30}
1#include <fcntl.h> // open, O_*
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define STRINGIZE_LITERAL(TEXT) #TEXT
8#define STRINGIZE_EVALUATED(EXPR) STRINGIZE_LITERAL(EXPR)
9
10#define MARKDOWN_HEADER "|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n"
11
12#define log_log(LEVEL, MESSAGE, ...) \
13 printf("|" LEVEL "|`" __FILE__ "`|`%s`|" STRINGIZE_EVALUATED(__LINE__) "|" MESSAGE "\n", \
14 __func__ __VA_OPT__(,) __VA_ARGS__)
15
16#define log_debug(MESSAGE, ...) log_log("DEBUG", MESSAGE __VA_OPT__(,) __VA_ARGS__)
17#define log_error(MESSAGE, ...) log_log("ERROR", MESSAGE __VA_OPT__(,) __VA_ARGS__)
18
19void foobar(const char* file_name)
20{
21 if (open(file_name, O_RDONLY) < 0)
22 log_error("Failed to open `%s`: %s", file_name, strerror(errno));
23}
24
25int main()
26{
27 printf(MARKDOWN_HEADER);
28 log_debug("Hello World !");
29 foobar("bar.csv");
30}
void foobar(const char* file_name)
{
if (open(file_name, 00) < 0)
printf("|"
"ERROR"
"|`"
"samples/03_stringline3.c"
"`|`%s`|"
"22"
"|"
"Failed to open `%s`: %s"
"\n",
__func__,
file_name,
strerror((*__errno_location())));
}
int main()
{
printf("|Level|File|Function|Line|Message|\n|:-|:-|:-|-:|:-|\n");
printf("|"
"DEBUG"
"|`"
"samples/03_stringline3.c"
"`|`%s`|"
"28"
"|"
"Hello World !"
"\n",
__func__);
foobar("bar.csv");
}
Level |
File |
Function |
Line |
Message |
|---|---|---|---|---|
DEBUG |
|
|
28 |
Hello World ! |
ERROR |
|
|
22 |
Failed to open |
Looks like we achieved several of our objectives:
The interface
The markdown table output
The inclusion of debug info (file, function, line)
The bonus objective of logging an expression alongside its result
Two objectives remain:
Configurable log level
Configurable output format
Configurable log level#
While our logs do have a log level associated, there’s currently no way to filter out certain levels.
Because we’re only creating a simplistic header-only logging library, we will not allow arbitrary filters (like outputting debug and warning but not info and error), only a threshold level: only logs as critical as the threshold or more shall be output.
This implies that there must be a way to compare levels.
Currently, log levels are just string literals like "DEBUG" and "ERROR", and cannot be compared meaningfully to determine which is “more critical”.
Run-time comparison#
Solution: Make log levels integers.
And we are clean coders right ? So we’ll define an enum:
/** Criticality of a log entry */
enum log_level {
NONE /**< Choose this value as threshold to disable log output */,
FATAL /**< The program will stop */,
ERROR /**< The current operation will be aborted */,
WARNING /**< Abnormal situation */,
INFO /**< Significant information */,
DEBUG /**< Only relevant to the developpers */,
TRACE /**< Spam */,
};
And a global threshold:
extern const enum log_level log_level;
Then we’ll just have to compare the level of a log entry to the threshold to know if it needs to be output:
#define log(LEVEL, MESSAGE, ...) \
if (LEVEL <= log_level) printf("|" STRINGIZE_EVALUATED(LEVEL) "|`" /* [...] */);
log_level = DEBUG;
log(INFO, "Bonjour"); // Logged
log(DEBUG, "Hello"); // Logged
log(TRACE, "Gunten tag"); // Not logged
Something like that, right ?
We have to be careful when a macro expands to more than a single statement, because calling a macro may look like a single statement, so users may omit braces in conditions:
1#include <fcntl.h> // open
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define log(LEVEL, MESSAGE, ...) if (LEVEL <= threshold) printf("[" #LEVEL "] " MESSAGE "\n" __VA_OPT__(,) __VA_ARGS__)
8
9enum log_level
10{
11 ERROR,
12 INFO,
13 DEBUG
14};
15
16enum log_level threshold = INFO;
17
18int main()
19{
20 int fd;
21 const char* filename = "inexistant.txt";
22
23 fd = open(filename, O_RDONLY);
24 log(DEBUG, "File descriptor: %i", fd);
25
26 if (fd < 0)
27 log(DEBUG, "Unable to open %s: %s", filename, strerror(errno));
28 else
29 log(INFO, "Successfully opened %s", filename);
30
31 if (fd > 0)
32 log(INFO, "Valid FD: %i", fd);
33 else if (fd == 0)
34 log(ERROR, "Zero FD !?");
35 else
36 log(ERROR, "Open failed (fd=%i) and set errno to %i: %s", fd, errno, strerror(errno));
37}
1#include <fcntl.h> // open
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define log(LEVEL, MESSAGE, ...) if (LEVEL <= threshold) printf("[" #LEVEL "] " MESSAGE "\n" __VA_OPT__(,) __VA_ARGS__)
8
9enum log_level
10{
11 ERROR,
12 INFO,
13 DEBUG
14};
15
16enum log_level threshold = INFO;
17
18int main()
19{
20 int fd;
21 const char* filename = "inexistant.txt";
22
23 fd = open(filename, O_RDONLY);
24 log(DEBUG, "File descriptor: %i", fd);
25
26 if (fd < 0)
27 log(DEBUG, "Unable to open %s: %s", filename, strerror(errno));
28 else
29 log(INFO, "Successfully opened %s", filename);
30
31 if (fd > 0)
32 log(INFO, "Valid FD: %i", fd);
33 else if (fd == 0)
34 log(ERROR, "Zero FD !?");
35 else
36 log(ERROR, "Open failed (fd=%i) and set errno to %i: %s", fd, errno, strerror(errno));
37}
enum log_level
{
ERROR,
INFO,
DEBUG
};
enum log_level threshold = INFO;
int main()
{
int fd;
const char* filename = "inexistant.txt";
fd = open(filename, 00);
if (DEBUG <= threshold)
printf("["
"DEBUG"
"] "
"File descriptor: %i"
"\n",
fd);
if (fd < 0)
if (DEBUG <= threshold)
printf("["
"DEBUG"
"] "
"Unable to open %s: %s"
"\n",
filename,
strerror((*__errno_location())));
else if (INFO <= threshold)
printf("["
"INFO"
"] "
"Successfully opened %s"
"\n",
filename);
if (fd > 0)
if (INFO <= threshold)
printf("["
"INFO"
"] "
"Valid FD: %i"
"\n",
fd);
else if (fd == 0)
if (ERROR <= threshold)
printf("["
"ERROR"
"] "
"Zero FD !?"
"\n");
else if (ERROR <= threshold)
printf("["
"ERROR"
"] "
"Open failed (fd=%i) and set errno to %i: %s"
"\n",
fd,
(*__errno_location()),
strerror((*__errno_location())));
}
[INFO] Successfully opened inexistant.txt
The output is not what was expected, can you see what’s wrong in the preprocessed tab ?
What’s wrong ?
Let’s use the simplest example possible:
#define M A;B;C
if (cond)
M;
expands to:
if (cond)
A;
B;
C;
In our case:
#define M if (cond2) A
if (cond1)
M;
else
M;
expands to:
if (cond1)
if (cond2)
A;
else if (cond2)
A;
“That’s why I always put curly braces in my conditions” I hear you say. Fair enough. But there is a simple way to avoid this pitfall without forcing a coding style on the users.
First attempt: adding braces in the macro
#define log(LEVEL, ...) { if (LEVEL <= threshold) printf(__VA_ARGS__); }
Full code
1#include <fcntl.h> // open
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define log(LEVEL, MESSAGE, ...) \
8 { \
9 if (LEVEL <= threshold) \
10 printf("[" #LEVEL "] " MESSAGE "\n" __VA_OPT__(,) __VA_ARGS__); \
11 }
12
13enum log_level
14{
15 ERROR,
16 INFO,
17 DEBUG
18};
19
20enum log_level threshold = INFO;
21
22int main()
23{
24 int fd;
25 const char* filename = "inexistant.txt";
26
27 fd = open(filename, O_RDONLY);
28 log(DEBUG, "File descriptor: %i", fd);
29
30 if (fd < 0)
31 log(DEBUG, "Unable to open %s: %s", filename, strerror(errno))
32 else
33 log(INFO, "Successfully opened %s", filename);
34
35 if (fd > 0)
36 log(INFO, "Valid FD: %i", fd)
37 else if (fd == 0)
38 log(ERROR, "Zero FD !?")
39 else
40 log(ERROR, "Open failed (fd=%i) and set errno to %i: %s", fd, errno, strerror(errno));
41}
1#include <fcntl.h> // open
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define log(LEVEL, MESSAGE, ...) \
8 { \
9 if (LEVEL <= threshold) \
10 printf("[" #LEVEL "] " MESSAGE "\n" __VA_OPT__(,) __VA_ARGS__); \
11 }
12
13enum log_level
14{
15 ERROR,
16 INFO,
17 DEBUG
18};
19
20enum log_level threshold = INFO;
21
22int main()
23{
24 int fd;
25 const char* filename = "inexistant.txt";
26
27 fd = open(filename, O_RDONLY);
28 log(DEBUG, "File descriptor: %i", fd);
29
30 if (fd < 0)
31 log(DEBUG, "Unable to open %s: %s", filename, strerror(errno))
32 else
33 log(INFO, "Successfully opened %s", filename);
34
35 if (fd > 0)
36 log(INFO, "Valid FD: %i", fd)
37 else if (fd == 0)
38 log(ERROR, "Zero FD !?")
39 else
40 log(ERROR, "Open failed (fd=%i) and set errno to %i: %s", fd, errno, strerror(errno));
41}
enum log_level
{
ERROR,
INFO,
DEBUG
};
enum log_level threshold = INFO;
int main()
{
int fd;
const char* filename = "inexistant.txt";
fd = open(filename, 00);
{
if (DEBUG <= threshold)
printf("["
"DEBUG"
"] "
"File descriptor: %i"
"\n",
fd);
};
if (fd < 0)
{
if (DEBUG <= threshold)
printf("["
"DEBUG"
"] "
"Unable to open %s: %s"
"\n",
filename,
strerror((*__errno_location())));
}
else
{
if (INFO <= threshold)
printf("["
"INFO"
"] "
"Successfully opened %s"
"\n",
filename);
};
if (fd > 0)
{
if (INFO <= threshold)
printf("["
"INFO"
"] "
"Valid FD: %i"
"\n",
fd);
}
else if (fd == 0)
{
if (ERROR <= threshold)
printf("["
"ERROR"
"] "
"Zero FD !?"
"\n");
}
else
{
if (ERROR <= threshold)
printf("["
"ERROR"
"] "
"Open failed (fd=%i) and set errno to %i: %s"
"\n",
fd,
(*__errno_location()),
strerror((*__errno_location())));
};
}
[ERROR] Open failed (fd=-1) and set errno to 2: No such file or directory
Solves our immediate problem, but introduces another. Can you see it ?
What’s wrong ?
#define M { A;B;C; }
if (cond)
M;
else
D;
expands to:
if (cond)
{
A;
B;
C;
}
;
else
D;
which doesn’t compile, because of the extra statement between the if and the else.
A solution is to not put a ; at the end of the line:
if (cond)
M
else
D;
This compiles fine, but introduces an inconsistant syntax. It will not be understood by you text editor, that will become crazy and add indent all code after that.
OK so we would like a way:
to group several statements in a block
follow it with a
;but such that it does not add an extra statement
Sounds impossible ?
On a completely unrelated note, did you know about the do while loop ? It’s similar to while but evalutates its condition after an iteration, which implies that it iterates at least once.
Its syntax is :
do {
/* statements */
} while (/* condition */);
Wait, is that a ; that doesn’t add a statement at the end ? And it iterates at least once ? Well, if that’s not proof that there is an Intelligent Designer, I don’t know what is.
Second attempt: Using “do while”
#define log(LEVEL, ...) do { if (LEVEL <= threshold) printf(__VA_ARGS__); } while (false);
1#include <fcntl.h> // open
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define log(LEVEL, MESSAGE, ...) \
8 do \
9 { \
10 if (LEVEL <= threshold) \
11 printf("[" #LEVEL "] " MESSAGE "\n" __VA_OPT__(,) __VA_ARGS__); \
12 } while (0)
13
14enum log_level
15{
16 ERROR,
17 INFO,
18 DEBUG
19};
20
21enum log_level threshold = INFO;
22
23int main()
24{
25 int fd;
26 const char* filename = "inexistant.txt";
27
28 fd = open(filename, O_RDONLY);
29 log(DEBUG, "File descriptor: %i", fd);
30
31 if (fd < 0)
32 log(DEBUG, "Unable to open %s: %s", filename, strerror(errno));
33 else
34 log(INFO, "Successfully opened %s", filename);
35
36 if (fd > 0)
37 log(INFO, "Valid FD: %i", fd);
38 else if (fd == 0)
39 log(ERROR, "Zero FD !?");
40 else
41 log(ERROR, "Open failed (fd=%i) and set errno to %i: %s", fd, errno, strerror(errno));
42}
1#include <fcntl.h> // open
2
3#include <errno.h> // errno
4#include <stdio.h> // printf
5#include <string.h> // strerror
6
7#define log(LEVEL, MESSAGE, ...) \
8 do \
9 { \
10 if (LEVEL <= threshold) \
11 printf("[" #LEVEL "] " MESSAGE "\n" __VA_OPT__(,) __VA_ARGS__); \
12 } while (0)
13
14enum log_level
15{
16 ERROR,
17 INFO,
18 DEBUG
19};
20
21enum log_level threshold = INFO;
22
23int main()
24{
25 int fd;
26 const char* filename = "inexistant.txt";
27
28 fd = open(filename, O_RDONLY);
29 log(DEBUG, "File descriptor: %i", fd);
30
31 if (fd < 0)
32 log(DEBUG, "Unable to open %s: %s", filename, strerror(errno));
33 else
34 log(INFO, "Successfully opened %s", filename);
35
36 if (fd > 0)
37 log(INFO, "Valid FD: %i", fd);
38 else if (fd == 0)
39 log(ERROR, "Zero FD !?");
40 else
41 log(ERROR, "Open failed (fd=%i) and set errno to %i: %s", fd, errno, strerror(errno));
42}
enum log_level
{
ERROR,
INFO,
DEBUG
};
enum log_level threshold = INFO;
int main()
{
int fd;
const char* filename = "inexistant.txt";
fd = open(filename, 00);
do
{
if (DEBUG <= threshold)
printf("["
"DEBUG"
"] "
"File descriptor: %i"
"\n",
fd);
} while (0);
if (fd < 0)
do
{
if (DEBUG <= threshold)
printf("["
"DEBUG"
"] "
"Unable to open %s: %s"
"\n",
filename,
strerror((*__errno_location())));
} while (0);
else
do
{
if (INFO <= threshold)
printf("["
"INFO"
"] "
"Successfully opened %s"
"\n",
filename);
} while (0);
if (fd > 0)
do
{
if (INFO <= threshold)
printf("["
"INFO"
"] "
"Valid FD: %i"
"\n",
fd);
} while (0);
else if (fd == 0)
do
{
if (ERROR <= threshold)
printf("["
"ERROR"
"] "
"Zero FD !?"
"\n");
} while (0);
else
do
{
if (ERROR <= threshold)
printf("["
"ERROR"
"] "
"Open failed (fd=%i) and set errno to %i: %s"
"\n",
fd,
(*__errno_location()),
strerror((*__errno_location())));
} while (0);
}
[ERROR] Open failed (fd=-1) and set errno to 2: No such file or directory
Success !
Recap#
In this chapter we’ve learned:
Adjacent literal strings are concatenated automatically at compile-time
Logs can be enriched with the magic constants
__FILE__,__func__and__LINE__Function-like macros can be variadic, allowing zero or more extra arguments
The extra arguements can be pasted with
__VA_ARGS__And
__VA_OPT__()can be used to remove characters when zero extra arguments are passed
The
#operator can create a string literal from anythingBut it affects how macro arguments are expanded
As a consequence when the arguments are macros themselves a wrapper may be used to force expansion