PC Review


Reply
Thread Tools Rate Thread

Debug-Logging with conditional compile and config options

 
 
Marcel Müller
Guest
Posts: n/a
 
      27th Oct 2011
I have a multi-threaded application with a lot of debug logging. The
logging expressions call functions with [Conditional("DEBUG")], so
release builds are free of the overhead.

Now I need to enable/disable different kinds of log events in the
app.config. Of course, this only applies to the debug builds.

But the question is: how to check the conditions?

If I check this in the logging function, the function arguments are
already evaluated. Evaluating the function arguments is often more
expensive than the logging itself. So I need to check the condition
before the function call.

OK, so i need to write
if (Logger.DebugEnabled) Logger.Log(...);

But what happens in a release build where Logger.Log does not exist
because of the Conditional("DEBUG")? Is the condition still evaluated?


Marcel
 
Reply With Quote
 
 
 
 
Marcel Müller
Guest
Posts: n/a
 
      27th Oct 2011
On 27.10.2011 16:23, Peter Duniho wrote:
[...]
>> OK, so i need to write
>> if (Logger.DebugEnabled) Logger.Log(...);
>>
>> But what happens in a release build where Logger.Log does not exist
>> because of the Conditional("DEBUG")? Is the condition still evaluated?

>
> Honestly, the whole question smacks of premature optimization to me.


Yes, you are right.

> Logging involves i/o, which is painfully slow compared to practically
> anything else a CPU might do. So it's hard to see how it could actually
> be the case that "evaluating the function arguments" could be "more
> expensive than the logging itself". It'd have to be some pretty
> expensive evaluating going on.


The I/O is write back cached by the OS. This is not that critical as
long as it is not too much.

But some of the log entries calculate some complex aggregate information
over a deep data structure and pass the result as string to the logger.
This cases can really slow down some tasks by a factor 3.

> I'm also suspicious of the concern that logging methods impose
> significant enough overhead that [Conditional("DEBUG")] might provide a
> useful performance improvement.


The main improvement results from not evaluating the function arguments.
The condition check will probably not involve any noticeable overhead.


> Personally, my general preference is to just use .NET's built-in "trace"
> mechanism. It's not the simplest API, but it comes with app.config
> support and is efficient enough that it's used in all sorts of places in
> the .NET framework itself.


Unfortunately we have our own logging API in our company. This API has
some features needed here. The most important are that several
application instances can safely share the same log file and that the
API is implemented in several different platforms. So I have not the
option to use another tracing tool.

> If using my own logging framework, I would
> not worry about overhead until I had some specific performance
> measurements that I could compare with some specific performance goals
> that showed clearly the logging was producing a significant slowdown,


If I put comments in front of a dozen logging calls inside the
applications data cache then some UI actions are about 30-50% faster.
This is significant if the one that does the testing over and over waits
for 20 seconds instead of doing his work.

> and even then I would focus only on the specific performance issues found.


I focus on the different cache hit events for now. But I do not want to
remove the logging completely, because it already has been very helpful
in several cases.


> As an example, I did run across a significant performance problem in a
> logging system last year. But in that case, the problem was that the
> system included caller information as part of the logged output, which
> required a stack trace. The logging system was generating the stack
> trace whether or not the specific level of logging was enabled.


Currently we have no stack trace information unless we log an exception.
In the latter case the stack trace has been examined anyway, isn't it?


> Anyway, all that said: I would guess that the JIT compiler will be smart
> enough to remove logical test (e.g. "if" statements) if those test
> branch around blocks of code that are empty, if it can. Note that if the
> logical test involves calling a method that is not a simple property
> getter, the compiler may not be able to remove the call, because it has
> no way to know that the method call does not involve an important
> side-effect.


Currently I tested something like
/// <summary>Enable Debug-Logging</summary>
#if DEBUG
private static readonly bool EnableLog =
Logger.GetLoggingFlag("MyClass");
#else
private const bool EnableLog = false;
#endif
and
if (EnableLog) Logger.DebugEvent(...);

The performance is fine, but I get dozens of warnings about unreachable
code in release build - although DebugEvent has a ConditionalAttribute.
This is a bit annoying.


> If the test simply compares a field against some constant (and this may
> include a simple property that does the comparison, since those may be
> inlined and the JIT optimizer might do the branch removal after the
> inlining has been performed), then it's possible the IT compiler can
> remove the entire thing.


How can the JIT know that a field does not chance?


Marcel
 
Reply With Quote
Reply

Thread Tools
Rate This Thread
Rate This Thread:

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off
Trackbacks are On
Pingbacks are On
Refbacks are Off



Features
 

Advertising
 

Newsgroups
 


All times are GMT +1. The time now is 06:40 PM.