Deadlock explanation- Updating and Inserting simultanuously. 1

[TheBugSlayer]

I wish I could attach an image without resorting to a link but here is the situation:
Process 180 has a U lock on Page A; Process 319 requests an IX lock on Page B and gets denied. Process 319 holds an IX lock on Page B and Process 180 requests a U lock and gets denied. A deadlock occurs.

Process 180 runs the following query:

UPDATE TableA 
SET Main=c.Main, Sub=c.Sub, Grp=c.Grp 
FROM TableA a 
JOIN TableC c ON a.FacilityID=c.FacilityID AND a.ClientID=c.ClientID 
WHERE a.Main IS NULL AND c.Main IS NOT NULL

Process 319 runs

INSERT INTO [TableA]([ClientID],[FacilityID],[PatientID],[AccNumber],[ReportDateTime],[DeliveryStatus],[PDFLocation],
			[OriginalPDFName],[CollectionDate],[ReceivedDate],[Pathologist],[FacilityKey]) 
VALUES(@1,@2,@3,@4,@5,@6,@7,@8,@9,@10,@11,@12)

Both processes run a query against the same table. However Process 319 is attempting an INSERT.
My question is why is Process 319 deadlocked if it's an INSERT? I based this assertion on the fact that the SQL Server Profiler's trace Deadlock Graph shows a cross on process 319. All tables in the query are properly indexed. Is it because the record that Process 319 is trying to insert will have indexes created for it that would fall in the page that Process 180 has locked?

Thanks for the help.

MCP SQL Server 2000, MCTS SQL Server 2005, MCTS SQL Server 2008 (DBD, DBA)

 

[yelworcm]

Funny you should post this. I had a run-in with Profiler's deadlock trace event not long ago, and I was left scratching my head, too. You may be looking at a larger explicit transaction than just the insert statement. At least, that is what I had found to be my case. The table was small, and two threads from the application were reading a small table (table scan select lock), holding on to that lock, then updating a record of the table (row exclusive lock). The deadlock trace only showed the final update statements, which made no sense to me, as they should have been done in serial with no problem. Only by looking at the whole trace of the connection was I able to see that an explicit transaction was started at the beginning of the whole mess. To top things off, the deadlock trace flag on SQL Server has apparently been changed from 1205 to 1222.

The alternative is that the two could be colliding on a non-clustered index (pretty rare occurrence, but that is why we have the deadlock trace). In this case, the insert can be pushing it's update up from the table to the non-clustered index, while the update is using that same index and trying to read downward to find the record it wants to update. I think I have only seen this sort of thing once, and it was years ago, so I am a little hazy on some of the details.

Does this help at all?

 

[TheBugSlayer]

Hi Yelworcm, it does shed some light. In my case I had also turned on trace flag 1222. Under normal circumstances we seldom experience deadlocks; SQL Server takes care of them and we right the apps to handle these situations gracefully. The boss however had decided to update hundreds of thousands of rows in a loop through a SP that rand 6 or 7 updates at once...I pointed the app as a culprit and luckily it was a one time thing and it does not need to run anymore. So I guess the concurrence is at the index page level. I would like to learn more about how to view more details for this kind of transactions. I set trace 1222 like I said and my understanding is that the details should show in the error log, however I have not see any pertaining to a deadlock.

MCP SQL Server 2000, MCTS SQL Server 2005, MCTS SQL Server 2008 (DBD, DBA)

 

[yelworcm]

Traceflags have a dirty little secret for those who are not used to them. Trace flags set with dbcc traceon are for the local connection only, unless you include "-1" as a trace flag. If the trace flag is set on the command line with the -T parameter, they will be server-wide.

Anyway, here is a simple example of how to generate your own deadlock, so you can inspect the output:

create table test1
(col1 int,
 col2 varchar(20))

create table test2
(col1 int,
 col2 varchar(20))

dbcc traceon (1222, -1)

-- On connection 1
begin transaction 

delete test1

insert into test1 values (1, 'hello')

update test1 set col2 = 'goodbye' where col1 = 1

waitfor delay = '000:00:10'

select * from test2

-- On connection 2

begin transaction

delete test2

insert into test2 values (11, 'hi')

update test2 set col2 = 'bye'

select * from test1

Note that neither transaction has a corresponding commit. This is an extremely bad practice for live production code, but we need to do it here to demonstrate the deadlock error. Simply run the first part to set up the environment, then the two parts after that from separate query windows. You will need to run part 2 within 10 seconds of starting part 1 to get the deadlock. Running this, I get the following in my errorlog (SQL 2012) marked as from SPID 12s.

deadlock-list
 deadlock victim=process176aa50c8
  process-list
   process id=process176aa50c8 taskpriority=0 logused=484 waitresource=RID: 7:1:228:0 waittime=2855 ownerId=43449 transactionname=user_transaction lasttranstarted=2013-03-04T13:14:38.290 XDES=0x178ab6d28 lockMode=S schedulerid=2 kpid=2432 status=suspended spid=52 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2013-03-04T13:14:43.843 lastbatchcompleted=2013-03-04T13:14:38.290 lastattention=1900-01-01T00:00:00.290 clientapp=Microsoft SQL Server Management Studio - Query hostname=MCROWLEY-L01 hostpid=2856 loginname=ANALOG\MCrowley isolationlevel=read committed (2) xactid=43449 currentdb=7 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
    executionStack
     frame procname=adhoc line=1 sqlhandle=0x020000002b48ba214fce8dcc87ec03e5b11cbe4f38cac56c0000000000000000000000000000000000000000
select * from test2     
    inputbuf
select * from test2
   process id=process176aa4928 taskpriority=0 logused=800 waitresource=RID: 7:1:230:0 waittime=5616 ownerId=43385 transactionname=user_transaction lasttranstarted=2013-03-04T13:14:20.653 XDES=0x179dbc3a8 lockMode=S schedulerid=2 kpid=2336 status=suspended spid=54 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2013-03-04T13:14:41.083 lastbatchcompleted=2013-03-04T13:14:33.880 lastattention=2013-03-04T13:10:59.767 clientapp=Microsoft SQL Server Management Studio - Query hostname=MCROWLEY-L01 hostpid=2856 loginname=ANALOG\MCrowley isolationlevel=read committed (2) xactid=43385 currentdb=7 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
    executionStack
     frame procname=adhoc line=10 stmtstart=222 sqlhandle=0x02000000e2bfaa2792c0c269299da02f4f2aa5f51d3e82c60000000000000000000000000000000000000000
select * from test1     
    inputbuf
begin transaction
delete test2
insert into test2 values (11, 'hi')
update test2 set col2 = 'bye'
select * from test1
  resource-list
   ridlock fileid=1 pageid=228 dbid=7 objectname=Applications.dbo.test2 id=lock17b8b9f00 mode=X associatedObjectId=72057594039107584
    owner-list
     owner id=process176aa4928 mode=X
    waiter-list
     waiter id=process176aa50c8 mode=S requestType=wait
   ridlock fileid=1 pageid=230 dbid=7 objectname=Applications.dbo.test1 id=lock17b8bb680 mode=X associatedObjectId=72057594039042048
    owner-list
     owner id=process176aa50c8 mode=X
    waiter-list
     waiter id=process176aa4928 mode=S requestType=wait

The objectname is the name of the object the two connections deadlock on, whether it is a table, or an index. Hope this helps.

 

[TheBugSlayer]

Thank you sir. I had used the command

DBCC TRACEON(1222, -1)

DBCC TRACESTATUS revealed that the trace flag is indeed global and still on. And I now see the deadlock info, although it's all mixed up, kind of. It's hard to follow the logic. This is where I wish it was possible to attach an image to a post.

Thanks again for the very instructive post.

MCP SQL Server 2000, MCTS SQL Server 2005, MCTS SQL Server 2008 (DBD, DBA)

 

[yelworcm]

you should be able to separate individual deadlock outputs by the SPID.

 

[TheBugSlayer]

Yes, i see that. But they are interleaved: 17,17,17,17,14,17,17,14,14,17,17,17, etc...and the time stamp is the same. Profiler is quite helpful, so it's no big deal. I have come across a sys.xp_readerrorlog that comes in handy sometimes.

MCP SQL Server 2000, MCTS SQL Server 2005, MCTS SQL Server 2008 (DBD, DBA)