
I was inspired by the topic “
What code points you know? ” To write this topic, and I wanted to share this logger there, but the author asked “without fanaticism”, and wanted to see such tricks that would take no more than five or ten seconds to understand, I decided to bring this matter to a separate topic, because in a quick way you will not look at this.
A small but sometimes quite useful class will be considered, plus a small trick with macros that allows for the initial analysis of the call stack directly in stdout, while the program is running. Of course, the light did not come together with the light on stdout, and you can redirect at least to a file, at least somewhere else - I just demonstrate a general principle.
Immediately agree:
- macro abuse is evil
- there is nothing new and supernatural in this article, it will be understandable even to a beginner (it’s intended for them)
- This technique is of little use (or not applicable at all) in a multithreaded environment.
- implementation does not claim to be ideal, complete, and even more so unique
- this technique in no way replaces, but only complements the debugger
But if while writing a program you have repeatedly written something like printf (“Entering Foo () \ n”); to monitor the entrance to a particular function, then you came to the right place.
So, we will try to refine this printf (“Entering Foo () \ n”) and squeeze the maximum out of it. The first thing that comes to mind is to replace the manual typing of the function name with the predefined macro __FUNCTION__, which contains a string (ie, const shar *) with the name of the framing function:
')
printf("Entering %s()\n", __FUNCTION__);
And in order not to litter the code visually and not to create distractions when reading, hide this case under the macro:
#define LOG_TRACE printf("Entering %s()\n", __FUNCTION__);
Now if we have any Lapsevid code, then carefully arranging the LOG_TRACE macros at the beginning of each function, we get something like this:
#include <stdio.h> #define LOG_TRACE printf("Entering %s()\n", __FUNCTION__); void abc() { LOG_TRACE } void foo() { LOG_TRACE abc(); } void bar() { LOG_TRACE foo(); abc(); } int main(int argc, char* argv[]) { bar(); return 0; }
When it is executed, it will appear in the console.
Entering bar() Entering foo() Entering abc() Entering abc()
Already something. But a little. However, if we recall that in addition to the __FUNCTION__ macro, we have at least remarkable macros __FILE__ and __LINE__, then in addition to the function name, we can also output the file name and line number:
#define LOG_TRACE printf("Entering %s() (%s:%d)\n", __FUNCTION__, __FILE__, __LINE__);
Entering bar() (main.cpp:23) Entering foo() (main.cpp:18) Entering abc() (main.cpp:14) Entering abc() (main.cpp:14)
Already better, it’s immediately clear where to look for.
Let's not pull the cat by the tail and make it so that not only the input but also the output from the function is logged. At this stage, we will part with a cozy sishechka and move on to its plus-son.
What happens when we exit a function (and any other scope)? The stack is cleared of what was put into it in the function body (scope). Technically, not really cleaning, but only shifting the pointer to the top of the stack, but let's call it that, because we are interested in nothing more than the destruction of objects created on the stack when leaving the field of view, and therefore their destructors are caused.
So if we now replace the logger function with an object of similar behavior, we will be able to monitor not only the input to the function, but also the output from it.
Let's get the TraceLogger class, which in the constructor will report on entering the function, and in the destructor it is joyful to report on the exit.
TraceLogger.h:
class TraceLogger { public: TraceLogger(const char* fileName, const char* funcName, int lineNumber); ~TraceLogger(); private: const char* _fileName; const char* _funcName; }; #define LOG_TRACE TraceLogger traceLogger(__FILE__, __FUNCTION__, __LINE__);
Now behind the macro there is the creation of an object on the stack with the transfer of the file name, function name and line number to it in the constructor. The file names and functions, we will remember - will be useful in the destructor. In this case, you can not create copies of strings, but limit yourself to pointers to them, because the lifetime of the object is limited to the function body, and it is during this time interval that the lines in which the macros __FILE__ and __FUNCTION__ are developed during preprocessing remain valid.
The implementation of the methods is as follows:
TraceLogger.cpp:
TraceLogger::TraceLogger(const char* fileName, const char* funcName, int lineNumber) { _fileName = fileName; _funcName = funcName; std::cout << "Entering " << _funcName << "() - (" << _fileName << ":" << lineNumber << ")" << std::endl; } TraceLogger::~TraceLogger() { std::cout << "Leaving " << _funcName << "() - (" << _fileName << ")" << std::endl; }
And the conclusion, respectively, is:
Entering bar() - (main.cpp:19) Entering foo() - (main.cpp:14) Entering abc() - (main.cpp:10) Leaving abc() - (main.cpp) Leaving foo() - (main.cpp) Entering abc() - (main.cpp:10) Leaving abc() - (main.cpp) Leaving bar() - (main.cpp)
Looking at this, the phrase “It would be more indenting about it!” Spins in the language, isn't it? No problem! Let's get a static member of the class in which we will store the indented string (several spaces are stupid) and we will display it at the beginning of the log line. When creating a new instance (what happens when entering the next function), we will increase the indentation, and when it is destroyed (what happens when the function leaves), we will decrease it.
TraceLogger.h:
class TraceLogger { ... private: ... static std::string Indent; };
TraceLogger.cpp:
std::string TraceLogger::Indent; TraceLogger::TraceLogger(const char* fileName, const char* funcName, int lineNumber) { _fileName = fileName; _funcName = funcName; std::cout << Indent << "Entering " << _funcName << "() - (" << _fileName << ":" << lineNumber << ")" << std::endl; Indent.append(" "); } TraceLogger::~TraceLogger() { Indent.resize(Indent.length() - 2); std::cout << Indent << "Leaving " << _funcName << "() - (" << _fileName << ")" << std::endl; }
And now our conclusion looks like this:
Entering bar() - (main.cpp:19) Entering foo() - (main.cpp:14) Entering abc() - (main.cpp:10) Leaving abc() - (main.cpp) Leaving foo() - (main.cpp) Entering abc() - (main.cpp:10) Leaving abc() - (main.cpp) Leaving bar() - (main.cpp)
Hooray! Now, at any time during the execution of the program, you can visually see in which function we are at the moment and how we actually got there. Well, if something fell, then it is immediately visible exactly where (even before uncovering gdb and feeding him the crust).
What else can you do? Of course, disable all this disgrace in the release version:
TraceLogger.h:
... #ifdef DEBUG #define LOG_TRACE TraceLogger logger(__FILE__, __FUNCTION__, __LINE__); #else #define LOG_TRACE #endif
And now in the release version all our LOG_TRACE is banal empty. And in order to preserve the purity of the binary, you can bite the entire class altogether, by hiding both the advertisement and the implementation for #ifdef DEBUG - I will leave this for you to do it yourself. Like timestamps at the beginning of the line - they are also very useful.
That's all. I hope someone will be useful.
Happy coding!