Debugging multithreaded code in real time !

[nedo]

Introduction

Writing a multithreaded application is much more difficult than a single threaded program. Even worse, one needs to debug in real time to find these bugs, which is nearly impossible. But fear not, this article explains how just that can be simply done !

Challenge

We all love Visual Studio, using its breakpoints and single stepping through code to find out why a program behaves differently than expected. Alas, setting a break point or single stepping will completely change the behaviour of a multithreaded application, where it matters which thread executes which instruction in which sequence, measured in microseconds or less. Stop or delay anything in the multithreaded system and it behaves completely differently.

So obviously, we cannot stop a single thread when debugging. Which means we should use tracing, looking something like this:

Console.WriteLine("Thread A requests someLock");
lock (someLock) {
  Console.WriteLine("Thread A got someLock");
  //do some work
  Console.WriteLine("Thread A releases someLock");
}
Console.WriteLine("Thread A released someLock");

Do this wherever you guess the error could happen and you will see in the output window which thread caused it. The only problem is that you cannot use Console.WriteLine(), because:

- It is way too slow, taking about 500 microseconds on my PC. The traced program would behave rather differently than the not traced program.

- Console.WriteLine locks the threads if several try to write at the same time, a big No No in real time multi-threading debugging.

Solution

Don't use the Console for tracing, but write your trace into memory. Once the problem occurs, check in the memory what had happened. Writing to the memory must be done with as little overhead as possible, something like this:

public const int MaxMessages = 0x100;
string[] messages = new string[MaxMessages];
int messagesIndex = -1;

public void Trace(string message) {
  int thisIndex = Interlocked.Increment(ref messagesIndex);
  messages[thisIndex] = message;
}

Basically, Trace() writes the message in a string array. Notice that Interlocked.Increment() is multithreading safe and none blocking, as opposed to many of the thread safe methods in the .NET framework which are blocking. This absolute minimum approach needs about 2 microseconds, a delay that should be acceptable. After all, there will always be some time variation, even if the exact same code is executed twice, depending what else the microprocessor is doing, if the code and data is in the processor's cache, etc.

Of course, the above code has also the problem that we get an exception when the array is full, which we can easily solve like this:

const int indexMask = MaxMessages-1;

public void Trace(string message) {
  int thisIndex = Interlocked.Increment(ref messagesIndex) & indexMask;
  messages[thisIndex] = message;
}

This forces the index back to 0, once it has reached the end of the messages array. The buffer can store 0x100 messages, in decimal notion 256. If you need more history, increase MaxMessages. But be careful, 0x1000000 % MaxMessages must be equal 0. Meaning you can use figures like 0x100, 0x200, 0x400, 0x800, 0x1000 but not 0x300.

What happens when messagesIndex reaches int.Max (0x7FFFFFFF or 2,147,483,647) ? Basically the integer will overflow to int.Min (0x8000000 or -2,147,483,648, but luckily no exception gets thrown. The bitwise "And" operator & cuts out the leading 1s and also the very negative number gets mapped into the range 0 - 0x100.

Continuare: aici