IanG on Tap

I told you you hadn't heard the last of this one...

Philip Haack has posted an update to his cross-thread-stack-trace-enabled version of the TimedLock. His update incorporates my most recent set of changes, but retains his additional code for keeping track of the stack traces for all the threads holding a lock, rather than just the one that aborted acquisition due to suspected deadlock.

I also received an email from Marek Malowidzki (who I don't think has a home page, so I apologize for the absence of a link there). He came up with an ingenious solution to the problem I pointed out with Philip's implementation - the fact that it generates a stack trace every time you acquire a lock. Since we hope that deadlocks are the exception rather than the rule, and we only require the stack traces on an error condition, the effort of generating a stack trace will usually be wasted.

Performance Digression

And before anyone starts crying premature optimization, the cost of building a stack trace is non-trivial; adding this into a lock operation makes it orders of magnitude more expensive in the non-contention case. Testing on my machine here, I find that Monitor.Enter/Monitor.Exit pairs take only 30ns (about 50 clock cycles) in the non-contention case. (The more expensive ReaderWriterLock takes about 250ns, incidentally.) But when we add in the cost of generating a stack trace it goes up to 10.7us. That's microseconds, or if you prefer, 10700ns. So it's over 300 times slower!

Of course that might not matter... It all depends on how coarse your locking is. If the work you'll be doing while holding the lock is going to take milliseconds to complete, then 10us to acquire a lock isn't such a big deal. But if your locks are fine-grained, so that you are doing executing a few lines of code while holding the lock, the cost of lock acquisition is more likely to dominate.

(In practice of course, you would need to test the effective costs of these things in context. I just timed these things in a micro benchmark kind of a test. The joy of performance measurement is that the cost of a given operation can vary wildly depending on the context in which you perform that operation. You might find that in your system, building a stack trace every time you acquire a lock makes no measurable difference to your performance.)

Marek Malowidzki's Solution

Marek's solution manages to avoid the stack trace generation cost in cases where the stack trace is not required, but he is still able to retrieve stack traces for both the thread that holds the lock and the thread that failed to acquire the lock in the failure case.

(I've not shown Marek's code by the way, since it was a proof of concept rather than finished code, and people have a habit of copying sample code on the internet into production systems...)

The trick he uses to achieve this is that the thread that owns the lock performs a check when releasing it - it looks to see if any other threads tried and failed to acquire lock while the owning thread was in possession. This is done using a shared Hashtable. When a thread fails to acquire a lock, it adds an entry to this Hashtable using the object it was trying to obtain the monitor for as the key. The value associated with the object is a data structure that contains a place for the owning thread to write a stack trace once it eventually releases the lock.

You might think that this won't work - surely if the thread that owns the lock fills in the stack trace once it releases the lock, the thread that failed to acquire the lock will never see this stack trace. After all, the error condition we're dealing with here is that we deadlocked while waiting for the lock to be released... This suggests that waiting for it to be released in order to get the stack trace isn't going to be successful - the lock isn't any more likely to become available just because we happen to have a different reason for waiting for it!

But Marek has thought of that. He doesn't wait for the owning thread's stack trace at the point at which the exception is thrown. Instead, the exception has a reference back to the data structure which will eventually be populated with the stack trace - we just throw the exception without waiting. We don't wait for the owning thread to write a stack trace until we actually come to handle the exception. The exception will of course propagate up the stack in the usual fashion, and there is a good chance that by the time it reaches an exception handler, the act of propagating the exception will have caused whatever other locks the failing thread held that were bringing about the deadlock to be released. This example illustrates the typical usage model:

private static void WillDeadlock(object o1, object o2)
{
    try
    {
        using (TimedLock.Lock(o1))
        {
            Thread.Sleep(200);
            using (TimedLock.Lock(o2))
            {
                Thread.Sleep(200);
            }
        }
    }
    catch (LockTimeoutException x)
    {
        // Wait for up to 5000ms for the owning thread
        // to give us its stack trace.
        StackTrace otherStack = x.GetBlockingThreadStackTrace(5000);
        Console.WriteLine(x);
        if (otherStack == null)
        {
            Console.WriteLine("Couldn't get other stack trace");
        }
        else
        {
            Console.WriteLine("Stack trace of thread that owns lock: {0}", 
                otherStack);
        }
    }
}

If this function is called on two different threads, each passing in the same pair of objects, but in a different order, this will deadlock at the second call to TimedLock.Lock on both threads. However, when the deadlock is detected, one of the threads will throw an exception. When that exception propagates back out to the catch block, it will leave the outer using block, releasing the lock that it already holds. This clears the deadlock, allowing the other thread to proceed, so when we call the GetBlockingThreadStackTrace method (this is Marek's extension), the deadlock is already cleared. This means that the owning thread will proceed and then release the lock once it is done, at which point the stack trace becomes available. The thread on which the exception was thrown will have to wait for the owning thread to release the lock before it gets the stack trace, but because the exception had the effect of clearing the deadlock, it's now OK to do this.

Of course there are more complex scenarios in which the throwing of an exception on the thread that detects the error will not have the effect of clearing the deadlock - it might be that the exception handler which catches the exception is too deeply nested, and that the problematic locks are still held by this time. This is why Marek's GetBlockingThreadStackTrace method requires a timeout to be passed in - it cannot guarantee that it will be able to retrieve the stack trace.

Variations

There are a couple of variations one could play on this theme, both of which avoid the problem where the thread which catches the exception might not be able to retrieve the stack trace. In both cases, the solution is to avoid even attempting to retrieve the stack trace on that thread.

The simplest variation is for the owning thread to throw an exception on releasing the lock if it detects that another thread detected deadlock. This way, both threads throw an exception - both the one that failed to acquire the lock and the one that succeeded. You would want to add some kind of information to the exceptions to allow them to be correlated in your logging of course, since they would be thrown at different times on different threads. But it does mean that all the information is available without making threads wait for one another in exception handlers.

But that's not a great solution for at least two reasons. First, it means both threads encounter failure, when we only really needed to fail one of the threads to clear the deadlock. Second, it means that exceptions can now emerge from a rather surprising place. Throwing exceptions when the lock is released is a surprising thing to do - while you would reasonably expect to fail to acquire a lock, failing to release one that you acquired successfully is not something you normally have to deal with. Worse, because of the using idiom the TimedLock supports, the lock is released in a compiler-generated finally block. Throwing exceptions from finally makes me a bit queasy, but even if you don't mind that, it's just nasty that an exception can emerge from the following line of code:

}

Yes, a single closing brace would be all the source code you see for a potential exception source. Barf.

A better solution would be for the owning thread to simply dump a stack trace into a diagnostic log, rather than throwing an exception. This way, you get all the information you require in your logs. (This assumes you put some information into the LockTimeoutException allowing the stack traces from the owning thread and the deadlock-detecting thread to be correlated. Allocating a unique number to each detected deadlock would do the trick.) But now, we don't end up with threads waiting for each other to print the information out, and we also avoid throwing exceptions on both threads. Of course the downside is that there are a variety of different diagnostic logging strategies that people use, so I can't produce a single example that everyone can use - the logging code would be different for everyone...