一、背景

我们在UAT环境压测的时候,遇到了如下的死锁异常。

Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 82) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

我们立即 查看应用日志,找到报错的方法查看,发现在一个方法对同一张表进行了3种操作,先INSERT,然后SELECT,最后DELETE。也就是说在同一个事务中,对同一张表先插入,然后查询,最后根据查询结果删除。此时,我大概意识到问题所在了。但是UAT环境中,SQL Server数据库是部署在客户侧的,不太好拿死锁报告。所以我决定在本地模拟出来这个死锁问题,然后进行修复。

二、本地模拟死锁

1.业务场景简介

我们有一张userToken表,核心字段有id、loginId和token,主要用来记录用户的登录token,用来控制系统中一个用户能不能多次登录。

我们出现死锁问题的方法是登录方法,该方法在登录时会向userToken表中插入一条数据,插入成功之后回去第三方检查这个用户的状态等是否正常,因为用户数据是第三方维护的。如果检查结果是这个用户状态不可用,那么就会去删除这个用户的token数据,同时给前端返回相应的异常信息。问题就出在删除的时候,是先根据用户的loginId去查询出该用户的所有token数据,然后找出本次登录的token数据,进行删除。为什么这里有问题后面我们再详细说明。

2.在本地模拟死锁
1). 准备数据

要模拟这个死锁场景,可以在 SQL Server Management Studio (SSMS) 或者DBeaver中创建一个简单的脚本,我使用的是DBeaver也很好用。使用以下存储过程代码:

-- 1.创建一个示例 userToken 表
CREATE TABLE userToken (
    id INT IDENTITY(1,1) PRIMARY KEY,
    loginId VARCHAR(50),
    token VARCHAR(50)
);

-- 2.创建一个存储过程,以模拟登录过程
CREATE PROCEDURE sp_Login
    @loginId VARCHAR(50)
AS
BEGIN
    -- 插入一个新记录
    INSERT INTO userToken (loginId, token) VALUES (@loginId, 'token_' + CONVERT(VARCHAR(50), NEWID()));

    WAITFOR DELAY '00:00:05'; -- 模拟延迟,更容易发生死锁
    -- 选择和删除记录
    DECLARE @id INT;
    SELECT @id = id FROM userToken WHERE loginId = @loginId;
    DELETE FROM userToken WHERE id = @id;
END;

-- 3. 在第一个窗口中模拟第一个线程

DECLARE @loginId VARCHAR(50) = 'user';

BEGIN TRANSACTION;
EXEC sp_Login @loginId;
COMMIT TRANSACTION;

-- 4. 在第二个窗口中模拟第二个线程
DECLARE @loginId VARCHAR(50) = 'user';

BEGIN TRANSACTION;
EXEC sp_Login @loginId;
COMMIT TRANSACTION;

-- 5. 在两个窗口中同时运行,模拟并发登录,并观察执行结果

2).执行存储过程并观察死锁发生

按照上面的步骤创建表和存储过程,并分别在两个窗口中同时执行。可能需要执行多次才能出现死锁。如果出现下面的两种之一,就说明已经发生了死锁。

情况一:

数据库连接工具控制台出现以下错误:SQL Error [1205] [40001]: Transaction (Process ID 63) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

情况二:

通过sqlserver自带的扩展事件[system_health]查看死锁的详细信息,执行下面的sql如果表格中有数据则已经发生了死锁。

SELECT xdr.value('@timestamp', 'datetime') AS [Date],
    xdr.query('.') AS [Event_Data]
FROM (SELECT CAST([target_data] AS XML) AS Target_Data
            FROM sys.dm_xe_session_targets AS xt
            INNER JOIN sys.dm_xe_sessions AS xs ON xs.address = xt.event_session_address
            WHERE xs.name = N'system_health'
              AND xt.target_name = N'ring_buffer'
    ) AS XML_Data
CROSS APPLY Target_Data.nodes('RingBufferTarget/event[@name="xml_deadlock_report"]') AS XEventData(xdr)
ORDER BY [Date] DESC;

如上图,已经发生死锁。

三、死锁的详细分析

1.查看死锁报告

在上面第二步中,我们通过sqlserver自带的扩展事件[system_health]先拿到了死锁报告。如下:

<event name="xml_deadlock_report" package="sqlserver" timestamp="2024-05-10T07:53:31.599Z">
    <data name="xml_report">
        <type name="xml" package="package0"/>
        <value>
            <deadlock>
                <victim-list>
                    <victimProcess id="process19f4497c108"/>
                </victim-list>
                <process-list>
                    <process id="process19f4497c108" taskpriority="0" logused="284" waitresource="KEY: 6:72057594058768384 (e8a66f387cfa)" waittime="3342" ownerId="50677" transactionname="user_transaction" lasttranstarted="2024-05-10T15:53:23.250" XDES="0x19f4c400428" lockMode="S" schedulerid="3" kpid="7120" status="suspended" spid="63" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2024-05-10T15:53:23.250" lastbatchcompleted="2024-05-10T15:51:07.110" lastattention="1900-01-01T00:00:00.110" clientapp="DBeaver 24.0.2 - SQLEditor &lt;Script-7.sql&gt;" hostname="NCSCND13691RVD0" hostpid="30508" loginname="sa" isolationlevel="read committed (2)" xactid="50677" currentdb="6" currentdbname="deadLockDatabase" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
                        <executionStack>
                            <frame procname="deadLockDatabase.dbo.sp_Login" line="11" stmtstart="590" stmtend="698" sqlhandle="0x03000600dfe61621f0cd05016cb1000001000000000000000000000000000000000000000000000000000000">
                                SELECT @id = id FROM userToken WHERE loginId = @loginI    
                            </frame>
                            <frame procname="adhoc" line="4" stmtstart="124" stmtend="166" sqlhandle="0x02000000b95c920287375badb00b99eeb827a3f3037c6bda0000000000000000000000000000000000000000">
                                unknown    
                            </frame>
                        </executionStack>
                        <inputbuf>
                            DECLARE @loginId VARCHAR(50) = 'user';

                            BEGIN TRANSACTION;
                            EXEC sp_Login @loginId;
                            COMMIT TRANSACTION;   
                        </inputbuf>
                    </process>
                    <process id="process19f4497e4e8" taskpriority="0" logused="284" waitresource="KEY: 6:72057594058768384 (11ea04af99f6)" waittime="2677" ownerId="50681" transactionname="user_transaction" lasttranstarted="2024-05-10T15:53:23.917" XDES="0x19f4ffdc428" lockMode="S" schedulerid="2" kpid="1248" status="suspended" spid="62" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2024-05-10T15:53:23.913" lastbatchcompleted="2024-05-10T15:52:46.183" lastattention="1900-01-01T00:00:00.183" clientapp="DBeaver 24.0.2 - SQLEditor &lt;Script-2.sql&gt;" hostname="NCSCND13691RVD0" hostpid="30508" loginname="sa" isolationlevel="read committed (2)" xactid="50681" currentdb="6" currentdbname="deadLockDatabase" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
                        <executionStack>
                            <frame procname="deadLockDatabase.dbo.sp_Login" line="11" stmtstart="590" stmtend="698" sqlhandle="0x03000600dfe61621f0cd05016cb1000001000000000000000000000000000000000000000000000000000000">
                            SELECT @id = id FROM userToken WHERE loginId = @loginI    
                            </frame>
                            <frame procname="adhoc" line="5" stmtstart="128" stmtend="170" sqlhandle="0x020000009bc16a079a9d61241dde15013e2cc413cd9c26920000000000000000000000000000000000000000">
                                unknown    
                            </frame>
                        </executionStack>
                        <inputbuf>
                            DECLARE @loginId VARCHAR(50) = 'user';

                            BEGIN TRANSACTION;
                            EXEC sp_Login @loginId;
                            COMMIT TRANSACTION;   
                        </inputbuf>
                    </process>
                </process-list>
                <resource-list>
                    <keylock hobtid="72057594058768384" dbid="6" objectname="deadLockDatabase.dbo.userToken" indexname="PK__userToke__3213E83FCAB09E1A" id="lock19f4f504a00" mode="X" associatedObjectId="72057594058768384">
                        <owner-list>
                            <owner id="process19f4497e4e8" mode="X"/>
                        </owner-list>
                        <waiter-list>
                            <waiter id="process19f4497c108" mode="S" requestType="wait"/>
                        </waiter-list>
                    </keylock>
                    <keylock hobtid="72057594058768384" dbid="6" objectname="deadLockDatabase.dbo.userToken" indexname="PK__userToke__3213E83FCAB09E1A" id="lock19f4f509180" mode="X" associatedObjectId="72057594058768384">
                        <owner-list>
                            <owner id="process19f4497c108" mode="X"/>
                        </owner-list>
                        <waiter-list>
                            <waiter id="process19f4497e4e8" mode="S" requestType="wait"/>
                        </waiter-list>
                    </keylock>
                </resource-list>
            </deadlock>
        </value>
    </data>
</event>
2.分析死锁报告

首先,在死锁发生的过程中,我们可以通过以下sql查询当前表锁持有的锁有哪些。

--将userToken换成自己的表名
SELECT * FROM sys.dm_tran_locks WHERE resource_type = 'OBJECT' AND resource_database_id = DB_ID() AND resource_associated_entity_id = OBJECT_ID('userToken');

我们可以看到在死锁发生的过程中,userToken表上有2把IX锁(意向排他锁)。应该就是上面执行存储过程中的2条INSERT语句产生的。

接下来,我们来详细分析一下死锁报告的内容,以了解为什么会出现死锁。

a.牺牲的进程

从报告上我们可以看到<victimProcess>,牺牲的进程是 process19f4497c108,它被suspend并等待共享锁在一个关键资源上。在sqlserver中当发生死锁时,sqlserver会选择牺牲其中的一个死锁,释放它所持有的锁,从而打破死循环。

b.进程列表

通过<process-list>我们可以看到本次有两个进程参与了死锁。

process19f4497c108(被牺牲的进程)
process19f4497e4e8

两个进程都在执行 sp_Login 存储过程,该过程将新记录插入到 userToken 表中,然后根据 loginId 列选择和删除记录。从<executionStack>可以看到是在执行SELECT @id = id FROM userToken WHERE loginId = @loginId的时候阻塞了,也就是去根据loginId去查询的时候阻塞了。

这两个进程分别等待的资源是:KEY: 6:72057594058768384 (e8a66f387cfa)和KEY: 6:72057594058768384 (11ea04af99f6)。

KEY值的含义KEY表示等待的资源是一个键,也就是索引中的特定行或行范围。以KEY: 6:72057594058768384 (e8a66f387cfa)为例。6代表数据库id,72057594058768384代表被锁索引(index)的id,也就是某一个索引,(e8a66f387cfa)代表索引中内部id,也就是在该索引中具体是哪一行,可以帮我们定位到表中特定的数据行。

关于前两个,比较简单可以通过系统表查询出来。

--72057594058768384替换为死锁报告中的KEY: 6:72057594058768384 (e8a66f387cfa)的中间数字部分
select db_id() as database_id, o. name, i. name, i. type from sys. indexes i
	inner join sys.objects o on i.object_id = o.object_id
	inner join sys.partitions p on p.index_id = i.index_id and p. object_id = i. object_id
where p.partition_id = 72057594058768384

从下面的结果中可以看到和报告下面index_name一致,锁定就是主键索引

关于(e8a66f387cfa)代表索引中内部id,可以通过一个未公布的系统函数 %%lockres%% 查看得到,如下

with cte as 
(
	select %%lockres%% as resource_key, id from userToken with(index(PK__userToke__3213E83FCAB09E1A))--替换为自己的表名和死锁报告中冲突的索引
)
select * from cte where resource_key in ( '(e8a66f387cfa)', '(11ea04af99f6)');--替换为死锁报告中等待的resource_key
c.资源列表

从<resource-list>中可以看到,有两个关键的锁在userToken表上。

lock19f4f504a00:由 process19f4497e4e8 拥有,具有排他(X)锁模式
lock19f4f509180:由 process19f4497c108 拥有,具有排他(X)锁模式

死锁发生是因为每个进程都在等待共享锁在一个资源上(userToken 表的 PK__userToke__3213E83FCAB09E1A 索引),而该资源已经被另一个进程以排他锁模式拥有的。

d.死锁场景

下面是死锁报告中描述的死锁场景:

  • process19f4497c108将一条新记录插入到userToken表中,并获取了索引(PK__userToke__3213E83FCAB09E1A)的排他锁(mode='X')。
  • process19f4497e4e8将一条新记录插入到userToken表中,并获取了索引(PK__userToke__3213E83FCAB09E1A)的排他锁(mode='X')。
  • process19f4497c108 尝试根据 loginId 去查询userToken表中的数据,由于process19f4497e4e8 持有了索引的排他锁,所以process19f4497c108必须等待锁的释放。
  • process19f4497e4e8 尝试根据 loginId 去查询userToken表中的数据,由于process19f4497c108持有了索引的排他锁,所以process19f4497e4e8 必须等待锁的释放。
  • 此时,两个进程都在等待对方释放锁,结果导致死锁。
e.结论 

死锁是由于 sp_Login 存储过程的并发执行导致的,这导致了 userToken 表上的争用。每个进程在 索引上的排他锁阻止了另一个进程执行其选择和删除操作,导致死锁。因为两个进程都持有了 userToken 表的 PK__userToke__3213E83FCAB09E1A 索引的排他锁(mode='X'),每个进程都在等待另一个进程释放其锁。

要解决这个问题,我们可以优化存储过程以减少 userToken 表上的争用。

四、解决死锁问题 

有了上面对死锁报告的详细分析,我们了解到了死锁产生的原因是锁竞争。那么我们可以减少一层锁,以避免锁的竞争。修改后存储过程如下:

-- 2.创建一个存储过程,以模拟登录过程
CREATE PROCEDURE sp_Login
    @loginId VARCHAR(50)
AS
BEGIN
    -- 插入一个新记录
    INSERT INTO userToken (loginId, token) VALUES (@loginId, 'token_' + CONVERT(VARCHAR(50), NEWID()));

    -- 直接根据loginId删除记录,减少一次查询,减少一次S锁的获取
    DELETE FROM userToken WHERE loginId = @loginId;
END;

-- 3. 在第一个窗口中模拟第一个线程

DECLARE @loginId VARCHAR(50) = 'user1';

BEGIN TRANSACTION;
EXEC sp_Login @loginId;
COMMIT TRANSACTION;

-- 4. 在第二个窗口中模拟第二个线程
DECLARE @loginId VARCHAR(50) = 'user2';

BEGIN TRANSACTION;
EXEC sp_Login @loginId;
COMMIT TRANSACTION;

-- 5. 在两个窗口中同时运行,模拟并发登录,并观察执行结果

 再次多次执行上面的存储过程,没有再遇到过死锁了。

新的存储过程分析:

在这个修改后的场景中,我们可以看到,每个窗口中都执行了一个事务,该事务包括插入一条记录、删除该记录、并提交事务。

在这种情况下,死锁的可能性非常小,因为每个窗口中的事务都是自包含的,不会等待另一个窗口中的事务释放锁。

  • 当第一个窗口执行 INSERT 语句时,它会获取该索引的 X 锁,并插入一条记录。然后,它执行 DELETE 语句,删除该记录,并释放 X 锁。最后,它提交事务。
  • 同样,第二个窗口执行 INSERT 语句时,它会获取该索引的 X 锁,并插入一条记录。然后,它执行 DELETE 语句,删除该记录,并释放 X 锁。最后,它提交事务。
  • 由于每个窗口中的事务都是独立的,不会等待另一个窗口中的事务释放锁,因此死锁的可能性非常小。

通过以上步骤,成功解决这个死锁问题。 

Logo

旨在为数千万中国开发者提供一个无缝且高效的云端环境,以支持学习、使用和贡献开源项目。

更多推荐