デッドロックについて説明してみる - その 3 ( デッドロックの内容をみてみる ) - - 都内で働くSEの技術的なひとりごと / Technical soliloquy of System Engineer working in Tokyo

　デッドロックの見方について説明してみたいと思います。それでは早速デッドロックを SQL Server に検出させてみましょう。下記のコマンドを SQL Server Management Studio から実行してみましょう。

DBCC TRACEON(1222,-1)

f:id:koogucc11:20161021180738p:plain

　トレースフラグがきちんと反映されているか確認してみましょう。下記のコマンドを SQL Server Management Studio から実行してみましょう。

DBCC TRACESTATUS

　下図のような結果になっていれば、成功です。
f:id:koogucc11:20161021180921p:plain

　下記の記事を参考にして、デッドロックを発生させてみましょう。
ryuchan.hatenablog.com

　上記の記事通りに処理を進めると、下図のような状態になります。
f:id:koogucc11:20161022030547p:plain

　次にエラーログを参照してみましょう。Log フォルダ配下の ERRORLOG にデッドロックの情報が出力されています。エラーログから『 deadlock-list 』のキーワードを探しましょう。デッドロックの詳細情報が出力されている箇所です。今回の実行結果から出力されたデッドロックの内容は下記の通りです。

deadlock-list
 deadlock victim=process264ca6d6108
  process-list
   process id=process264ca6d6108 taskpriority=0 logused=144 waitresource=KEY: 10:72057594047365120 (8194443284a0) waittime=3378 ownerId=208452 transactionname=user_transaction lasttranstarted=2016-10-21T17:59:00.170 XDES=0x264e25475e8 lockMode=U schedulerid=1 kpid=7672 status=suspended spid=55 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2016-10-21T17:59:00.137 lastbatchcompleted=2016-10-21T17:59:00.133 lastattention=1900-01-01T00:00:00.133 clientapp=Microsoft SQL Server Management Studio - クエリ hostname=xxxxxxxx hostpid=9636 loginname=xxxxxxxx isolationlevel=read committed (2) xactid=208452 currentdb=10 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
    executionStack
     frame procname=adhoc line=17 stmtstart=742 stmtend=982 sqlhandle=0x020000002ac21b1c626aefe609b1bd5c778fde060fd0e1d90000000000000000000000000000000000000000
unknown     
     frame procname=adhoc line=17 stmtstart=742 stmtend=982 sqlhandle=0x02000000b865d60581449ff5a87c353f302f7be636728a490000000000000000000000000000000000000000
unknown     
    inputbuf
DECLARE @Error_Message  NVARCHAR(MAX);
DECLARE @Error_Severity INT;
DECLARE @Error_State    INT;
WHILE 0 = 0
BEGIN
    BEGIN TRY
        BEGIN TRAN
        -- ProductID = 2 のデータを更新する。
        UPDATE 
            Production.Product
        SET Name = N'Bearing Ball' 
        WHERE 
            ProductID = 2 
        -- ProductID = 1 のデータを更新する。
        UPDATE 
            Production.Product
        SET Name = N'Adjustable Race'
        WHERE 
            ProductID = 1 
        COMMIT TRAN
    END TRY
    -- 例外をキャッチしたら、メッセージを出力して処理を終了する。
    BEGIN CATCH
        SET @Error_Message  = ERROR_MESSAGE();
        SET @Error_Severity = ERROR_SEVERITY();
        SET @Error_State    = ERROR_STATE();
        RAISERROR(@Error_Message, @Error_Severity, @Error_State);
        BREAK;
    END CATCH
END    
   process id=process264bc1d9468 taskpriority=0 logused=144 waitresource=KEY: 10:72057594047365120 (61a06abd401c) waittime=3378 ownerId=208455 transactionname=user_transaction lasttranstarted=2016-10-21T17:59:00.170 XDES=0x264e2546a08 lockMode=U schedulerid=1 kpid=13380 status=suspended spid=57 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2016-10-21T17:58:57.553 lastbatchcompleted=2016-10-21T17:58:57.553 lastattention=1900-01-01T00:00:00.553 clientapp=Microsoft SQL Server Management Studio - クエリ hostname=xxxxxxxx hostpid=9636 loginname=xxxxxxxx isolationlevel=read committed (2) xactid=208455 currentdb=10 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
    executionStack
     frame procname=adhoc line=17 stmtstart=748 stmtend=984 sqlhandle=0x020000002ac21b1c626aefe609b1bd5c778fde060fd0e1d90000000000000000000000000000000000000000
unknown     
     frame procname=adhoc line=17 stmtstart=748 stmtend=984 sqlhandle=0x02000000b3207c1e426c24e8f6554c9a244fc1f935b220440000000000000000000000000000000000000000
unknown     
    inputbuf
DECLARE @Error_Message  NVARCHAR(MAX);
DECLARE @Error_Severity INT;
DECLARE @Error_State    INT;
WHILE 0 = 0
BEGIN
    BEGIN TRY
        BEGIN TRAN 
        -- ProductID = 1 のデータを更新する。
        UPDATE 
            Production.Product
        SET Name = N'Adjustable Race'
        WHERE 
            ProductID = 1 
        -- ProductID = 2 のデータを更新する。
        UPDATE 
            Production.Product
        SET Name = N'Bearing Ball' 
        WHERE 
            ProductID = 2 
        COMMIT TRAN
    END TRY
    -- 例外をキャッチしたら、メッセージを出力して処理を終了する。	
    BEGIN CATCH
        SET @Error_Message  = ERROR_MESSAGE();
        SET @Error_Severity = ERROR_SEVERITY();
        SET @Error_State    = ERROR_STATE();
        RAISERROR(@Error_Message, @Error_Severity, @Error_State);
        BREAK;
    END CATCH
END    
  resource-list
   keylock hobtid=72057594047365120 dbid=10 objectname=AdventureWorks.Production.Product indexname=PK_Product_ProductID id=lock26489049000 mode=X associatedObjectId=72057594047365120
    owner-list
     owner id=process264bc1d9468 mode=X
    waiter-list
     waiter id=process264ca6d6108 mode=U requestType=wait
   keylock hobtid=72057594047365120 dbid=10 objectname=AdventureWorks.Production.Product indexname=PK_Product_ProductID id=lock264e054b280 mode=X associatedObjectId=72057594047365120
    owner-list
     owner id=process264ca6d6108 mode=X
    waiter-list
     waiter id=process264bc1d9468 mode=U requestType=wait

　デッドロックの状態を把握するには、下記の情報を知っていれば十分かと思います。

deadlock victim
デッドロック発生時、ロールバックされたプロセスIDが表示されます。
process-list
プロセスのリストが列挙されます。
process id
プロセスIDです。
spid
ユーザープロセスのセッション IDです。
clientapp
クライアントアプリケーションです。
hostname
ホスト名です。
loginname
ログインユーザー名です。
isolationlevel
トランザクション分離レベルです。
executionStack
これ以降に実行されたクエリが記録されます。
inputbuf
実行されたクエリの内容です。
resource-list
対象となったリソースのリストです。
mode
ロックの種類です。
objectname
テーブル名です。
indexname
インデックス名です。
owner-list
要求の状態です。
waiter-list
待ちの状態です。

　それでは、早速デッドロックの出力結果を見ていきましょう。2行目の『deadlock victim=process264ca6d6108』から、process264ca6d6108 がデッドロックの対象となったことが判断できます。4行目からがデッドロックの対象となったプロセス情報です。5行目からが実際の実行結果が参照できます。さらに、10行目のinputbuf以降にデッドロック対象となったクエリ( 11行目から )が出力されます。

deadlock-list
 deadlock victim=process264ca6d6108
  process-list
   process id=process264ca6d6108 taskpriority=0 logused=144 waitresource=KEY: 10:72057594047365120 (8194443284a0) waittime=3378 ownerId=208452 transactionname=user_transaction lasttranstarted=2016-10-21T17:59:00.170 XDES=0x264e25475e8 lockMode=U schedulerid=1 kpid=7672 status=suspended spid=55 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2016-10-21T17:59:00.137 lastbatchcompleted=2016-10-21T17:59:00.133 lastattention=1900-01-01T00:00:00.133 clientapp=Microsoft SQL Server Management Studio - クエリ hostname=xxxxxxxx hostpid=9636 loginname=xxxxxxxx isolationlevel=read committed (2) xactid=208452 currentdb=10 lockTimeout=4294967295 clientoption1=671090784 clientoption2=390200
    executionStack
     frame procname=adhoc line=17 stmtstart=742 stmtend=982 sqlhandle=0x020000002ac21b1c626aefe609b1bd5c778fde060fd0e1d90000000000000000000000000000000000000000
unknown     
     frame procname=adhoc line=17 stmtstart=742 stmtend=982 sqlhandle=0x02000000b865d60581449ff5a87c353f302f7be636728a490000000000000000000000000000000000000000
unknown     
    inputbuf
DECLARE @Error_Message  NVARCHAR(MAX);
DECLARE @Error_Severity INT;
DECLARE @Error_State    INT;
WHILE 0 = 0
BEGIN
    BEGIN TRY
        BEGIN TRAN
        -- ProductID = 2 のデータを更新する。
        UPDATE 
            Production.Product
        SET Name = N\'Bearing Ball\' 
        WHERE 
            ProductID = 2 
        -- ProductID = 1 のデータを更新する。
        UPDATE 
            Production.Product
        SET Name = N\'Adjustable Race\'
        WHERE 
            ProductID = 1 
        COMMIT TRAN
    END TRY
    -- 例外をキャッチしたら、メッセージを出力して処理を終了する。
    BEGIN CATCH
        SET @Error_Message  = ERROR_MESSAGE();
        SET @Error_Severity = ERROR_SEVERITY();
        SET @Error_State    = ERROR_STATE();
        RAISERROR(@Error_Message, @Error_Severity, @Error_State);
        BREAK;
    END CATCH
END

　resource-list から、対象のテーブル、インデックス、それぞれのクエリからのロック状態も把握することができます。AdventureWorks.Production.Product、PK_Product_ProductID ( 2,7行目 ) に対して、mode = X ( 排他 ) と mode = U ( 更新 ) で待ちになっていることがわかります ( 3-6,8-11行目 )。その結果、デッドロックが発生したことが判断できますね。

resource-list
   keylock hobtid=72057594047365120 dbid=10 objectname=AdventureWorks.Production.Product indexname=PK_Product_ProductID id=lock26489049000 mode=X associatedObjectId=72057594047365120
    owner-list
     owner id=process264bc1d9468 mode=X
    waiter-list
     waiter id=process264ca6d6108 mode=U requestType=wait
   keylock hobtid=72057594047365120 dbid=10 objectname=AdventureWorks.Production.Product indexname=PK_Product_ProductID id=lock264e054b280 mode=X associatedObjectId=72057594047365120
    owner-list
     owner id=process264ca6d6108 mode=X
    waiter-list
     waiter id=process264bc1d9468 mode=U requestType=wait

　次回以降は、1204 と Deadlock Graph について説明します。( 記事数稼ぎのような気もする... )

　もう店頭にならんでるんですよね。Lenovo で予約した意味なし。
ptskunx.hatenablog.com

　最近、IoT やりたい気分。