Logging In C++

Final Tips on Using Log

I've been using an interesting technique that lets you compare different runs by actually diff'ing the log files from each run. This is especially useful when you have no idea what could be wrong and why you get different results when running the same code:

On different platforms (Linux versus Windows). On different versions of the same the same platform (RHEL3 vs. RHEL4). With different compiler settings (debug versus optimize).

Just turn the verbosity to maximum detail level (remember, because the logging is so light, you already have a lot of log statements on logDEBUGx in your code), run the application in the two different contexts, remove the timestamps from the log files (using, for instance, the sed program), and compare the two outputs. Even though the output files can be huge, it is the difference between them that matters, and that difference tends to be small and highly informative.

Another nice outcome of using this log framework was combining the logging of multiple different applications (or multiple instances of a single application) in a single unique file. Just open the same file from several applications in append mode, and voila—nicely interleaved logs from various processes! The resulted log file is still meaningful and (on a decent operating system at least) preserves log lines as atomic units.

I've done some measurements to actually see how fast the runtime mechanism is (versus the compile time). The results turned out to be very good. I ran the same code in three different configurations:

off-INFO. log disabled at compile time, used as a base line. on-INFO. log enabled at compile time, disabled at runtime (using INFO level of detail). on-DEBUG4. log enabled at runtime and compile time (using DEBUG4 level of detail).

Each configuration was run multiple (20) times (to eliminate the possible random errors). Figure 1 and Table 1 illustrate the results. As you can see, the runtime performance (25.109 sec) matches the compile time (25.109 sec). That means you really will pay for logging only if you are going to use it.

[Click image to view at full size]

Figure 1: Log speed tests.

I found very useful in practice to also output the thread ID from where the output comes from along with the timestamp and logging level. This is a real help when reading a log file that comes from a multithreading application.

Petru is a vice president for Morgan Stanley, where he works as a C++ senior programmer in investment banking. He can be contacted at [email protected].

Related Article

Part 2 of this article can be found here.