Exception like stack trace in pure C

All of us have seen stack traces printed out after an exception has been thrown.

Java:

Exception in thread "main" java.lang.NullPointerException
        at com.example.myproject.Book.getTitle(Book.java:16)
        at com.example.myproject.Author.getBookTitles(Author.java:25)
        at com.example.myproject.Bootstrap.main(Bootstrap.java:14)

Python:

Traceback (most recent call last):
  File "test.py", line 8, in b
    c()
  File "test.py", line 13, in c
    assert False
AssertionError

You may find a plenty of information about other languages online.

Stack traces are almost always helpful when debugging. But what if exceptions just don't exist in the language or are forbidden? Well, I don't sympathize C++ exceptions and I don't appreciate exceptions over error codes in other languages, but this is out of the scope of the blog post.

So, let's be more specific. We are in the pure C world. We can't use exceptions. Now what? Do something ugly like:

1. printf("OMG, something happened\n");
2. return;

What if we need to finish executing the program if that something happens?

1. char* ar = malloc(23423423);
2. if(ar == NULL)
3. {
4.  printf("oh, ar can't be allocated\n");
5.  exit(errorcode);
6. }

What if there are a number of functions where ar can be allocated (not the same ar, but just local to function ar)? What if we reuse ar in such a way that it is assigned to a different variable and that malloced again, or realloced? What if we want to easily weed errors out of a normal output? Oh, we could use

1. fprintf(stderr, "my error");

But what if we now want to change output from stderr to another stream? Or what if we want a uniform format for all of our errors? Or what if we just want to track our error from the origin all the way up to the place where it was called from? Imagine an XML or Json parser which blows up somewhere in a node parsing? What will that error from inside the depths of the parser tell you? Nothing at all, it is generic. It would be much lovelier to see who called that parser and with what arguments. This is where stack trace would be handy. And here is what we are aiming for in C:

Error: example.c:35 (my_function) - [0000001b] custom error
 ----> someFile.c:50 (super_hero_function) - [0000001b]
 ----> main.c:163 (main) - [00000001]

This is an example of a proper stack trace. It has an origin in example.c::my_function() and it traces all the way back to main.c::main() through someFile.c::super_hero_function(), but it also outputs a return result of each of those functions on its way.

This is a code which serves this kind of output:

1. //
2. // developed by Sergey Markelov (09-2013)
3. //
4. #ifndef GENERIC_LOGGER
5. #define GENERIC_LOGGER
7. #include <stdio.h>
9. extern FILE *errStream;
10. extern FILE *outStream;
12. #define ERR_STREAM              errStream
13. #define OUT_STREAM              outStream
15. #define ERROR_PREFIX            "Error: "
16. #define STANDARD_PREFIX         ""
17. #define ERROR_CONTINUE_PREFIX   " ----> "
19. #define STRINGIFY(x) #x
20. #define TOSTRING(x)  STRINGIFY(x)
22. #define _LOG(stream, prefix, format, ...) \
23.     { fprintf(stream, "%s (%s) - " format "\n", prefix __FILE__ ":" TOSTRING(__LINE__), __func__, ##__VA_ARGS__); }
25. #define LogError(format, ...) \
26.     { _LOG(ERR_STREAM, ERROR_PREFIX, format, ##__VA_ARGS__); }
28. #define Log(format, ...) \
29.     { _LOG(OUT_STREAM, STANDARD_PREFIX, format, ##__VA_ARGS__); }
31. //
32. // @brief this macro originates the error. Functions down the stack should use
33. //        ContinueErrorEx() or ContinueError() to propagate the error behavior.
34. //
35. //        In the log it will look like:
36. //
37. //        Error: example.c:35 (my_function) - [0000001b] custom error
38. //         ----> someFile.c:50 (process) - [0000001b]
39. //         ----> main.c:163 (main) - [00000001]
40. //
41. // @param result the value which needs to be logged
42. // @param resultSpecifier printf() specifier for the result. Ex. "%d" means @c result is of type @c int
43. //        you can also use "0x%08x" to make it Hex
44. // @param format, ... - custom formatted message
45. //
46. #define OriginateErrorEx(result, resultSpecifier, format, ...) \
47.     { LogError("[" resultSpecifier "] " format, result, ##__VA_ARGS__); return result; }
49. //
50. // @see OriginateErrorEx
51. //
52. #define OriginateError(result, resultSpecifier) \
53.     { LogError("[" resultSpecifier "] ", result); return result; }
55. //
56. // @see OriginateErrorEx
57. //
58. #define ContinueErrorEx(result, resultSpecifier, format, ...) \
59.     { _LOG(ERR_STREAM, ERROR_CONTINUE_PREFIX, \
60.            "[" resultSpecifier "] " format, result, ##__VA_ARGS__); return result; }
62. //
63. // @see OriginateErrorEx
64. //
65. #define ContinueError(result, resultSpecifier) \
66.     { _LOG(ERR_STREAM, ERROR_CONTINUE_PREFIX, \
67.            "[" resultSpecifier "] ", result); return result; }
69. #endif

and here is an example usage:

1. //
2. // developed by Sergey Markelov (09-2013)
3. //
5. #include "logger.h"
7. //
8. // defined in logger.h
9. //
10. FILE *errStream;
11. FILE *outStream;
13. static int blowUp()
14. {
15.     if(ftell(NULL) == -1) OriginateErrorEx(-1, "%d", "ftell() caused errno %d - '%s'", errno, strerror(errno));
16.     return 0;
17. }
19. int main(void)
20. {
21.     int res;
23.     errStream = stderr;
24.     outStream = stdout;
26.     res = blowUp();
27.     if(res != 0) ContinueError(res, "%d");
29.     return 0;
30. }

ftell will fail on NULL file stream and this stack trace will be outputed to stderr:

Error: main.c:15 (blowUp) - [-1] ftell() caused errno [3450] - 'Descriptor is not valid'
 ----> main.c:27 (main) - [-1]

As you may see we have everything we need to understand what exactly happened and when and who caused that error to happen.

In the code above I used variadic macros. That version is GNU specific and you can't find it in a compiler from MS. Clang supports it out of the box unless you specify to warn about that with -Wgnu. GCC, of course, supports it.

When I say that MS doesn't support variadic macros, that is not to be confused with the full GNU support when you separate format part from the actual variadic part. This way, we can do tricky things like that:

1. #define _LOG(stream, prefix, format, ...) \
2.     { fprintf(stream, "%s (%s) - " format "\n", prefix __FILE__ ":" TOSTRING(__LINE__), __func__, ##__VA_ARGS__); }

that is the most generic logging function from the above. It constructs the format string concatenating
"%s (%s) - " with format which is passed as an argument to a macro.

Also I used __LINE__ stringification discussed here.

All that logging mechanism is pure C style macros, thus the original code after preprocessing will be as fast as ordinary fprintf's here and there in your code. So, at the run time we pay no extra cost for a lot of extra functionality!

And all you have to do to use this logging mechanism is to include the h file and to declare errStream and outStream. You can link those to stderr and stdout. Or you can fopen a file and link the stream to there.