SQL Server - Deadlock during two concurrent DELETE

Question

I've got a Java app exposing a REST API to delete records in a table (SQL Server), sometimes the API must handle concurrent deletion requests (each request uses a different DB session)

Here is an extract of the DB schema:

MailingInstruction
------------------
id (PK)
[...]
addressId (FK to Address table)

Address
------------------
id (PK)
street
street_nr
[...]

The deletion of a MailingInstruction record triggers a cascade deletion of the associated Address. Each MailingInstruction has a dedicated Address (no re-use)

But from time to time, one of the concurrent delete fails because of a deadlock:

Transaction (Process ID 51) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

So I enabled some logs:

DBCC TRACEON(1222, 3605,-1)

And it seems the problem is a DELETE on Address record which is strange because as I delete by primary key I thought the lock would be only on the specific record.

Here is the deadlock trace:

2021-09-17 09:53:53.39 spid15s deadlock-list 2021-09-17 09:53:53.39 spid15s deadlock victim=process80ba33848 2021-09-17 09:53:53.40 spid15s process-list 2021-09-17 09:53:53.40 spid15s process id=process80ba33848 taskpriority=0 logused=348 waitresource=KEY: 5:72057594043564032 (e82f06e0affb) waittime=1424 ownerId=30578 transactionname=implicit_transaction lasttranstarted=> 2021-09-17T09:53:51.967 XDES=0x113be80420 lockMode=S schedulerid=4 kpid=684 status=suspended spid=51 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=> 2021-09-17T09:53:51.970 lastbatchcompleted=> 2021-09-17T09:53:51.967 lastattention=1900-01-01T00:00:00.967 clientapp=Microsoft JDBC Driver for SQL Server hostname=MY-DESKTOP hostpid=0 loginname=sa isolationlevel=read committed (2) xactid=30578 currentdb=5 currentdbname=MY_DB lockTimeout=4294967295 clientoption1=671088672 clientoption2=128058 2021-09-17 09:53:53.44 spid15s executionStack 2021-09-17 09:53:53.45 spid15s frame procname=adhoc line=1 stmtstart=24 stmtend=100 sqlhandle=0x02000000627bbe0c9854b43c4ee3d7183c254e990331f4e80000000000000000000000000000000000000000 2021-09-17 09:53:53.46 spid15s unknown 2021-09-17 09:53:53.46 spid15s frame procname=unknown line=1 sqlhandle=0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 2021-09-17 09:53:53.47 spid15s unknown 2021-09-17 09:53:53.47 spid15s inputbuf 2021-09-17 09:53:53.47 spid15s (@P0 bigint)delete from Address where addressId=@P0 2021-09-17 09:53:53.48 spid15s process id=process80ba1f088 taskpriority=0 logused=352 waitresource=KEY: 5:72057594043564032 (036d9ed30da4) waittime=1424 ownerId=30579 transactionname=implicit_transaction lasttranstarted=> 2021-09-17T09:53:51.967 XDES=0x1137680420 lockMode=S schedulerid=2 kpid=604 status=suspended spid=53 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=> 2021-09-17T09:53:51.970 lastbatchcompleted=> 2021-09-17T09:53:51.967 lastattention=1900-01-01T00:00:00.967 clientapp=Microsoft JDBC Driver for SQL Server hostname=MY-DESKTOP hostpid=0 loginname=sa isolationlevel=read committed (2) xactid=30579 currentdb=5 currentdbname=MY_DB lockTimeout=4294967295 clientoption1=671088672 clientoption2=128058 2021-09-17 09:53:53.51 spid15s executionStack 2021-09-17 09:53:53.52 spid15s frame procname=adhoc line=1 stmtstart=24 stmtend=100 sqlhandle=0x02000000627bbe0c9854b43c4ee3d7183c254e990331f4e80000000000000000000000000000000000000000 2021-09-17 09:53:53.53 spid15s unknown 2021-09-17 09:53:53.53 spid15s frame procname=unknown line=1 sqlhandle=0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 2021-09-17 09:53:53.54 spid15s unknown 2021-09-17 09:53:53.54 spid15s inputbuf 2021-09-17 09:53:53.54 spid15s (@P0 bigint)delete from Address where addressId=@P0 2021-09-17 09:53:53.55 spid15s resource-list 2021-09-17 09:53:53.55 spid15s keylock hobtid=72057594043564032 dbid=5 objectname=MY_DB.dbo.MailingInstruction indexname=PK__MailingI__F3FD20CC83FED272 id=lock1146070b80 mode=X associatedObjectId=72057594043564032 2021-09-17 09:53:53.56 spid15s owner-list 2021-09-17 09:53:53.56 spid15s owner id=process80ba1f088 mode=X 2021-09-17 09:53:53.57 spid15s waiter-list 2021-09-17 09:53:53.57 spid15s waiter id=process80ba33848 mode=S requestType=wait 2021-09-17 09:53:53.57 spid15s keylock hobtid=72057594043564032 dbid=5 objectname=MY_DB.dbo.MailingInstruction indexname=PK__MailingI__F3FD20CC83FED272 id=lock11393baa00 mode=X associatedObjectId=72057594043564032 2021-09-17 09:53:53.58 spid15s owner-list 2021-09-17 09:53:53.59 spid15s owner id=process80ba33848 mode=X 2021-09-17 09:53:53.59 spid15s waiter-list 2021-09-17 09:53:53.59 spid15s waiter id=process80ba1f088 mode=S requestType=wait

Any idea why the deletion of two different records triggers this deadlock ?

Thank you

Answer 1

And it seems the problem is a DELETE on Address record which is strange because as I delete by primary key I thought the lock would be only on the specific record.

Sure, on Address. But then it scans MailingInstruction to implement the cascade delete.

The leading cause of deadlocks on cascade delete is not having proper indexing on your Foreign Keys. AddressID must at a minimum have an index, and preferably it's the leading column of the Primary Key of MailingInstruction.

Answer 2

Lead Docks

One problem you may be running into is around implicit transactions, which are the default for the JDBC driver. You can verify this in the deadlock details you posted: transactionname=implicit_transaction.

You can change this by using con.setAutoCommit(true); in your connection string.

Somewhat Interesting

A point of interest is that the lock mode for this delete is shared: lockMode=S. That may indicate there's a lookup involved in the query plan.

You can get the plan for the delete by running this query, as long as it's still in the plan cache.

SELECT
    qs.last_execution_time,
    qs.execution_count,
    qs.total_worker_time,
text = 
    SUBSTRING
    (
        st.text, 
        ( qs.statement_start_offset / 2 ) + 1,
        (
          ( 
            CASE qs.statement_end_offset 
                 WHEN -1 
                 THEN DATALENGTH(st.text) 
                 ELSE qs.statement_end_offset 
            END - qs.statement_start_offset 
          ) / 2 
        ) + 1
    ),
    query_plan =
        TRY_CAST(qp.query_plan AS xml)
FROM sys.dm_exec_query_stats AS qs  
CROSS APPLY sys.dm_exec_sql_text
(
    qs.sql_handle
) AS st  
CROSS APPLY sys.dm_exec_text_query_plan 
(
    qs.plan_handle,
    qs.statement_start_offset,
    qs.statement_end_offset
) AS qp
WHERE qs.sql_handle = 0x02000000E1E2A73A5B449F98DAE6C300BE7E0DBC30E139D00000000000000000000000000000000000000000;

It could also indicate that there are other queries in the batch along with the delete that aren't showing up in the deadlock graph, because deadlock graphs are hot garbage.

Generality

If you're going to continue using implicit transactions, it would behoove you to turn on Read Committed Snapshot Isolation to avoid other complications with the absurd locking that takes place under the Read Committed isolation level, which is also hot garbage.

You can turn that on like so, just sub in your database name:

ALTER DATABASE 
    StackOverflow 
SET READ_COMMITTED_SNAPSHOT ON 
    WITH ROLLBACK IMMEDIATE;