715
魔獸
RDS SQL Server死鎖(Deadlock)係列之五利用Extended Events獲取死鎖信息
問題引入
在過去很長一段時間,不斷有客人會問道:“在事先沒有任何跟蹤或者監控部署的情況下,阿裏雲RDS SQL Server有沒有辦法獲取到曆史死鎖信息,供我們分析?”。在寫到RDS SQL Server死鎖係列文章之五時,我們就可以使用Extended Events來解決這個問題。
分析問題
Extended Events是微軟從SQL Server 2008版本開始引入的,其中有一個默認事件會話是system_health,它的作用是用來收集SQL Server發生的錯誤信息,以XML格式存儲在一個名為sys.dm_xe_session_targets的DMV中,這其中就包含了死鎖信息。所以,我們可以利用這個DMV關聯另外一個名為sys.dm_xe_sessions的DMV來獲取死鎖信息。
注意:存儲在這兩個DMV中的信息會伴隨SQL Server服務重啟而消失。也就是說,我們無法獲取到SQL Server服務重啟之前的曆史死鎖信息。
獲取曆史死鎖信息
為了描述清楚如何獲取曆史死鎖信息,我們可以選擇其中任意一條死鎖信息加以分析,代碼如下:
USE master
GO
-- analysis Extend Event for deadlock
DECLARE
@deadlock_graph_nvarchar nvarchar(max)
,@deadlock_graph_xml xml
;
;WITH RingBufferTarget
AS
(
SELECT CAST (target_data AS XML) AS target_xml
FROM sys.dm_xe_session_targets st
INNER JOIN sys.dm_xe_sessions s
ON s.address = st.event_session_address
WHERE s.[name] = 'system_health' and st.target_name = 'ring_buffer'
)
SELECT TOP 1 @deadlock_graph_nvarchar = CAST(T.C.query('.') AS NVARCHAR(MAX))
FROM RingBufferTarget AS A
CROSS APPLY target_xml.nodes('./RingBufferTarget/event') AS T(C)
WHERE T.C.value('./@name','varchar(200)') = 'xml_deadlock_report'
SELECT
@deadlock_graph_xml = CAST(REPLACE(REPLACE(@deadlock_graph_nvarchar, '<', '<'),'>', '>') as xml)
;
select @deadlock_graph_xml.query('event/data/value/deadlock')
;WITH deadlock
AS
(
SELECT
OwnerID = T.C.value('@id', 'varchar(50)')
,SPid = T.C.value('(./@spid)[1]','int')
,status = T.C.value('(./@status)[1]','varchar(10)')
,Victim = case when T.C.value('@id', 'varchar(50)') = T.C.value('(./../../victim-list/victimProcess/@id)[1]','varchar(50)') then 1 else 0 end
,LockMode = T.C.value('@lockMode', 'varchar(20)')
,Inputbuf = T.C.value('(./inputbuf/text())[1]','varchar(max)')
,SPName = T.C.value('(./executionStack/frame/@procname)[1]','sysname')
,Hostname = T.C.value('(./@hostname)[1]','sysname')
,Clientapp = T.C.value('(./@clientapp)[1]','varchar(max)')
,LoginName = T.C.value('@loginname', 'varchar(20)')
,Action = T.C.value('(./@transactionname)[1]','varchar(max)')
,TransactionTime = T.C.value('@lasttranstarted', 'datetime')
--,*
FROM @deadlock_graph_xml.nodes('./event/data/value/deadlock/process-list/process') AS T(C)
)
,
keylock
AS
(
SELECT
OwnerID = T.C.value('./owner[1]/@id', 'varchar(50)')
,KeylockObject = T.C.value('./../@objectname', 'varchar(200)')
,Indexname = T.C.value('./../@indexname', 'varchar(200)')
,IndexLockMode = T.C.value('./../@mode', 'varchar(20)')
FROM @deadlock_graph_xml.nodes('./event/data/value/deadlock/resource-list/keylock/owner-list') AS T(C)
)
SELECT
A.SPid
,A.TransactionTime
,is_Vitim = A.Victim
,A.SPName
,A.LockMode
,B.Indexname
,B.KeylockObject
,B.IndexLockMode
,A.Inputbuf
,A.Hostname
,A.LoginName
,A.Clientapp
,A.Action
,status
FROM deadlock AS A
LEFT JOIN keylock AS B
ON A.OwnerID = B.OwnerID
從執行查詢後的結果來看,我們成功拿到了曆史死鎖信息(從時間字段來看,死鎖發生在8天以前),這些有用的信息包含:鎖進程,死鎖進程,鎖的類型,執行的語句,登錄用戶等信息,如下截圖所示:
我們也可以打開這個死鎖信息的xml,如下:
<deadlock>
<victim-list>
<victimProcess />
</victim-list>
<process-list>
<process taskpriority="0" logused="0" waitresource="KEY: 14:72057594038910976 (8194443284a0)" waittime="3906" ownerId="23597" transactionname="user_transaction" lasttranstarted="2017-04-19T21:28:11.050" XDES="0x87141730" lockMode="X" scheduler kp status="suspended" sp sb ec priority="0" trancount="2" lastbatchstarted="2017-04-19T21:28:11.050" lastbatchcompleted="2017-04-19T21:28:11.027" clientapp="Microsoft SQL Server Management Studio - Query" hostname="CHERISH-PC" hostp loginname="Cherish-PC\Cherish" isolationlevel="read committed (2)" xact currentdb="14" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
<executionStack>
<frame procname="" line="8" stmtstart="58" sqlhandle="0x020000008902b6141ee31ae1865c893c9823c9cf5d55fafb" />
<frame procname="" line="8" stmtstart="156" stmtend="276" sqlhandle="0x020000008e0a8d0d015ffe0258d01a670c6864df6370c807" />
</executionStack>
<inputbuf>
BEGIN TRAN
UPDATE dbo.test_deadlock2
SET name = &apos;CC&apos;
WHERE id = 1
;
UPDATE dbo.test_deadlock1
SET name = &apos;CC&apos;
WHERE id = 1
;
COMMIT
</inputbuf>
</process>
<process taskpriority="0" logused="0" waitresource="KEY: 14:72057594038976512 (8194443284a0)" waittime="503" ownerId="23574" transactionname="user_transaction" lasttranstarted="2017-04-19T21:28:09.450" XDES="0x87140e80" lockMode="X" scheduler kp status="suspended" sp sb ec priority="0" trancount="2" lastbatchstarted="2017-04-19T21:28:09.443" lastbatchcompleted="2017-04-19T21:28:09.440" clientapp="Microsoft SQL Server Management Studio - Query" hostname="CHERISH-PC" hostp loginname="Cherish-PC\Cherish" isolationlevel="read committed (2)" xact currentdb="14" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200">
<executionStack>
<frame procname="" line="9" stmtstart="58" sqlhandle="0x0200000070cad20bef4ae5ada9481eea2eb28415cd7e0c04" />
<frame procname="" line="9" stmtstart="208" stmtend="328" sqlhandle="0x020000008b7a380c6bf24758d2b29f0eeb276e4f0aa76d8f" />
</executionStack>
<inputbuf>
BEGIN TRAN
UPDATE dbo.test_deadlock1
SET name = &apos;CC&apos;
WHERE id = 1
;
WAITFOR DELAY &apos;00:00:05&apos;
UPDATE dbo.test_deadlock2
SET name = &apos;CC&apos;
WHERE id = 1
;
ROLLBACK </inputbuf>
</process>
</process-list>
<resource-list>
<keylock hobt db objectname="" indexname="" mode="X" associatedObjectId="72057594038910976">
<owner-list>
<owner mode="X" />
</owner-list>
<waiter-list>
<waiter mode="X" requestType="wait" />
</waiter-list>
</keylock>
<keylock hobt db objectname="" indexname="" mode="X" associatedObjectId="72057594038976512">
<owner-list>
<owner mode="X" />
</owner-list>
<waiter-list>
<waiter mode="X" requestType="wait" />
</waiter-list>
</keylock>
</resource-list>
</deadlock>
最後更新:2017-04-28 23:21:44