SET CONTEXT_INFO for tracking specific SQL requests

Question

I've got a problem where I'm seeing some very strange lock waits, with the process at the top of the lock wait tree in the 'sleeping' 'AWAITING COMMAND' state. I can see the machine name and application, and I'm pretty sure it's a client-side transaction that's blocked on the client-side after locking some records that's causing the problem, but I haven't been able to find through code examination what it could be doing. I've already ruled out GC, because the same application is responding to other requests (we have a request to dump the status of all pending requests, each with a unique ID, and that returned just fine while the lock remained). By the time we are notified of this issue, request are backed up to the tune of several thousand per SQL client machine, so sifting through all these requests is very painful without writing custom code just for that.

I'd like to add some info to the SQL connection information to track which request is the one at the top, not just which machine and application (and I think this may prove useful in diagnosing future issues as well). I could append something to the application name in the connection string, but I think that would likely do bad things to the connection pooling.

I read this post: Can I Set The Value of App_Name() AFTER Login? and this one: http://www.sqlservercentral.com/articles/T-SQL/2765/ which seem to indicate that I might be able to use SET CONTEXT_INFO to get data into sys.dm_exec_requests.context_info and then I would be able to use that data to identify the exact request the bad transaction is coming from.

We're not using SET CONTEXT_INFO for anything else in the application (and the SQL servers are dedicated to this application).

Is there some reason I would not want to do request identification this way, or some better way to track requests through to the SQL layer?

Answer 1

I've now got this in production and it's working beautifully. We found the underlying issue before this went out, but it may be very useful for future issues.

To any future readers, SET CONTEXT_INFO can indeed be used for correlating SQL requests to the code and/or requests that run them, and I've seen no noticeable performance hit.

For anyone curious about the specifics of this locking issue, it turns out that in this case, we had several places in our code where we opened a transaction and then during the transaction, we called a library function that on the surface appeared to just retrieve a cached value, but in reality did some non-database work that should not have been done inside the transaction and then proceeded to open its own database connection. Under certain high-load situations, this caused a deadlock because the transaction locked a highly-contented item, then while the improper processing was occurring, every other available connection became blocked waiting for the same highly-contented item. Once the processing was complete, the errant code then attempted to open the separate database connection, which deadlocked because every available connection was in use and waiting for the transaction to complete. Adding code to detect that situation and log the call stacks allowed us to find not only the case that had begun triggering multiple times per week, but five other cases as well.

Lesson: let the database do everything involved with every transaction (never use SqlConnection.BeginTransaction). When you think you need to do something client side during the transaction, redesign the system so that you don't need to do that--you may think you're fine with the one thing you're doing, and you might be, but you never know how the code may subtly change in the future and break you just like this.