Logging In C++: Part 2

Logging is a critical technique for troubleshooting and maintaining software systems. It's simple, provides information without requiring knowledge of programming language, and does not require specialized tools. Logging is a useful means to figure out if an application is actually doing what it is supposed to do. Good logging mechanisms can save long debugging sessions and dramatically increase the maintainability of applications.

This article is a follow-up to Logging in C++. After having used the logging described therein for two years, I needed certain enhancements to it that improve logging granularity by a large margin: Each individual logging statement can be conveniently turned on and off without the need to recompile or even stop and restart the application.

The previous article presented a simple, yet powerful, logging framework in which each log statement has a specific level of detail associated with it. In that framework, the logging detail level depends on how important or interesting the logged information is. When the application runs, a log level is specified for entire application, so only the log statements at or below a specific detail level are enabled and displayed.

FILELog::ReportingLevel() = logINFO;
FILE_LOG(logINFO) << "This log statement is enabled";
FILE_LOG(logDEBUG) << "This log statement is disabled";

The recommended use of the log level is to keep it at a high level of detail for as long as the code is not mature enough, or while you are hunting for a bug. For example, logging the content of some variables makes sense while you are still trying to figure out whether the application works fine, but it just generates logging noise after that. Once the code looks like is doing the right thing, you may want to progressively reduce the logging detail (i.e., level) to finally ship with a relatively sparse logging level that allows post-mortem debugging without slowing down the application.

Assume the application you released went into some bad state and doesn't do what it is supposed to do. You'd like to crank the debugging level up rapidly, but if that requires some static configuration change and the restart of the application, reproducing the problem may be difficult. Also, increasing the log level would dramatically increase the amount of total logged data (since there are so many other log statements on that level), possibly making the application unusable in a production environment.

In this article, I show how you can efficiently "hot-enable" exactly the log statements believed relevant without having to stop and rerun the program. Once you get from the log file the clues you need to track down the issue, you can disable back the logging so you keep the log file at normal size -- all while the application is running. The complete source code and related files are available here.

Some Ingredients

In this section I introduce some techniques used for achieving our goal: Efficiently enabling/disabling the log statements with line-level granularity:

• Sharing data between threads using simple variables and no locking. A simple and efficient way to communicate between different threads is to use a shared global variable. You have to satisfy certain conditions:
  1. The reading/writing of data has to be atomic (using native machine word size).
  2. Reading/writing should be done using memory barriers (compile time/run time). The code will use such shared global variables to signal whether a given log statement should be enabled or disabled. One thread will set the variable with the desired value, while another thread will read it. There is no locking involved in reading the variable, so sharing these variables can be done very efficiently.
• Declaring static local variable inside for statements. You can define a static local variable on-the-fly, inside a for statement. For example:
  

  for (static int i = 0;;);
  

  
  is legal in C++, and the variable is visible only inside the for loop. By using these for loops the log statements can read these variables very efficiently, without any lookup.
• Declare local variable inside if statements. You can define a local variable on-the-fly, inside an if statement. For example:
  

  if (bool flag = false) ; else …
  

  
  This variable is visible only inside the if/else statement. The purpose of these if statements is only to make sure that the inner for loops are executed once at most.