Locks are held in the database to ensure data consistency. If there are errors due to lock time-out or performance issues due to lock waits, the recommendation is to review the transactions that are involved in the locks to check if it is possible to change anything in their logic or isolation level to improve concurrency and avoid the blocks. Blocks can also be caused by transactions taking longer than expected and, in this case, it may require query tuning.
We can use T-SQL while the issue is happening to identify the queries involved in the block and the applications that are running them.
With the query below, we can see the sessions involved in the block, last query they ran, and which one is the head of the block. It might already give us enough information to identify where the issue is:
|
--Blocking tree
SET NOCOUNT ON |
If the information provided by the last query is not enough and we have to look deeper into the sessions that are part of the block, we can run the query below:
|
--Details about the sessions that are blocking and being blocked:
SELECT current_timestamp as [CURRENT_TIMESTAMP] , DB_NAME(dtl.resource_database_id) AS database_name , req.session_id AS blocked_sessionID , ses.program_name blocked_programName , ses.host_name blocked_hostname , ses.login_name blocked_login , CASE ses.transaction_isolation_level WHEN 1 THEN 'ReadUncomitted' WHEN 2 THEN 'ReadCommitted' WHEN 3 THEN 'Repeatable' WHEN 4 THEN 'Serializable' WHEN 5 THEN 'Snapshot' END blocked_isolation_level , REPLACE(REPLACE(sqltext.TEXT, CHAR(13), ' '), CHAR(10), ' ') AS blocked_last_query , req.status AS [blocked_status] , req.command AS blocked_command , req.cpu_time AS blocked_cpuTime , req.total_elapsed_time AS blocked_totalElapsedTime , blocked_tran.transaction_id blocked_transaction_id , osw.blocking_session_id AS blocker_SessionID , blocker_ses.program_name blocker_programName , blocker_ses.host_name blocker_hostName , blocker_ses.login_name blocker_login , CASE blocker_ses.transaction_isolation_level WHEN 1 THEN 'ReadUncomitted' WHEN 2 THEN 'ReadCommitted' WHEN 3 THEN 'Repeatable' WHEN 4 THEN 'Serializable' WHEN 5 THEN 'Snapshot' END blocker_isolation_level , REPLACE(REPLACE(iif(blocker_sqltext.TEXT is NULL,blocker_sqltext2.event_info,blocker_sqltext.TEXT), CHAR(13), ' '), CHAR(10), ' ') AS blocker_last_query , blocker_req.status AS [blocker_status] , blocker_req.command AS blocker_command , blocker_req.cpu_time AS blocker_cpuTime , blocker_req.total_elapsed_time AS blocker_totalElapsedTime , blocker_proc.lastwaittype blocker_last_waittype , blocker_proc.last_batch blocker_last_batch , blocker_proc.open_tran blocker_open_tran , blocker_tran.transaction_id blocker_transaction_id , blocker_proc.cmd blocker_command , dtl.request_mode AS lockRequestMode , dtl.resource_type AS lockResourceType , dtl.resource_subtype AS lockResourceSubType , osw.wait_type AS taskWaitType , osw.resource_description AS taskResourceDescription , osw.wait_duration_ms FROM sys.dm_exec_requests req INNER JOIN sys.dm_exec_sessions ses on ses.session_id = req.session_id CROSS APPLY sys.dm_exec_sql_text(req.sql_handle) AS sqltext INNER JOIN sys.dm_tran_locks dtl on dtl.request_session_id = req.session_id INNER JOIN sys.dm_os_waiting_tasks osw on osw.session_id = req.session_id LEFT JOIN sys.dm_tran_session_transactions blocked_tran on blocked_tran.session_id =req.session_id INNER JOIN dbo.sysprocesses blocker_proc on osw.blocking_session_id = blocker_proc.spid LEFT JOIN sys.dm_exec_requests blocker_req on blocker_req.session_id = osw.blocking_session_id LEFT JOIN sys.dm_exec_sessions blocker_ses on blocker_ses.session_id = osw.blocking_session_id LEFT JOIN sys.dm_tran_session_transactions blocker_tran on blocker_tran.session_id =osw.blocking_session_id OUTER APPLY sys.dm_exec_sql_text(blocker_req.sql_handle) AS blocker_sqltext OUTER APPLY sys.dm_exec_input_buffer(osw.blocking_session_id,0) as blocker_sqltext2;
|
This query will provide information about the last queries on both sides, the isolation level of each and if they are inside a transaction.
Locks are held for the duration of the transaction (between commits/rollbacks), so the lock might be being held due to a previous query of the current transaction. Said that, there may be cases in which the block does not make sense when looking at both sessions last query, but it does when we look at the whole transaction. However, we cannot see the previous queries the transaction ran using T-SQL.
In the cases where the blocks are happening due to a lock acquired for a previous statement, we can use the query below to see which locks are being held by the sessions involved in the block. It won’t give us the previous queries in the transactions, but it might help us understand why the block is happening and assist in the investigation.
|
--Details about the locks that are being held by the sessions that are blocking and being blocked:
select DB_NAME(locks.resource_database_id) AS database_name , locks.request_session_id , locks.resource_type, locks.resource_subtype , locks.resource_description , locks.resource_associated_entity_id , locks.resource_lock_partition , locks.request_mode , locks.request_type , locks.request_status , locks.request_reference_count , locks.request_lifetime , locks.request_exec_context_id , locks.request_request_id , locks.request_owner_type FROM sys.dm_exec_requests req INNER JOIN sys.dm_os_waiting_tasks osw on osw.session_id = req.session_id INNER JOIN sys.dm_tran_locks locks on osw.blocking_session_id = locks.request_session_id or (osw.session_id = locks.request_session_id and osw.blocking_session_id is not null) order by locks.request_session_id;
|
For Azure SQL Database, if the database has auditing enabled in the Portal, we can find all the queries that were run by the transaction in the audit logs by filtering by session ID and transaction ID provided in the second query.
For both Azure SQL Database and Azure SQL Managed Instance, we can create an XEvents session to see which queries are being run by the applications and filter by the transaction ID and session returned by the second query.
Both XEvents and Auditing will only assist in the investigation of locks that happened after they were enabled/started.
Examples:
1. Using Extended Events:
For this example, I created an XEvents session in a Managed Instance for the events sql_statement_starting and sql_statement_completed filtering by the database name and adding the global fields sessionID and transaction_id. You may also want to include other global fields to help you in the investigation, such as client_app_name, client_hostname and username.
Note: For more information about XEvents, please refer to the extended events documentation.
After the Extended Events is active, we have a block in our database with the following blocking tree:
As you can see, the head (session 98) last statement was an alter in the table Person and It is blocking the session 97 (insert in the table Person), which we can understand just looking at the queries.
However, the session 97 last statement was an insert into the table Person and It is blocking the session 115, that is trying to insert into the table Person2. If it is a different table, how can they this block happen?
We can understand when we look at the information collected by the XEvents:
We see the session 97 ran 2 queries in this same transaction (same transaction_id) and the first one was an alter in the table Person2.
It may be difficult to find the information right away if there is high activity on the database, so you can filter by the session_id and transaction_id, provided by the second query in this article to find all the statements that were executed within the same transaction.
2. Using Azure SQL DB Auditing
If you have auditing enabled for your Azure SQL DB server/database, you can use the audit log to see the statements that were run by the transaction(s).
If we have the same scenario as the previous example, but now in an Azure SQL DB with auditing enabled:
As you can see above, the head (session 102) last statement was an alter in the table Person and It is locking the session 104 (insert in the table Person), which we can understand just looking at the queries.
However, the session 104 which last statement was the insert into Person is blocking the session 100 that is trying to insert into the table Person2. If it is a different table, how can they this block happen?
If we open the audit log and add the columns session_id and transaction_id, we can see the session 104 ran in this same transaction (same transaction_id) an alter in the table Person2:
We cannot see in the audit log the statements that are blocked, because it only shows the statements that have been completed. We can use the session_id and transaction_id returned by the second query of this article to filter the audit information and see the previous queries ran by the transaction(s).
References:
https://blog.sqlauthority.com/2015/07/07/sql-server-identifying-blocking-chain-using-sql-scripts/