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:
printf("OMG, something happened\n");
return;
What if we need to finish executing the program if that
something happens?
char* ar = malloc(23423423);
if(ar == NULL)
{
printf("oh, ar can't be allocated\n");
exit(errorcode);
}
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
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:
//
// developed by Sergey Markelov (09-2013)
//
#ifndef GENERIC_LOGGER
#define GENERIC_LOGGER
#include <stdio.h>
extern FILE *errStream;
extern FILE *outStream;
#define ERR_STREAM errStream
#define OUT_STREAM outStream
#define ERROR_PREFIX "Error: "
#define STANDARD_PREFIX ""
#define ERROR_CONTINUE_PREFIX " ----> "
#define STRINGIFY(x) #x
#define TOSTRING(x) STRINGIFY(x)
#define _LOG(stream, prefix, format, ...) \
{ fprintf(stream, "%s (%s) - " format "\n", prefix __FILE__ ":" TOSTRING(__LINE__), __func__, ##__VA_ARGS__); }
#define LogError(format, ...) \
{ _LOG(ERR_STREAM, ERROR_PREFIX, format, ##__VA_ARGS__); }
#define Log(format, ...) \
{ _LOG(OUT_STREAM, STANDARD_PREFIX, format, ##__VA_ARGS__); }
//
// @brief this macro originates the error. Functions down the stack should use
// ContinueErrorEx() or ContinueError() to propagate the error behavior.
//
// In the log it will look like:
//
// Error: example.c:35 (my_function) - [0000001b] custom error
// ----> someFile.c:50 (process) - [0000001b]
// ----> main.c:163 (main) - [00000001]
//
// @param result the value which needs to be logged
// @param resultSpecifier printf() specifier for the result. Ex. "%d" means @c result is of type @c int
// you can also use "0x%08x" to make it Hex
// @param format, ... - custom formatted message
//
#define OriginateErrorEx(result, resultSpecifier, format, ...) \
{ LogError("[" resultSpecifier "] " format, result, ##__VA_ARGS__); return result; }
//
// @see OriginateErrorEx
//
#define OriginateError(result, resultSpecifier) \
{ LogError("[" resultSpecifier "] ", result); return result; }
//
// @see OriginateErrorEx
//
#define ContinueErrorEx(result, resultSpecifier, format, ...) \
{ _LOG(ERR_STREAM, ERROR_CONTINUE_PREFIX, \
"[" resultSpecifier "] " format, result, ##__VA_ARGS__); return result; }
//
// @see OriginateErrorEx
//
#define ContinueError(result, resultSpecifier) \
{ _LOG(ERR_STREAM, ERROR_CONTINUE_PREFIX, \
"[" resultSpecifier "] ", result); return result; }
#endif
and here is an example usage:
//
// developed by Sergey Markelov (09-2013)
//
#include "logger.h"
//
// defined in logger.h
//
FILE *errStream;
FILE *outStream;
static int blowUp()
{
if(ftell(NULL) == -1) OriginateErrorEx(-1, "%d", "ftell() caused errno %d - '%s'", errno, strerror(errno));
return 0;
}
int main(void)
{
int res;
errStream = stderr;
outStream = stdout;
res = blowUp();
if(res != 0) ContinueError(res, "%d");
return 0;
}
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:
#define _LOG(stream, prefix, format, ...) \
{ 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.
