Overhead associated with OutputDebugString in release build

Question

Is there a significant overhead associated with calling OutputDebugString in release build?

Washedup

Answer 1

Measured - 10M calls take about 50 seconds. I think it's significant overhead for unused functionality.

Using a macro can help get rid of this in release build:

#ifdef _DEBUG
    #define LOGMESSAGE( str ) OutputDebugString( str );
#else
    #define LOGMESSAGE( str )
#endif

Not only removes the calls, but also the parameters evaluation and the text strings are entirely removed and you'll not see them in the binary file.

Maryrose

Answer 2

I'm writing this long after this question has been answered, but the given answers miss a certain aspect:

OutputDebugString can be quite fast when no one is listening to its output. However, having a listener running in the background (be it DbgView, DBWin32, Visual Studio etc.) can make it more than 10 times slower (much more in MT environment). The reason being those listeners hook the report event, and their handling of the event is done within the scope of the OutputDebugString call. Moreover, if several threads call OutputDebugString concurrently, they will be synchronized. For more, see Watch out: DebugView (OutputDebugString) & Performance.

As a side note, I think that unless you're running a real-time application, you should not be that worried about a facility that takes 50 seconds to run 10M calls. If your log contains 10M entries, the 50 seconds wasted are the least of your problems, now that you have to somehow analyze the beast. A 10K log sounds much more reasonable, and creating that will take only 0.05 seconds as per sharptooth's measurement.

So, if your output is within a reasonable size, using OutputDebugString should not hurt you that much. However, have in mind a slowdown will occur once someone on the system starts listening to this output.

Salinger

I'm currently chasing performance of OutputDebugString and the note you make about concurrent threads synchronising around it really shines a light on things. Thanks for making that clear. – Bonhomie

Answer 3

I had read in an article that OutPutDebugString internally does few interesting things:

1. Creates\Opens mutex and wait infinitely till mutex is acquired.
2. Passes the data between the application and the debugger is done via a 4kbyte chunk of shared memory, with a Mutex and two Event objects protecting access to it.

Even if the debugger is not attached ( in release mode) there is significant cost involved in using OutputDebugstring with the usage of various kernel objects.

Performance hit is very evident if you write a sample code and test.

Cozza

Answer 4

I've not seen a problem in dozens of server-side release mode apps over the years, all of which have built-in metrics. You can get the impression that it's slow because most of the debug-catcher applications you can find (DBWIN32 et al) are pretty slow at throwing the data up onto the screen, which gives the impression of lag.

Of course all of our applications have this output disabled by default, but it is useful to be able to turn it on in the field, since you can then view debug output from several applications, serialised in something like DBWin32. This can be a very useful debugging technique for bugs which involve communicating applications.

Avesta

Answer 5

Never leave OutputDebugString() calls in a release build. Always either remove them by using #ifdef statements, or provide another switch to have them turned off.

If you leave them in, have them disabled by default and only activate them on request, because otherwise your app will make it hard to debug other apps which behave nice (i.e., only output debug data on request).

Theres DebugView to catch the output of apps, but of course that's only good if not every app chatters along for no good reason.

Bulldog

Answer 6

Why not measure it yourself? Compile the following code, run it & time it. Then remove the call to OutputDebugString, recompile and rerun. Should take abut three minutes of you time.

   #include <windows.h>

    int main() {
        const int COUNT = 1000000;
        int z = 0;    
        for ( unsigned int i = 0; i < COUNT; i++ ) {
            z += i;
            OutputDebugString( "foo" );
        }
        return z;
    }

Bonis

Note that just running this code is not the whole story. Performance will be largely determined by what is monitoring the debug output (DebugView, Visual Studio debugger, etc.), and could differ depending on which version of Windows you are running, so you need to test under many different circumstances. It would take a lot more than three minutes of one's time. – Chippy

I've tested the above code snippet using a poor man's time(NULL) - start. The 1000,000 times takes 13 seconds if turn on OutputDebugString, but no attached debugger, if open DbgViewer to capture the output, the time being 169 seconds. If turn off the OutputDebugString, the measured time is 0 second. – Leftward

Answer 7

The existing answers are dating back to 2009 / 2010.

While the performance of a forgotten OutputDebugString() may not have changed much, I can tell that the tooling makes a huge difference.

• No tool: 30 µs/call (x86) 10 µs/call (x64)
• DebugView (completely disabled): 64 µs/call (x86) 37 µs/call (x64)
• DebugView++ (paused): 67 µs (x86)
• DebugView (autoscroll deactivated): 735 µs/call (x86) 703 µs/call (x64)
• DebugView++ (autoscroll deactivated): 67 µs/call
• DebugView (autoscroll active): 936 µs (x86) 799 µs/call (x64)
• DebugView++ (autoscroll active): 67µs/call
• VS 2019: 81 µs/call
• DebugView (synchronizing 2 instances): up to 1736 µs/call
• DebugView++ (synchronizing 2 instances): up to 102µs/call

Conclusions:

The original DebugView was so slow that I reduced the number of samples to actually finish somewhen.

DebugView++ does a really great job.

VS 2019 seems to do a much better job that older Visual Studios, mentioned in this answer. I can't compare myself, but it's so close at DebugView++ that I consider it really good.

---

Measurements: 100.000 calls of OutPutDebugStringW in a single for loop. All builds in Release mode. Intel i7-6820HQ, 2.7 GHz, limited to 99% to prevent Turbo Boosting. Using std::chrono::high_resolution_clock::now() for measurement before and after the 100.000 calls.

Lurlene

Author of Debugview++ here; thanks for the compliment Thomas ;) The main reason for OutputDebugString to cause slowdown is whether somebody is listening to the messages (for example if the debugger is attached or debugview++ is running and listening. The thread of the sender is effectively blocked until the received acknowledges having read the message. Debugview++ was specifically optimized to do this fast, but most other tools do not do that. – Justle

Whether a slowdown is 'significant' depends on your application. As others have stated: measure it :) – Justle

@JanWilmans: thank you for writing DebugView++. I was able to solve a bug with it. Debugging and DebugView were not an option due to timing issues. – Lurlene

Answer 8

I was curious about this topic so I did some research.

I've posted the results, the source code and project files so that you can repeat the tests for your setup. Covers running a release mode app without anything monitoring OutputDebugString and then with Visual Studio 6, Visual Studio 2005 and Visual Studio 2010 monitoring OutputDebugString to see what differences in performance there are for each version of Visual Studio.

Interesting results, Visual Studio 2010 processes OutputDebugString information up to 7x slower than Visual Studio 6.

Full article here: Whats the cost of OutputDebugString?

Idomeneus