Channels ▼
RSS

Parallel

Logging In C++: Part 2


Using Line-level Logging Effectively

The implementation of this framework will be greatly simplified by using the new C++0x standard. Some of the features that are of interest here are implemented in the std::atomic<T> class, so there is no need to use the atomic_ops library anymore (memory barriers). Also the fact the static variables can be safely initialized dynamically, and the resulting code is thread safe is a big help.

I also compared the previous version of log FILE_LOG versus LOGMAN to see how big the overhead introduced by this mechanism is. The code executes same disabled log statements 100,000,000 times:


#include "logman.h"

int main(int argc, char* argv[])
{
    LogMan::Set("main3.cpp", 15, LogMan::DISABLED);
    const int count = 100000000;
    FILE_LOG(logINFO) << "Start file log";
    for (int i = 0; i != count; ++i)
    {
        FILE_LOG(logDEBUG) << "this is not executed";
    }
    FILE_LOG(logINFO) << "Start log man";
    for (int i = 0; i != count; ++i)
    {
        LOGMAN(logINFO) << "this is disabled too";
    }
    FILE_LOG(logINFO) << "End";
    return 0;
}

The test produces the following results:


$> log2-test3.1
- 18:34:38.796640 INFO: Start file log
- 18:34:40.199079 INFO: Start log man
- 18:34:42.191984 INFO: End

It took 1.4 sec to execute the first loop and 2.0 sec to execute the second loop. This means the overhead introduced by this mechanism is low, albeit measurable.

While this sample can be used for measuring the overhead, it is actually not a very good example of usage. Instead of enabling/disabling logging statements using Set() functions calls (which are very sensitive to the line number where the statement is located) it is better to directly change the logging level of the log statement itself (and perhaps recompile the code).

A better use of this framework is in conjunction with a means that efficiently enables/disables at runtime individual log statements. This can be done by starting a separate thread that periodically reads (for example every second) a file that specifies the file names, line numbers that identifies the log statements, and the corresponding values. That thread has a very low CPU load, since most of the time it does nothing and it sleeps. For example:


$> cat enabler.txt
file1.cpp,30,1
file2.cpp,49,0
file3.cpp,100,-1

By passing these values to the Set() function you can dynamically adjust the logging level of any individual log statement, and enabling the log statement at file file1.cpp:30 and disabling the log statement in file2.cpp:49.

To help generate this enabler.txt, file the Init() function could be print in the logfile itself the file names and the file numbers for all the local static variable added into the global map. It is then a simple task to create a simple GUI that parses the log file and extracts this information, and then gives us a way to create the enabler.txt file by just checking some buttons.

Conclusion

This article presents a simple way to change the logging level of an application at the line-level granularity. The method employed is efficient, and the interface presented to the programmer is easy to use. The upcoming C++0x standard will simplify the implementation and it will make it even simpler.

Related Article

Part 1 of this article can be found here.


Petru is a vice president for Morgan Stanley, where he works as a C++ senior programmer in investment banking. He can be contacted at petru.marginean@gmail.com.


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.
 

Video