Dr. Dobb's is part of the Informa Tech Division of Informa PLC

This site is operated by a business or businesses owned by Informa PLC and all copyright resides with them. Informa PLC's registered office is 5 Howick Place, London SW1P 1WG. Registered in England and Wales. Number 8860726.


Channels ▼
RSS

C/C++

Logging In C++


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.

In this article, I present a simple—but highly useful—logging framework that is typesafe, threadsafe (at line-level), efficient, portable, fine-grained, compact, and flexible. The complete source code, which works with Visual C++ 7.1, g++ 3.3.5, and CC 5.3 on Sun and other platforms, is available in the DDJ October 2007 zip file at www.ddj.com/code/.

In Part 2 of this article, I enhance this technique by providing more granularity.

The First Step

Let's take a first stab at a Log class. Listing One uses an std::ostringstream member variable called "os" to accumulate logged data. The Get() member function gives access to that variable. After all data is formatted, Log's destructor persists the output to the standard error. You use Log class like this:

Log().Get(logINFO) << "Hello " << username;

Executing this code creates a Log object with the logINFOx logging level, fetches its std::stringstream object, formats and accumulates the user-supplied data, and finally, persists the resulting string into the log file using exactly one call to fprintf().

Why flush during destruction? The last two steps are important because they confer threadsafety to the logging mechanism. The fprintf() function is threadsafe, so even if this log is used from different threads, the output lines won't be scrambled. According to gnu.org/software/libc/manual/html_node/Streams-and-Threads.html:

Listing One

// Log, version 0.1: a simple logging class
enum TLogLevel {logERROR, logWARNING, logINFO, logDEBUG, logDEBUG1,
logDEBUG2, logDEBUG3, logDEBUG4};
class Log
{
public:
   Log();
   virtual ~Log();
   std::ostringstream& Get(TLogLevel level = logINFO);
public:
   static TLogLevel& ReportingLevel();
protected:
   std::ostringstream os;
private:
   Log(const Log&);
   Log& operator =(const Log&);
private:
   TLogLevel messageLevel;
};
std::ostringstream& Log::Get(TLogLevel level)
{
   os << "- " << NowTime();
   os << " " << ToString(level) << ": ";
   os << std::string(level > logDEBUG ? 0 : level - logDEBUG, '\t');
   messageLevel = level;
   return os;
}
Log::~Log()
{
   if (messageLevel >= Log::ReportingLevel())
   {
      os << std::endl;
      fprintf(stderr, "%s", os.str().c_str());
      fflush(stderr);
   }
}

The POSIX Standard requires that by default the stream operations are atomic...issuing two stream operations for the same stream in two threads at the same time will cause the operations to be executed as if they were issued sequentially. The buffer operations performed while reading or writing are protected from other uses of the same stream. To do this, each stream has an internal lock object that has to be (implicitly) acquired before any work can be done.

Before moving on to a more efficient implementation, let's write code to insert tabs in proportion to the logging level, and append an std::endl to each chunk of text. This makes the log line oriented and easy to read by both humans and machines. Here's the relevant code:

Log::ReportingLevel() = logDEBUG2;
const int count = 3;
Log().Get(logDEBUG) << "A loop with "    << count << " iterations";
for (int i = 0; i != count; ++i)
{
   Log().Get(logDEBUG1)        << "the counter i = " << i;
}

which outputs:

- 22:25:23.643 DEBUG: 	A loop with 3 iterations
- 22:25:23.644 DEBUG1: 	the counter i = 0
- 22:25:23.645 DEBUG1: 	the counter i = 1
- 22:25:23.645 DEBUG1: 	the counter i = 2

Indentation makes the logging more readable. More leading tabs imply a more detailed level of logging.


Related Reading


More Insights






Currently we allow the following HTML tags in comments:

Single tags

These tags can be used alone and don't need an ending tag.

<br> Defines a single line break

<hr> Defines a horizontal line

Matching tags

These require an ending tag - e.g. <i>italic text</i>

<a> Defines an anchor

<b> Defines bold text

<big> Defines big text

<blockquote> Defines a long quotation

<caption> Defines a table caption

<cite> Defines a citation

<code> Defines computer code text

<em> Defines emphasized text

<fieldset> Defines a border around elements in a form

<h1> This is heading 1

<h2> This is heading 2

<h3> This is heading 3

<h4> This is heading 4

<h5> This is heading 5

<h6> This is heading 6

<i> Defines italic text

<p> Defines a paragraph

<pre> Defines preformatted text

<q> Defines a short quotation

<samp> Defines sample computer code text

<small> Defines small text

<span> Defines a section in a document

<s> Defines strikethrough text

<strike> Defines strikethrough text

<strong> Defines strong text

<sub> Defines subscripted text

<sup> Defines superscripted text

<u> Defines underlined text

Dr. Dobb's encourages readers to engage in spirited, healthy debate, including taking us to task. However, Dr. Dobb's moderates all comments posted to our site, and reserves the right to modify or remove any content that it determines to be derogatory, offensive, inflammatory, vulgar, irrelevant/off-topic, racist or obvious marketing or spam. Dr. Dobb's further reserves the right to disable the profile of any commenter participating in said activities.

 
Disqus Tips To upload an avatar photo, first complete your Disqus profile. | View the list of supported HTML tags you can use to style comments. | Please read our commenting policy.