The Hairy Problem

The other day I was debugging a hairy deadlock in a large application at work. When I say hairy, I mean dozens of threads, all potentially able to walk through the same areas, events raised inside a lock, and calls to other methods that recursively enter the same lock.

The only way to track down the conflicting calls was to add logging to all the possible entry/exit points to see where each locking block was first entered. This took a good deal of time and debugging to add. After some careful log analysis, I quickly identified the problem area and was able to resolve the problem.

Gimme My Syntactic Sugar

The real advantage of [csharp]lock[/csharp] is that it’s syntactically very powerful. With a single statement you get the locking calls neatly wrapped in a [csharp]try..finally[/csharp], which means a guarantee (more or less) that the lock will be released when leaving the block.

How can we hook into that to add logging and not lose the simplicity? The answer is the using statement. You get the same syntactic power, but you get to bring your own implementation.

Below is something I put together as a kind of proof of concept. (I haven’t used it in production code yet.) It works by entering the lock in the constructor and releasing it when disposed.

Then something like this:

[csharp linenumbers=”false”]
lock (LockObj)
{
// … do something …
}
[/csharp]

Becomes this:
[csharp linenumbers=”false”]
using (MonitoredLock.From(() => LockObj))
{
// … do something …
}
[/csharp]

See what we did there? We didn’t assign a variable name. That’s to make sure that no one tries to dispose of it in-flight.

Notice we also assigned the lock object through an expression. This lets us get both the name and the reference from the actual object used.

Sample Code

See the full gist which also includes a simple example console app.

Some other cool features you’ll see in this implementation:

• Keeps a lock depth counter using a ConditionalWeakTable which automatically removes items that have been garbage collected.
• It’s structured so that if you turn off tracing, all the log-generating code is suppressed for max performance. (You might want to choose your own compiler constant.)
• Allows you to override the lock name in the constructor if you want to use a better name:
  [csharp]new MonitoredLock(_lockObj, “LockObj”)[/csharp]

Let me know what you think in the comments.