The Rambling DBA: Jonathan Kehayias : Deadlock

The Curious Case of the Dubious Deadlock and the Not So Logical Lock

Jonathan Kehayias — Fri, 29 May 2009 01:13:35 GMT

This blog post by James Rowland Jones on a specific type of deadlock is so interesting that I have to share the link to it. Not only so other people read it, but in case I ever need to find it again in a pinch, I can easily find it on this post. James encountered a very interesting deadlock and provides a really in depth explanation including the use of an undocumented side of locking in SQL Server that you'd be hard pressed to find somewhere else online.

http://blogs.conchango.com/jamesrowlandjones/archive/2009/05/28/the-curious-case-of-the-dubious-deadlock-and-the-not-so-logical-lock.aspx

As an additional note, he mentions at the bottom of the blog post an upcoming SQL Server Internals book that he is co-authoring with Christian Bolton, Justin Langford & Brent Ozar with contributions from Cindy Gross and me. I am working on the Waits and Extended Events chapter in this book currently which has been quite a learning experience and has really changed how I look at problems in SQL Server and troubleshoot performance issues personally. More to come on the book when it gets closer to publication.

EDIT:

Apparently Jame's blog post was so interesting it sparked some other posts online as well..

http://rusanu.com/2009/05/29/lockres-collision-probability-magic-marker-16777215/

Clarification on SQL Server Deadlocks being Unavoidable

Jonathan Kehayias — Thu, 30 Apr 2009 09:43:36 GMT

While running through some of my personal emails tonight, I happened across two different questions regarding some statements I have made on forums post in the past, as well as in one of my articles on SQL Server Central:

Even with "proper design" it is still possible to have deadlocking occur which is why it is crucial for applications to properly handle 1205 errors generated by the database engine. If a deadlock occurs, a properly built application should log the occurrence, but also resubmit the deadlocked transaction as a part of handling the error.

For whatever reason, this statement seems to stop being read at:

Even with "proper design" it is still possible to have deadlocking occur

and it is being taken to mean that deadlocks in SQL Server are unavoidable. This is not what this statement is intending to say by far, and I am a firm believer that deadlocks are generally caused by a fundamental design problem that can be fixed. The real problem is that sometimes, fixing the design problem is very complex and could mean restructuring the database, refactoring code, and/or other tasks that are not necessarily feasible to do at the moment. If you find yourself in one of these major redesign scenarios, solving the deadlock immediately may not actually be possible.

Many thanks go out to Louis Davidson who taught me this, or at least made me think about it when I reply/write about deadlocks online, but properly designed applications should have exception handling built into their data access layer which brings us to the remainder of the quote from the article that seems to never get read:

which is why it is crucial for applications to properly handle 1205 errors generated by the database engine. If a deadlock occurs, a properly built application should log the occurrence, but also resubmit the deadlocked transaction as a part of handling the error.

Handling exceptions and errors seems to be second place in development these days, at least based on the questions that get asked on the forums at times. Having written my own applications and tools in the past year, I am not exempt from this problem either. I have only recently begun to put exception management at the front of my application development, and in a hurry, I often still don't do it until something blows up the first time, and I have to go back and correct my shortcoming. The entire point of these two statements is that the application should properly handle the deadlock exception, and attempt to resubmit the transaction a second time before raising a hard error back to the user, and it should then log the error in some manner for follow up or tracking.

Deadlocking seems to be becoming more prevalent based on the trends I see in questions on the forums, which may be partially related to the increasing speed and performance of server hardware, but most often, it is the result of bad design.

Anatomy of a Deadlock - Part Deux

Jonathan Kehayias — Tue, 25 Nov 2008 17:59:00 GMT

There was a very interesting post on the forums regarding a deadlock that is very similar to the deadlock described in the initial Anatomy of a Deadlock post I made a few months back. This one is slightly different however because it involves Range locks, Serializable Transaction Isolation Level, and a Heap with a Non-Clustered Index. I am a visual person when it comes to deadlocks, and to figure it all out I often just draw a diagram on paper, but this one is interesting enough to put into Visio and show.

To keep from reposting the entire post, I am going to stick to the pertinent details only on this blog post. The post has a heap with a non-clustered index on the primary key:

CREATE TABLE [dbo].[T_IC_AUDIT_LOG](
 [APP_ID] [varchar](50) NOT NULL,
 [TRANSACTION_ID] [varchar](50) NOT NULL,
 [USER_NAME] [nvarchar](256) NOT NULL,
 [LOG_FUNCTION] [nvarchar](256) NULL,
 [LOG_TIME] [datetime] NOT NULL,
 [APP_VERSION] [nvarchar](20) NULL,
 CONSTRAINT [C_IC_AUDIT_LOG_PK] PRIMARY KEY NONCLUSTERED 
(
 [TRANSACTION_ID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, IGNORE_DUP_KEY = OFF, 
       ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
) ON [PRIMARY]

GO
SET ANSI_PADDING OFF

Then a stored procedure is used to add records to the table:

CREATE PROCEDURE [dbo].[P_IC_AUDIT_LOG_I]
 @p_app_name                  varchar(256),
 @p_transaction_id            nvarchar(50),
 @p_user_name                 nvarchar(256),
 @p_log_function              nvarchar(256),
 @p_log_time                  datetime,
 @p_app_version               nvarchar(20) 
AS

SET NOCOUNT ON
SET XACT_ABORT ON

BEGIN
 DECLARE  @v_app_id VARCHAR(50)
 DECLARE  @v_error INT

    EXEC @v_error = P_IC_APP_GET_ID @p_app_name, @v_app_id OUTPUT
    IF @v_error <> 0 RETURN @v_error
        
 DECLARE @v_count INT
 SELECT @v_count = COUNT(*) FROM T_IC_AUDIT_LOG WHERE TRANSACTION_ID=@p_transaction_id;

 IF (@v_count >0 )
 BEGIN
  RETURN;
 END

 INSERT INTO T_IC_AUDIT_LOG (APP_ID, TRANSACTION_ID, [USER_NAME], 
            LOG_FUNCTION, LOG_TIME, APP_VERSION)
 VALUES (@v_app_id, @p_transaction_id, @p_user_name , 
            @p_log_function, @p_log_time, @p_app_version)

END
SET NOCOUNT OFF
SET XACT_ABORT OFF

This is being executed from ADO.NET using a System.Transaction, which is forcing it to run Serializable. The below picture demonstrates why the Deadlock actually is occuring:

The SPID on the right, process998f28, calls the stored procedure and gets a RangeS-S lock on the non-clustered index to do the count(*) against the transaction_id column which defines the non-clustered index for the primary key. Since this is run in a Serializable transaction, the lock is held for the duration of the stored procedure. When the insert is called on this same SPID, process998f28, an SIX lock is issued against the tables Heap allocation.

This deadlock, like the previous one, is timing based. While the SIX lock is taken for the insert on SPID process998f28, the second SPID, process90aa78, starts the stored procedure and takes a RangeS-S lock on the non-clustered index. After this happens the original SPID, , will require a RangeI-N lock to update the non-clustered index with the new row. This will be blocked by the existing RangeS-S lock on the non-clustered index which is being held by SPID process90aa78 for the duration of its execution.

When SPID process90aa78 finishes the count(*) select, it will then need a SIX lock on the Heap allocation, but it will be blocked by the existing SIX lock which is waiting on the RangeS-S lock to release, and the deadlock occurs.

The Deadlock graph for this is:

<deadlock-list>
  <deadlock victim="process90aa78">
    <process-list>
      <process id="process90aa78" taskpriority="0" logused="0" waitresource="OBJECT: 9:1567500813:0 " waittime="46" ownerId="485513" transactionname="user_transaction" lasttranstarted="2008-11-14T19:31:16.347" XDES="0xd0d2040" lockMode="IX" schedulerid="1" kpid="4784" status="suspended" spid="63" sbid="0" ecid="0" priority="0" transcount="2" lastbatchstarted="2008-11-14T19:31:16.347" lastbatchcompleted="2008-11-14T19:31:16.347" clientapp=".Net SqlClient Data Provider" hostname="NCS-LIFENG" hostpid="2776" loginname="test" isolationlevel="serializable (4)" xactid="485513" currentdb="9" lockTimeout="4294967295" clientoption1="673316896" clientoption2="128056">
        <executionStack>
          <frame procname="xxxxx.dbo.P_IC_AUDIT_LOG_I" line="40" stmtstart="1822" stmtend="2330" sqlhandle="0x03000900b0d65c591167e5001c9a00000100000000000000">
INSERT INTO T_IC_AUDIT_LOG(
  APP_ID,
  TRANSACTION_ID ,
  [USER_NAME] ,
  LOG_FUNCTION ,
  LOG_TIME ,
  APP_VERSION 
 )
 VALUES(
  @v_app_id,
  @p_transaction_id,
  @p_user_name ,
  @p_log_function ,
  @p_log_time ,
  @p_app_version
 )     </frame>
        </executionStack>
        <inputbuf>
Proc [Database Id = 9 Object Id = 1499256496]    </inputbuf>
      </process>
      <process id="process998f28" taskpriority="0" logused="936" waitresource="KEY: 9:72057594137280512 (5702e611629e)" waittime="62" ownerId="485490" transactionname="user_transaction" lasttranstarted="2008-11-14T19:31:16.347" XDES="0xcc9e5e0" lockMode="RangeI-N" schedulerid="2" kpid="2684" status="suspended" spid="60" sbid="0" ecid="0" priority="0" transcount="2" lastbatchstarted="2008-11-14T19:31:16.347" lastbatchcompleted="2008-11-14T19:31:16.347" clientapp=".Net SqlClient Data Provider" hostname="NCS-LIFENG" hostpid="2776" loginname="test" isolationlevel="serializable (4)" xactid="485490" currentdb="9" lockTimeout="4294967295" clientoption1="673316896" clientoption2="128056">
        <executionStack>
          <frame procname="xxxxx.dbo.P_IC_AUDIT_LOG_I" line="40" stmtstart="1822" stmtend="2330" sqlhandle="0x03000900b0d65c591167e5001c9a00000100000000000000">
INSERT INTO T_IC_AUDIT_LOG(
  APP_ID,
  TRANSACTION_ID ,
  [USER_NAME] ,
  LOG_FUNCTION ,
  LOG_TIME ,
  APP_VERSION 
 )
 VALUES(
  @v_app_id,
  @p_transaction_id,
  @p_user_name ,
  @p_log_function ,
  @p_log_time ,
  @p_app_version
 )     </frame>
        </executionStack>
        <inputbuf>
Proc [Database Id = 9 Object Id = 1499256496]    </inputbuf>
      </process>
    </process-list>
    <resource-list>
      <objectlock lockPartition="0" objid="1567500813" subresource="FULL" dbid="9" objectname="xxxx.dbo.T_IC_AUDIT_LOG" id="lockcbc5340" mode="SIX" associatedObjectId="1567500813">
        <owner-list>
          <owner id="process998f28" mode="SIX" />
        </owner-list>
        <waiter-list>
          <waiter id="process90aa78" mode="IX" requestType="convert" />
        </waiter-list>
      </objectlock>
      <keylock hobtid="72057594137280512" dbid="9" objectname="xxxxx.dbo.T_IC_AUDIT_LOG" indexname="C_IC_AUDIT_LOG_PK" id="lockcbc7400" mode="RangeS-S" associatedObjectId="72057594137280512">
        <owner-list>
          <owner id="process90aa78" mode="RangeS-S" />
        </owner-list>
        <waiter-list>
          <waiter id="process998f28" mode="RangeI-N" requestType="wait" />
        </waiter-list>
      </keylock>
    </resource-list>
  </deadlock>
</deadlock-list>

The solution to this problem is to convert the non-clustered index on the primary key to a clustered index. This prevents the cross locking scenario, and is actually going to be better for performance since the data will then be logically stored by the clustered index key.

With a clustered index, the following image should show how the deadlock is prevented.

I don't currently have a reproduction of the above scenario, but I have added it to my ever growing list of things to create and post. I am certain that I can create a demo for this problem.

UPDATE:

While finalizing this, a repost was made where the isolation level was changed, but a deadlock still occurred. The issue is still the non-clustered index on the heap, and locking order. Converting to a clustered index will fix the problem still.

The Anatomy of a Deadlock

Jonathan Kehayias — Wed, 30 Jul 2008 16:50:00 GMT

A common question of the forums is "How do I stop these deadlocks?" I wrote a small reference article on the SQL Examples Site for the forums for how to trap deadlocks using trace flags and Madhu Nair wrote an article for how to trap them with SQL Profiler:

Troubleshoot Deadlocking in SQL Server.
Troubleshoot Deadlocking in SQL Server 2005 using Profiler.

Most people seem to understand a UPDATE/INSERT, UPDATE/DELETE, INSERT/INSERT, DELETE/DELETE deadlocks pretty well, and the books online cover them pretty good. However, commonly I see where deadlocks occur with a INSERT/SELECT, UPDATE/SELECT, DELETE/SELECT process that is a bit more complex. The following image should provide a bit more explanation as to what is happening with this kind of deadlock.

This is a specific kind of deadlock and is caused by a nonclustered index that forces a key lookup to the clustered index. To demonstrate this kind of structure consider the following:

use tempdb
go
create table KeyLookupDeadlock
(rowid int identity primary key,
 firstname varchar(30),
 lastname varchar(30),
 dateofbirth datetime,
 favoritecolor varchar(10))
go
create nonclustered index ix_KeyLookupDeadlock_firstname 
on KeyLookupDeadLock (firstname)
go
insert into keylookupdeadlock select 'jon', 'kehayias', '07/29/2008', 'blue'
insert into keylookupdeadlock select 'mickey', 'mouse', '07/28/2008', 'green'
insert into keylookupdeadlock select 'minnie', 'mouse', '07/24/2008', 'yellow'
insert into keylookupdeadlock select 'donald', 'duck', '07/23/2008', 'fusia'
go 150000
insert into keylookupdeadlock select 'jim', 'fisher', '07/28/2008', 'red'
go
alter index all on keylookupdeadlock rebuild
go

This will create a table that has enough rows on most systems to cause a key lookup for the following query:

select firstname, lastname, dateofbirth, favoritecolor
from keylookupdeadlock
where firstname = 'jim'

Keeping in mind that this is an overly simplistic example, what will happen to cause the deadlock is that two SPIDS will start within microseconds of each other, one issuing the SELECT, and the other attempting to INSERT a new Row. The SELECT immediately takes a shared lock on the NonClustered Index and the INSERT immediately takes a Exclusive Lock on the Clustered Index. For the SELECT to complete, it will need to take a shared lock on the clustered index to get the additional columns in the SELECT list, but it will be blocked. At the same time, to complete the INSERT operation will require an Exclusive lock on the nonclustered indexes on the table, which is incompatible with the existing shared lock held by the SELECT operation, so both processes will be blocked waiting on the other to release its lock. This is where the deadlock occurs.

To resolve this, the nonclustered index can be dropped and replaced with a covering index that uses the INCLUDE option to cover the query completely:

create nonclustered index ix_KeyLookupDeadlock_firstname_included
on KeyLookupDeadLock (firstname)
include (lastname, dateofbirth, favoritecolor)

The resulting execution plan shows that the Key Lookup no longer happens, which will revent the deadlock from occuring:

For further information on Lock compatibilities see:

The Rambling DBA: Jonathan Kehayias : Deadlock

The Curious Case of the Dubious Deadlock and the Not So Logical Lock

Clarification on SQL Server Deadlocks being Unavoidable

Anatomy of a Deadlock - Part Deux

The Anatomy of a Deadlock

Lock Compatibility (Database Engine)