How to track blocking that happen for less than a second - SQL Server

Question

I am trying to troubleshoot a blocking issue which happens for less than a second. The OLTP application is very sensitive and has to have an response time of less than 200ms for some transactions as per the agreed SLA. We had some lock escalation issues with the new code release which we were able to solve with reducing the batch size in the updates. Even with the small batch size, we suspect that the new sp is blocking the same rows that the OLTP transactions is updating.

I need to find the session that is getting blocked and the resource its waiting on. As per my understanding "blocked process threshold" can set for a minimum of 1 second and so this will not capture the blocking.

I am experimenting with wait_info and wait_completed x events.

Is there any other way we could track this. Thanks

Answer 1

As you are specifically interested in locking rather than general waits the locks_lock_waits extended event sounds more suitable.

With a filter on increment >= 200

CREATE EVENT SESSION [locks_lock_waits] ON SERVER 
ADD EVENT sqlserver.locks_lock_waits(
        ACTION(sqlserver.sql_text)
            WHERE  ( [sqlserver].[is_system] = 0
                     AND [increment] >= 200
                     AND [counter] <= 1000 ) 
    )
ADD TARGET package0.ring_buffer;

GO

ALTER EVENT SESSION [locks_lock_waits]  
ON SERVER  STATE = start;  

The above gathers the statements waiting on locks for the threshold amount of time but doesn't give the specific lock resource.

I have never used this event and have no insight into how much overhead this session would cause on your production server.

I found this video on the topic. That does strongly recommend filtering on counter to reduce the number of events collected and I have done so above.

It also mentions an old legacy undocumented command

dbcc lock(StallReportThreshold, 200) -- 200 is threshold in ms

Which (if trace flag 3605 is enabled) dumps out limited information such as the below to the SQL Server error log.

Process 53 waited 6844 ms for S lock on RID: 2:1:120:2 result: OKWAIT

I just mention this in passing as extended events would be clearly preferable anyway as it is documented and much more powerful.

Answer 2

If you are interested in locking, there are several extended events available:

lock_acquired
lock_released
lock_escalation

The first two events have a duration column in (microseconds) which you could filter on for your thresholds. They also have a resource_description action which will give you some detail on the resources involved.

The lock_escalation event also has a statement action which you can add to collect the T-SQL statement that triggered the lock escalation. It also has escalation_cause. Here's a sample session:

CREATE EVENT SESSION [locking] ON SERVER 
ADD EVENT sqlserver.lock_acquired( SET collect_resource_description = (1) ),
ADD EVENT sqlserver.lock_escalation( SET collect_statement = (1) ),
ADD EVENT sqlserver.lock_released( SET collect_resource_description = (1) )
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)
GO

I suspect there is probably a reason you can't set the blocked process report threshold to less than a second: locking is perfectly normal in an RDBMS - the database engine has to lock resources in order to protect them. Although there is not an official definition as to when locking becomes blocking, locking ticking over sub-second, seems kind of normal to me.