4

I am supporting vendor based application, which is filled with blocking and deadlock. Deadlocks occur mostly involving two or three processes however I noticed yesterday, it was involving 9 SPIDs.

Can somebody please help me in understanding this deadlock graph and solution on how to avoid this.

<deadlock><victim-list><victimProcess id="process2ff017c28"/><victimProcess id="process2f1538108"/><victimProcess id="process2f618d088"/><victimProcess id="process2f6d828c8"/><victimProcess id="process2f6d83848"/><victimProcess id="process2da9b5468"/><victimProcess id="process2efac7468"/><victimProcess id="process2efac7848"/></victim-list><process-list><process id="process2ff017c28" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4412" ownerId="284194209" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:29:07.323" XDES="0x2a785f800" lockMode="IX" schedulerid="1" kpid="9052" status="suspended" spid="63" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.733" lastbatchcompleted="2019-04-08T15:30:58.733" lastattention="1900-01-01T00:00:00.733" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284194209" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2f1538108" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4411" ownerId="284107628" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:24:11.843" XDES="0xdacf54e0" lockMode="IX" schedulerid="1" kpid="7272" status="suspended" spid="73" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.737" lastbatchcompleted="2019-04-08T15:30:58.727" lastattention="1900-01-01T00:00:00.727" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284107628" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2f618d088" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4620" ownerId="284193487" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:28:59.513" XDES="0x20df303b0" lockMode="IX" schedulerid="2" kpid="2088" status="suspended" spid="79" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.527" lastbatchcompleted="2019-04-08T15:30:58.527" lastattention="1900-01-01T00:00:00.527" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284193487" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2f6d828c8" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4302" ownerId="284194269" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:29:07.743" XDES="0x25090c6d0" lockMode="IX" schedulerid="3" kpid="3140" status="suspended" spid="105" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.843" lastbatchcompleted="2019-04-08T15:30:58.843" lastattention="1900-01-01T00:00:00.843" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284194269" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2f6d83848" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4319" ownerId="284178892" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:26:38.450" XDES="0xb83c63b0" lockMode="IX" schedulerid="3" kpid="7372" status="suspended" spid="81" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.827" lastbatchcompleted="2019-04-08T15:30:58.827" lastattention="1900-01-01T00:00:00.827" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284178892" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2da9b5468" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4300" ownerId="284174799" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:25:26.760" XDES="0x20d4683b0" lockMode="IX" schedulerid="3" kpid="5664" status="suspended" spid="97" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.847" lastbatchcompleted="2019-04-08T15:30:58.847" lastattention="1900-01-01T00:00:00.847" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284174799" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2efac7468" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4394" ownerId="284192570" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:28:49.180" XDES="0x184e789f0" lockMode="IX" schedulerid="4" kpid="5348" status="suspended" spid="98" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.753" lastbatchcompleted="2019-04-08T15:30:58.753" lastattention="1900-01-01T00:00:00.753" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284192570" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2efac7848" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4409" ownerId="284178168" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:26:23.063" XDES="0x2420aab80" lockMode="IX" schedulerid="4" kpid="4572" status="suspended" spid="68" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.740" lastbatchcompleted="2019-04-08T15:30:58.737" lastattention="1900-01-01T00:00:00.737" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284178168" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process><process id="process2efac7c28" taskpriority="0" logused="0" waitresource="OBJECT: 11:1142295129:0 " waittime="4413" ownerId="284177493" transactionname="implicit_transaction" lasttranstarted="2019-04-08T15:26:12.160" XDES="0xab9103b0" lockMode="IX" schedulerid="4" kpid="2448" status="suspended" spid="52" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2019-04-08T15:30:58.733" lastbatchcompleted="2019-04-08T15:30:58.733" lastattention="1900-01-01T00:00:00.733" clientapp="jTDS" hostname="APPNAME" hostpid="123" loginname="IRB_APP_USER" isolationlevel="repeatable read (3)" xactid="284177493" currentdb="11" currentdbname="Database_Name" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058"><executionStack><frame procname="adhoc" line="1" stmtstart="46" stmtend="180" sqlhandle="0x02000000b6b6e728e6bf289c908196a1f4e56b8892a5eab10000000000000000000000000000000000000000">
unknown    </frame></executionStack><inputbuf>
(@P0 bigint,@P1 bigint)update Table_Name set STATUS_ID= @P0  where id= @P1    </inputbuf></process></process-list><resource-list><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2f6d828c8" mode="S"/><owner id="process2da9b5468" mode="S"/><owner id="process2f6d828c8" mode="IX" requestType="convert"/><owner id="process2da9b5468" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2ff017c28" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f6d828c8" mode="S"/><owner id="process2da9b5468" mode="S"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2f6d828c8" mode="IX" requestType="convert"/><owner id="process2da9b5468" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2f1538108" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f6d828c8" mode="S"/><owner id="process2da9b5468" mode="S"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2f6d828c8" mode="IX" requestType="convert"/><owner id="process2da9b5468" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2f618d088" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f618d088" mode="S"/><owner id="process2da9b5468" mode="S"/><owner id="process2f618d088" mode="IX" requestType="convert"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2da9b5468" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2f6d828c8" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f618d088" mode="S"/><owner id="process2da9b5468" mode="S"/><owner id="process2f618d088" mode="IX" requestType="convert"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2da9b5468" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2f6d83848" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f6d83848" mode="S"/><owner id="process2efac7848" mode="S"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2efac7848" mode="IX" requestType="convert"/><owner id="process2f6d83848" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2da9b5468" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f6d83848" mode="S"/><owner id="process2efac7848" mode="S"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2efac7848" mode="IX" requestType="convert"/><owner id="process2f6d83848" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2efac7468" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f6d83848" mode="S"/><owner id="process2efac7468" mode="S"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2efac7468" mode="IX" requestType="convert"/><owner id="process2f6d83848" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2efac7848" mode="IX" requestType="convert"/></waiter-list></objectlock><objectlock lockPartition="0" objid="1142295129" subresource="FULL" dbid="11" objectname="Database_Name.Schema_Name.Table_Name" id="lock2149d8800" mode="S" associatedObjectId="1142295129"><owner-list><owner id="process2ff017c28" mode="S"/><owner id="process2f6d83848" mode="S"/><owner id="process2efac7468" mode="S"/><owner id="process2ff017c28" mode="IX" requestType="convert"/><owner id="process2efac7468" mode="IX" requestType="convert"/><owner id="process2f6d83848" mode="IX" requestType="convert"/></owner-list><waiter-list><waiter id="process2efac7c28" mode="IX" requestType="convert"/></waiter-list></objectlock></resource-list></deadlock>

Isolation level is set as Read Committed Snapshot.

When I opened this deadlock graph in Sentry One plan Explorer, it was scary.

Deadlock Graph Sentry Plan Explorer

Version: Microsoft SQL Server 2014 (SP3) (KB4022619) - 12.0.6024.0 (X64) Sep 7 2018 01:37:51 Copyright (c) Microsoft Corporation Enterprise Edition (64-bit) on Windows NT 6.3 (Build 14393: ) (Hypervisor)

9

Your default isolation level might be Read Committed Snapshot, but the isolation level set by your application = repeatable read (3)

For all the update statements in the deadlock, these are the isolationlevels:

isolationlevel="repeatable read (3)"

This is done at the connection level with this command:

SET TRANSACTION ISOLATION LEVEL REPEATABLE READ

the Repeatable Read SQL Server isolation level prevents dirty reads and not-repeatable reads. It is achieved by placing shared locks on all data that is read by each statement in a transaction and all the locks are held until the transaction completes. As a result other transactions are unable to modify the data that has been read by the current transaction. However, it does not prevent other transactions from inserting new rows into the tables which have been selected in the current transaction A part of the explanation on repeatable read here

Transactions blocking eachother, with lock escalation under the repeatable read isolation level can cause blocking and as a byproduct of blocking, deadlocks.

The blocked queries where waiting on the resource:

waitresource="OBJECT: 11:1142295129:0 "

Where the several processes have Shared locks on this entire object:

<owner id="process2ff017c28" mode="S"/><owner id="process2f6d828c8" mode="S"/><owner id="process2da9b5468" mode="S"/>

and these same processes have several intent exclusive locks on these objects

 <owner id="process2f6d828c8" mode="IX" requestType="convert"/>

Whereas the requestType="convert" explains that the processes are trying to convert the shared lock into an IX lock.

And as @David Browne - Microsoft explained:

In Repeatable Read the object-level S locks that conflict with the pending IX locks could have been acquired on an earlier query in the transaction.

Meaning that a reasonable explanation is that all these transactions are trying to convert their own shared lock (e.g. because of a previous select) into an Exclusive lock (Update statement). As a result of being in the repeatable read isolation level they do not want to give up their locks, resulting in deadlocks.

What can you do

You should contact the application team / vendor and see if this a necessary evil, because blocking will be more prevalent.

Next to checking up on the isolation level, you should look into speeding up the queries inside the transactions by adding indexes.

  • This morning managed to get vendor to change the setting of isolation level from Repeatable Read to Read Committed and in last 6 hours not even a single deadlock is encountered. Earlier every hour we used to have more than 5-6 deadlocks in working hour. Thanks a lot for your help, this was great answer. Disabling Implicit transaction seems to be not feasible at this point as vendor needs to do code change. – Learning_DBAdmin Apr 15 at 12:20
  • 1
    @Learning_DBAdmin Great to hear! Happy to help, thanks for your kind words! – Randi Vertongen Apr 15 at 12:57
12

This definitely seems to be a bad combination of isolation level, lock escalation, and many sessions each issuing multiple queries inside the same transaction.

If you expand the waiter/owner list you see they are all trying to access the same resource (presumably the entire table):

enter image description here

Also a slightly less scary way to see this is to optimize layout and use force directed:

enter image description here

If you replay the deadlock you will see all of these different sessions holding their transactions open for relatively long periods of time (5+ minutes, which is crazy, though the animation really hides that), and issuing multiple queries intermittently. You need to drastically reduce the amount of time you spend inside those transactions (or get rid of them altogether), collapse multiple queries for different parameter values into a single, point-in-time query, build better indexes so that escalation doesn't happen, stop forcing repeatable read, created a clustered index (if I'm reading the resource descriptor right, that's a heap!?), or all of the above.

9

Another problem in your XML graph is that you appear to have "implicit_transactions" turned on:

transactionname="implicit_transaction"

This can also lead to blocking if the application doesn't explicitly close transactions. This can be set at the connection level, or by calling SET IMPLICIT TRANSACTIONS ON explicitly.

Check out these times:

screenshot of Plan Explorer deadlock graph

You have transactions that started at 15:25:26 that are still running at 15:30:58. Five minutes is usually way too long to be holding locks - it's a recipe for blocking and deadlocks. This seems like potentially an accidental open lingering transaction.

If you have any control over the application's connection string, verify that they are not turning this setting on. Also, double check that this isn't set at the server level via sp_configure 'user options (see here for more detail).

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.