diff options
| author | Sebastiano Tronto <sebastiano@tronto.net> | 2024-06-20 15:40:29 +0200 |
|---|---|---|
| committer | Sebastiano Tronto <sebastiano@tronto.net> | 2024-06-20 15:40:29 +0200 |
| commit | a3f35dbc0419ecb5fa3f346d34a90a3a5116acc3 (patch) | |
| tree | cd66fd094a5ff7ec2ee8a0f28faefe1c411c5889 | |
| parent | 1bcb4bfa744d0fe9c341724405b8344a97a402de (diff) | |
| download | sebastiano.tronto.net-a3f35dbc0419ecb5fa3f346d34a90a3a5116acc3.tar.gz sebastiano.tronto.net-a3f35dbc0419ecb5fa3f346d34a90a3a5116acc3.zip | |
Added blog post
| -rw-r--r-- | src/blog/2024-06-20-callback-log/callback-log.md | 197 |
1 files changed, 197 insertions, 0 deletions
diff --git a/src/blog/2024-06-20-callback-log/callback-log.md b/src/blog/2024-06-20-callback-log/callback-log.md new file mode 100644 index 0000000..8b2c87d --- /dev/null +++ b/src/blog/2024-06-20-callback-log/callback-log.md | |||
| @@ -0,0 +1,197 @@ | |||
| 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://stackoverflow.com/questions/14082476/what-is-the-best-way-for-giving-callback-for-logging). | ||
| 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! | ||
