callback-log.md (7411B)
1 # Another C trick: flexible logging with callback functions 2 3 Working with C on my personal projects I enjoy complete freedom: I 4 don't have to follow existing conventions, I don't have to bend my 5 code to fit into an existing codebase, I can re-organize the program's 6 structure whenever I feel like. On the other hand, I don't get to 7 learn well-known good practices that were invented by whose who 8 beat their heads against the wall before me. 9 10 Sometimes, through a lot of wall-headbanging, I get to re-invent 11 these good practices by myself. Some time ago I wrote about 12 [using macros to make functions testable](../2023-11-14-test-visibility-c-macro). 13 Now it is time for another trick: using a 14 [callback function](https://en.wikipedia.org/wiki/Callback_(computer_programming)) 15 for logging! 16 17 ## The problem 18 19 I am working on a new version of [nissy](https://nissy.tronto.net), 20 a Rubik's cube solver with some extra functionalities that I and a 21 few others use. The code is public but I won't link it here for 22 now; it is not ready and many things will likely change by the time 23 you read this post. 24 25 One thing I decided to do was organizing the code as a library that 26 can be used by other programs to provide user-facing functionalities. 27 In other words, the main code does not have a `main()` function. 28 Other programs that use this code as a library include or may include 29 in the future: 30 31 * A testing utility / framework 32 * A command line interface 33 * A graphical interface (tentative) 34 35 As a consequence, the library itself should avoid using standard 36 input and output - that would be fine for the CLI interface, but 37 useless for the GUI. All the necessary information is exchanged 38 between the library and the client code via function return values 39 and parameters, including `char *` buffers for text output. 40 This also means I can get rid of `stdio.h` from my library code. 41 42 However, sometimes it is useful to see some logging info, especially 43 when debugging. For this reason, I have hidden an `#include <stdio.h>` 44 behind the compile-time option `#ifdef DEBUG`. 45 46 This means so far I could only see log information when building 47 in debug mode. But I have recently realized that this is too limiting: 48 even in the user-facing version of this program, long-running queries 49 could benefit from more frequent output before the response has been 50 calculated. But how can I do this without using `stdio`? 51 52 ## Brainstorming 53 54 Problem solving is full of dead ends and wasted brain-cycles. Before 55 I present to you the clever solution I found like I am some kind 56 of coding guru, let's see some of the bad ideas that I came up with 57 and discarded. 58 59 ### More macros 60 61 If I can hide debug logging behind a compile-time macro, why not 62 doing it for logging in general? I could split up the logging from 63 the other debug stuff and let the programmer (i.e. me) choose at 64 build time whether to have logs or not. 65 66 But this is not great. First of all, I don't like the idea of making 67 the build system more complex, I think it makes the code less 68 portable. Secondly, it is less flexible, because it limits the 69 options to what I decide right now. Of course I could add more stuff 70 later as needed, but this implies more coupling between the library 71 and the client. 72 73 ### Use `char *` buffers 74 75 Since some information is exchanged via `char *` output parameters, 76 the same could be done for logging information. This is very flexible, 77 because it allows the caller to do whatever they want with the log 78 output. But passing a "log buffer" parameter to every function call, 79 which is likely to be the same for the whole program, is annoying 80 and feels redundant. Moreover, reading this information off the the 81 buffer in real time is very complicated. 82 83 ### Custom `FILE *` stream 84 85 If I log the information to 86 [standard error](https://en.wikipedia.org/wiki/Stderr) using 87 `fprintf(stderr, ...)`, perhaps replacing `stderr` with a custom 88 `FILE *` object could do the trick. It limits the log messages to 89 be written to a file, but in the UNIX world *almost* everything 90 is a file. This trick may not be the most portable, but it is 91 certainly quite flexible. 92 93 But how would the programmer set this custom stream? There must be 94 a way to do it with macros, but then we have the same problems of 95 the first idea. Alternatively, I could define a global `FILE *` 96 variable and add to my interface to let the caller set this variable... 97 98 And this brought me to the final idea: if I can set a global variable 99 via a function call, why not make this variable a pointer to a 100 function? 101 102 ## The solution 103 104 The solution I settled for is the following. 105 106 In the main source file `mylib.c` I define a global function pointer 107 108 ``` 109 void (*mylib_log)(const char *, ...); 110 ``` 111 112 This pointer will be used to call the function that prints the log. 113 By default it is unset (NULL), which I choose to interpret as "no 114 logs should be printed". I used the dots `...` because I wanted 115 this function to be 116 [variadic](https://en.wikipedia.org/wiki/Variadic_function), just 117 like the classic `printf()`. 118 119 After this declaration I have some wrapper code that checks if the 120 logger function is set before calling it: 121 122 ``` 123 #define LOG(...) if (mylib_log != NULL) mylib_log(__VA_ARGS__); 124 ``` 125 126 The macro above uses `__VA_ARGS__` to refer to the list of arguments 127 denoted by the three dots. Now to show a log message I can do: 128 129 ``` 130 void do_thing(int a, int b) { 131 int x = compute(a, b); 132 133 LOG("Computed value %d\n", x) 134 135 return x; 136 } 137 ``` 138 139 Finally, there is a public function that lets the user of the 140 library set the logger function: 141 142 ``` 143 void mylib_setlogger(void (*f)(const char *, ...)) { 144 mylib_log = f; 145 } 146 ``` 147 148 And that's it! Using this setup is pretty simple. For example, for my unit 149 tests I have something like this: 150 151 ``` 152 #include <stdarg.h> /* For va_list and related functions */ 153 154 void log_stderr(const char *str, ...) 155 { 156 va_list args; 157 158 va_start(args, str); 159 vfprintf(stderr, str, args); 160 va_end(args); 161 } 162 163 int main(void) { 164 mylib_setlogger(log_stderr); 165 run_test(); 166 return 0; 167 } 168 ``` 169 170 The function `vfprintf()` is a version of `fprintf()` that takes a 171 [`va_list`](https://en.cppreference.com/w/c/variadic/va_list) 172 argument instead of an old-style parameter list. This is the 173 standard way to pass on variadic function arguments, as far as I 174 know. In case you did not know, `fprintf()` is a version of 175 `printf()` that prints to a given stream - in this case, `stderr`. 176 177 Now if I ever get to implementing a GUI, all I have to do to show 178 `mylib`'s logs is implementing a function `log_to_gui()` that shows 179 the given text somewhere, and call a `mylib_setlogger(log_to_gui)` 180 at the start of the program. Neat! 181 182 ## Conclusion 183 184 When I code for fun, I definitely enjoy coming up with my own 185 solution for problems like this, even if the solution already exists 186 somewhere. I also think that re-inventing standard practices like 187 this is making me a better programmer, because after struggling 188 with it myself I understand the practices better and I appreciate 189 them more. 190 191 This time in particular I learnt how to implement variadic functions, 192 and a bit of their 193 [history](https://retrocomputing.stackexchange.com/questions/20512/how-did-varargs-in-c-develop). 194 I am still not sure if this will work well when I end up using 195 this library in a non-C project. Is it even possible to call C 196 variadic functions from other languages? Will I have to provide a 197 logger that takes a `va_list` instead? I guess I'll find out!