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++


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.

on-DEBUG4 off-INFO on-INFO
AVERAGE 00:00:28.002 00:00:25.106 00:00:25.109
STDEV 0.0000029838 0.0000008605 0.0000014926

Table 1

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.


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.