SEa*_*986 10 sql-server deadlock blocking sql-server-2016
我遇到过一种情况,用户在我们的一个运行存储过程的应用程序中运行了某些内容。存储过程执行一些日志记录(INSERT
记录到日志表),然后以以下格式执行简单的删除
DELETE FROM MyTable WHERE Id = 1
从具有数百万行的表中删除DELETE
数万条记录(存储过程对多个表执行此操作)并生成并行执行计划。Id 列是复合主键中的第二列,但该表没有任何以该列开头的索引。
删除计划可在此处获取
表的匿名 DDL 如下
CREATE TABLE [dbo].MyTable
(
[Column15] [varchar](50) NULL,
[Column16] [int] NULL,
[Column2] [datetime] NULL,
[Column3] [datetime] NULL,
[Column4] [varchar](50) NOT NULL,
[Column5] [datetime] NULL,
[Column17] [varchar](8) NULL,
[Column18] [varchar](50) NULL,
[Column6] [int] NULL,
[Column7] [int] NULL,
[Column9] [int] NULL,
[Column8] [int] NULL,
[Column19] [varchar](50) NULL,
[Column20] [varchar](50) NULL,
[Column21] [varchar](50) NULL,
[Column22] [varchar](50) NULL,
[Column23] [varchar](50) NULL,
[Column24] [varchar](50) NULL,
[Column25] [varchar](50) NULL,
[Column26] [varchar](50) NULL,
[Column10] [datetime] NULL,
[Column27] [varchar](50) NULL,
[Column28] [varchar](50) NULL,
[Column29] [varchar](50) NULL,
[Column30] [varchar](50) NULL,
[Column31] [varchar](50) NULL,
[Column32] [datetime] NULL,
[Column33] [datetime] NULL,
[Column34] [int] NULL,
[Column35] [varchar](50) NULL,
[Column11] [char](1) NULL,
[Column36] [char](1) NULL,
[Column12] [char](1) NULL,
[Column37] [char](1) NULL,
[Column38] [char](1) NULL,
[Column39] [char](1) NULL,
[Column40] [char](1) NULL,
[Column41] [char](1) NULL,
[Column42] [datetime] NULL,
[Column13] [varchar](50) NULL,
[Column43] [varchar](50) NULL,
[Column44] [varchar](50) NULL,
[Column45] [varchar](50) NULL,
[Column46] [varchar](50) NULL,
[Column47] [varchar](50) NULL,
[Column48] [varchar](50) NULL,
[Column49] [varchar](50) NULL,
[Column50] [varchar](255) NULL,
[Column51] [varchar](50) NULL,
[Column52] [varchar](50) NULL,
[Column53] [varchar](50) NULL,
[Column54] [varchar](50) NULL,
[Column55] [varchar](50) NULL,
[Column56] [varchar](50) NULL,
[Column57] [varchar](50) NULL,
[Column58] [varchar](50) NULL,
[Column59] [varchar](50) NULL,
[Column60] [varchar](50) NULL,
[Column61] [varchar](50) NULL,
[Column62] [varchar](50) NULL,
[Column63] [varchar](50) NULL,
[Column64] [int] NOT NULL,
[Column65] [varchar](50) NULL,
[Column66] [varchar](255) NULL,
[Column67] [varchar](50) NULL,
[Column68] [varchar](50) NULL,
[Column14] [varchar](50) NOT NULL,
[Column69] [varchar](50) NULL,
[Column70] [varchar](255) NULL,
[Column71] [varchar](50) NULL,
[Column72] [int] NULL,
[Column73] [varchar](50) NULL,
[Column74] [varchar](255) NULL,
[Column75] [varchar](50) NULL,
[Column76] [varchar](255) NULL,
[Column77] [varchar](50) NULL,
[Column78] [varchar](50) NULL,
[Column79] [varchar](255) NULL,
[Column80] [varchar](50) NULL,
[Column81] [varchar](50) NULL,
[Column82] [char](1) NULL,
[Column83] [char](1) NULL,
[Column84] [date] NULL,
[Column85] [date] NULL,
[Column86] [date] NULL,
[Column87] [date] NULL,
[Column88] [date] NULL,
CONSTRAINT [MyConstraintName] PRIMARY KEY CLUSTERED
(
[Columnn4] ASC,
[Column1] ASC,
[Column14] ASC
)
WITH
(
PAD_INDEX = OFF,
STATISTICS_NORECOMPUTE = OFF,
IGNORE_DUP_KEY = OFF,
ALLOW_ROW_LOCKS = ON,
ALLOW_PAGE_LOCKS = ON
)
)
GO
ALTER TABLE [dbo].[MyTable] ADD DEFAULT ('MyDefault') FOR [COLUMN_14]
GO
CREATE NONCLUSTERED INDEX [IDX_MyTable] ON [dbo].[MyTable]
(
[Column11] ASC,
[Column12] ASC,
[Column10] ASC,
[Column9] ASC,
[Column8] ASC,
[Column5] ASC,
[Column2] ASC,
[Column3] ASC,
[Column13] ASC,
[Column6] ASC,
[Column7] ASC
)
WITH
(
PAD_INDEX = OFF,
STATISTICS_NORECOMPUTE = OFF,
SORT_IN_TEMPDB = OFF,
DROP_EXISTING = OFF,
ONLINE = OFF,
ALLOW_ROW_LOCKS = ON,
ALLOW_PAGE_LOCKS = ON
)
Run Code Online (Sandbox Code Playgroud)
用户报告说应用程序没有执行任何操作,当我使用查看 SQL Server 时sp_whoisactive
,我可以看到似乎出现了死锁:
我们可以看到会话 98、99 和 69 被 107 阻塞,但 107 被 69 阻塞,因此 69 和 107 之间存在死锁 - 它们都在等待其他释放锁?
我抓取了sp_whoisactive @get_locks = 1
每个 69 和 107 的输出,可以看到它们似乎都已被授予索引上的页面锁定(尽管我们看不到哪个页面),并且正在等待索引内不同页面上的锁定:
<Database name="MyDB">
<Locks>
<Lock request_mode="S" request_status="GRANT" request_count="1" />
</Locks>
<Objects>
<Object name="Mytable" schema_name="dbo">
<Locks>
<Lock resource_type="OBJECT" request_mode="IX" request_status="GRANT" request_count="9" />
<Lock resource_type="PAGE" page_type="*" index_name="IDX_Mytable" request_mode="U" request_status="GRANT" request_count="337" />
<Lock resource_type="PAGE" page_type="*" index_name="IDX_MyTable" request_mode="U" request_status="WAIT" request_count="8" />
</Locks>
</Object>
</Objects>
</Database>
<Database name="MyDB">
<Locks>
<Lock request_mode="S" request_status="GRANT" request_count="1" />
</Locks>
<Objects>
<Object name="MyTable" schema_name="dbo">
<Locks>
<Lock resource_type="OBJECT" request_mode="IX" request_status="GRANT" request_count="9" />
<Lock resource_type="PAGE" page_type="*" index_name="IDX_MyTable" request_mode="U" request_status="GRANT" request_count="685415" />
<Lock resource_type="PAGE" page_type="*" index_name="IDX_MyTable" request_mode="U" request_status="WAIT" request_count="4" />
</Locks>
</Object>
</Objects>
</Database>
<Database name="tempdb">
<Objects>
<Object name="(null)">
<Locks>
<Lock resource_type="DATABASE.ENCRYPTION_SCAN" request_mode="S" request_status="GRANT" request_count="2" />
</Locks>
</Object>
</Objects>
</Database>
Run Code Online (Sandbox Code Playgroud)
果然,我KILL
完成了第 69 节课,其余三节课也完成了。
以下是会话 69 和 107 之间的块进程报告(有趣的是,会话 69 自身阻塞的块报告!?):
69 封锁 107
<event name="blocked_process_report" package="sqlserver" timestamp="2022-06-01T09:36:33.217Z">
<data name="duration">
<value>5291794000</value>
</data>
<data name="database_id">
<value>7</value>
</data>
<data name="object_id">
<value>0</value>
</data>
<data name="index_id">
<value>0</value>
</data>
<data name="lock_mode">
<value>4</value>
<text>U</text>
</data>
<data name="transaction_id">
<value>4524669110</value>
</data>
<data name="resource_owner_type">
<value>0x00000001</value>
<text>LOCK</text>
</data>
<data name="blocked_process">
<value>
<blocked-process-report monitorLoop="386256">
<blocked-process>
<process id="processf491f8a4e8" taskpriority="0" logused="0" waitresource="PAGE: 7:8:40517682 " waittime="5291794" ownerId="4524669110" transactionname="DELETE" lasttranstarted="2022-06-01T09:08:12.210" XDES="0xfc5d2fdc40" lockMode="U" schedulerid="11" kpid="78972" status="suspended" spid="107" sbid="0" ecid="2" priority="0" trancount="0" lastbatchstarted="2022-06-01T09:06:18.560" lastbatchcompleted="2022-06-01T09:06:18.550" lastattention="1900-01-01T00:00:00.550" clientapp=".Net SqlClient Data Provider" hostname="MyServer" hostpid="52940" isolationlevel="read committed (2)" xactid="4524669110" currentdb="7" currentdbname="MyDB" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000003320a71f1f003704cf13be99833b422d70e704c70000000000000000000000000000000000000000" />
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000009d132a27f589a9771a2be6d262e2dcecf057db6d0000000000000000000000000000000000000000" />
<frame line="61" stmtstart="5794" stmtend="5814" sqlhandle="0x030007007d01b22be394d50083ae000001000000000000000000000000000000000000000000000000000000" />
<frame line="1" stmtend="90" sqlhandle="0x01000700990d272800ffb8abec00000000000000000000000000000000000000000000000000000000000000" />
</executionStack>
<inputbuf>
EXEC dbo.MyProc 'MyParam', 542 </inputbuf>
</process>
</blocked-process>
<blocking-process>
<process status="suspended" waitresource="PAGE: 7:4:40156264 " waittime="5291779" spid="69" sbid="0" ecid="4" priority="0" trancount="0" lastbatchstarted="2022-06-01T09:06:10.557" lastbatchcompleted="2022-06-01T09:06:10.550" lastattention="1900-01-01T00:00:00.550" clientapp=".Net SqlClient Data Provider" hostname="MyServer" hostpid="52940" isolationlevel="read committed (2)" xactid="4524737805" currentdb="7" currentdbname="MyDB" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000003320a71f1f003704cf13be99833b422d70e704c70000000000000000000000000000000000000000" />
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x02000000c6cda92c3611dbd63ae5aab8d90f06e394ee900c0000000000000000000000000000000000000000" />
<frame line="61" stmtstart="5794" stmtend="5814" sqlhandle="0x030007007d01b22be394d50083ae000001000000000000000000000000000000000000000000000000000000" />
<frame line="1" stmtend="90" sqlhandle="0x010007003ebee03a606e2cc9df00000000000000000000000000000000000000000000000000000000000000" />
</executionStack>
<inputbuf>
EXEC dbo.MyProc 'MyParam', 541 </inputbuf>
</process>
</blocking-process>
</blocked-process-report>
</value>
</data>
<data name="database_name">
<value>MyDb</value>
</data>
</event>
Run Code Online (Sandbox Code Playgroud)
107 封锁 69
<event name="blocked_process_report" package="sqlserver" timestamp="2022-06-01T09:36:33.216Z">
<data name="duration">
<value>5291778000</value>
</data>
<data name="database_id">
<value>7</value>
</data>
<data name="object_id">
<value>0</value>
</data>
<data name="index_id">
<value>0</value>
</data>
<data name="lock_mode">
<value>4</value>
<text>U</text>
</data>
<data name="transaction_id">
<value>4524737805</value>
</data>
<data name="resource_owner_type">
<value>0x00000001</value>
<text>LOCK</text>
</data>
<data name="blocked_process">
<value>
<blocked-process-report monitorLoop="386256">
<blocked-process>
<process id="process923873f468" taskpriority="0" logused="0" waitresource="PAGE: 7:4:40156264 " waittime="5291778" ownerId="4524737805" transactionname="DELETE" lasttranstarted="2022-06-01T09:08:20.940" XDES="0x8b14c02960" lockMode="U" schedulerid="11" kpid="118356" status="suspended" spid="69" sbid="0" ecid="4" priority="0" trancount="0" lastbatchstarted="2022-06-01T09:06:10.557" lastbatchcompleted="2022-06-01T09:06:10.550" lastattention="1900-01-01T00:00:00.550" clientapp=".Net SqlClient Data Provider" hostname="MyServer" hostpid="52940" isolationlevel="read committed (2)" xactid="4524737805" currentdb="7" currentdbname="MyDB" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000003320a71f1f003704cf13be99833b422d70e704c70000000000000000000000000000000000000000" />
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x02000000c6cda92c3611dbd63ae5aab8d90f06e394ee900c0000000000000000000000000000000000000000" />
<frame line="61" stmtstart="5794" stmtend="5814" sqlhandle="0x030007007d01b22be394d50083ae000001000000000000000000000000000000000000000000000000000000" />
<frame line="1" stmtend="90" sqlhandle="0x010007003ebee03a606e2cc9df00000000000000000000000000000000000000000000000000000000000000" />
</executionStack>
<inputbuf>
EXEC dbo.MyProc 'MyParam', 541 </inputbuf>
</process>
</blocked-process>
<blocking-process>
<process status="suspended" waittime="5283425" spid="107" sbid="0" ecid="6" priority="0" trancount="0" lastbatchstarted="2022-06-01T09:06:18.560" lastbatchcompleted="2022-06-01T09:06:18.550" lastattention="1900-01-01T00:00:00.550" clientapp=".Net SqlClient Data Provider" hostname="MyServer" hostpid="52940" isolationlevel="read committed (2)" xactid="4524669110" currentdb="7" currentdbname="MyDB" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000003320a71f1f003704cf13be99833b422d70e704c70000000000000000000000000000000000000000" />
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000009d132a27f589a9771a2be6d262e2dcecf057db6d0000000000000000000000000000000000000000" />
<frame line="61" stmtstart="5794" stmtend="5814" sqlhandle="0x030007007d01b22be394d50083ae000001000000000000000000000000000000000000000000000000000000" />
<frame line="1" stmtend="90" sqlhandle="0x01000700990d272800ffb8abec00000000000000000000000000000000000000000000000000000000000000" />
</executionStack>
<inputbuf>
EXEC dbo.MyProc 'MyParam', 542 </inputbuf>
</process>
</blocking-process>
</blocked-process-report>
</value>
</data>
<data name="database_name">
<value>MyDB</value>
</data>
</event>
Run Code Online (Sandbox Code Playgroud)
69 封锁 69
<event name="blocked_process_report" package="sqlserver" timestamp="2022-06-01T09:36:33.216Z">
<data name="duration">
<value>5291785000</value>
</data>
<data name="database_id">
<value>7</value>
</data>
<data name="object_id">
<value>0</value>
</data>
<data name="index_id">
<value>0</value>
</data>
<data name="lock_mode">
<value>4</value>
<text>U</text>
</data>
<data name="transaction_id">
<value>4524737805</value>
</data>
<data name="resource_owner_type">
<value>0x00000001</value>
<text>LOCK</text>
</data>
<data name="blocked_process">
<value>
<blocked-process-report monitorLoop="386256">
<blocked-process>
<process id="processbd825f2108" taskpriority="0" logused="0" waitresource="PAGE: 7:9:42316852 " waittime="5291785" ownerId="4524737805" transactionname="DELETE" lasttranstarted="2022-06-01T09:08:20.940" XDES="0x89f1981100" lockMode="U" schedulerid="12" kpid="124532" status="suspended" spid="69" sbid="0" ecid="2" priority="0" trancount="0" lastbatchstarted="2022-06-01T09:06:10.557" lastbatchcompleted="2022-06-01T09:06:10.550" lastattention="1900-01-01T00:00:00.550" clientapp=".Net SqlClient Data Provider" hostname="MyServer" hostpid="52940" isolationlevel="read committed (2)" xactid="4524737805" currentdb="7" currentdbname="MyDB" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000003320a71f1f003704cf13be99833b422d70e704c70000000000000000000000000000000000000000" />
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x02000000c6cda92c3611dbd63ae5aab8d90f06e394ee900c0000000000000000000000000000000000000000" />
<frame line="61" stmtstart="5794" stmtend="5814" sqlhandle="0x030007007d01b22be394d50083ae000001000000000000000000000000000000000000000000000000000000" />
<frame line="1" stmtend="90" sqlhandle="0x010007003ebee03a606e2cc9df00000000000000000000000000000000000000000000000000000000000000" />
</executionStack>
<inputbuf>
EXEC dbo.MyProc 'My Param', 541 </inputbuf>
</process>
</blocked-process>
<blocking-process>
<process status="suspended" waitresource="PAGE: 7:9:42316852 " waittime="5291791" spid="69" sbid="0" ecid="5" priority="0" trancount="0" lastbatchstarted="2022-06-01T09:06:10.557" lastbatchcompleted="2022-06-01T09:06:10.550" lastattention="1900-01-01T00:00:00.550" clientapp=".Net SqlClient Data Provider" hostname="MyServer" hostpid="52940" isolationlevel="read committed (2)" xactid="4524737805" currentdb="7" currentdbname="MyDB" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x020000003320a71f1f003704cf13be99833b422d70e704c70000000000000000000000000000000000000000" />
<frame line="1" stmtstart="6116" stmtend="6236" sqlhandle="0x02000000c6cda92c3611dbd63ae5aab8d90f06e394ee900c0000000000000000000000000000000000000000" />
<frame line="61" stmtstart="5794" stmtend="5814" sqlhandle="0x030007007d01b22be394d50083ae000001000000000000000000000000000000000000000000000000000000" />
<frame line="1" stmtend="90" sqlhandle="0x010007003ebee03a606e2cc9df00000000000000000000000000000000000000000000000000000000000000" />
</executionStack>
<inputbuf>
EXEC dbo.MyProc 'My Param', 541 </inputbuf>
</process>
</blocking-process>
</blocked-process-report>
</value>
</data>
<data name="database_name">
<value>MyDB</value>
</data>
</event>
Run Code Online (Sandbox Code Playgroud)
我还可以看到使用dm_tran_locks
该会话似乎已在相同的资源上阻止了自身。(请注意,此输出来自后续运行,涉及的会话 ID 已更改为 83 和 58)
/* which session has the lock on the resources that session 83 is waiting */
SELECT resource_description,
request_status,
request_session_id
FROM sys.dm_tran_locks
WHERE resource_description IN (
SELECT resource_description
FROM sys.dm_tran_locks
WHERE request_session_id IN (83) AND
request_status = 'WAIT'
) AND
request_status = 'GRANT'
/