您如何解释 SQL 死锁跟踪？答案

【问题标题】：How do you interpret a SQL deadlock trace?您如何解释 SQL 死锁跟踪？
【发布时间】：2018-06-15 15:09:58
【问题描述】：

我们的 SQL 服务器发生了死锁。我已经阅读了有关 Stack Overflow 和其他地方的许多页面，但我找不到有关如何阅读跟踪日志的分步说明列表。有人能告诉我如何解释这个吗？显然现在我需要知道如何解释这个特定的日志，但我真正需要长期学习的是如何阅读未来的日志。

完整的跟踪日志如下。让我解释一下我们是如何解释这个的。然后你可以告诉我我们做错了什么以及如何正确阅读它。

我们正在考虑以下几行：

06/14/2018 14:56:25,spid8s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x000000086D8ECD90 模式:U SPID:171 BatchID:2 ECID:0 TaskProxy:(0x0000000125F1C768) 值:0x2dade880 成本:(0/2000) 2018 年 6 月 14 日 14:56:25，spid8s，未知，受害者资源所有者：

上面写着“victim”和“Xdes:0x000000086D8ECD90”表示进程 0x000000086D8ECD90 是由于某些资源出现死锁而关闭的进程。

然后在这些行中再次提到 0x000000086D8ECD90：

06/14/2018 14:56:25，spid24s，未知，从 site_updates 中删除 table_name = 'order_head' 和 update_type = 'update' 和 row_id in（从插入的选择 id 2018年6月14日14：56：25，spid24s，未知帧PROCNAME = MyDatabase.dbo.update_order_head线= 5 stmtstart = 168 stmtend = 412 SQLHANDLE = 0x03000700a2b0aa21d638280131a7000000000000000000000000000000000000000000000000000000000000 2018 年 6 月 14 日 14:56:25，spid24s，未知，执行堆栈 2018 年 6 月 14 日 14:56:25，spid24s，未知，进程 id=process624d9c108 taskpriority=0 logused=2000 waitresource=KEY: 7:345803707580416 (a1de22506108) waittime=9019 ownerId=3985897338 transactionname=user_transaction lasttranstarted=2 14T14:56:16.413 XDES=0x86d8ecd90 lockMode=U schedulerid=3 kpid=10664 status=suspended spid=171 sbid=2 ecid=0 priority=0 trancount=2 lastbatchstarted=2018-06-14T14:56:16.423 lastbatchcompleted=2018- 06-14T14:56:16.423 lastattention=1900-01-01T00:00:00.423 clientapp=.Net SqlClient 数据提供者主机名=NTSWKS56 hostpid=12396 loginname=MyDomain\user2isolationlevel=读取提交 (2) xactid=3985897338 currentdb=7 lockTimeout =4294967295 客户端选项1=671219744 客户端选项2=128056 2018 年 6 月 14 日 14:56:25，spid24s，未知，进程列表

表示从 site_updates 中删除的命令是由于表 site_updates 上的死锁而停止的命令

然后这一行：

2018 年 6 月 14 日 14:56:25，spid24s，未知，从 site_updates 中删除，其中 table_name = 'shipment_head' 和 update_type = 'inserted' 和 row_id in（从插入中选择 id

表明该命令首先导致了 site_update 的死锁。

我们接近了吗？离基地远吗？有什么方法可以准确地确定发生了什么和/或如何解决它？（如“第一次删除 site_updates 表获得了排他锁，因此在运行第二次删除时导致死锁。要解决此问题，请在第一次删除之前添加 XXXX，这样表就不会被锁定。）

完整的死锁跟踪：

06/14/2018 14:56:25,spid24s,Unknown,keylock hobtid=345803707580416 dbid=7 objectname=MyDatabase.dbo.site_updates indexname=PK_site_updates id=lock140bfd400 mode=X associatedObjectId=345803707580416
06/14/2018 14:56:25,spid24s,Unknown,resource-list
06/14/2018 14:56:25,spid24s,Unknown,IF @@TRANCOUNT > 0 BEGIN exec sp_add_shipment 6379785<c/> 'GND'<c/> '4.00'<c/> 'CLCH105 (6pcs)'<c/> '6x83066'<c/> 'fedexsmartpost'<c/> 'MyDomain\user1'<c/> 'MyDomain\user1' END

06/14/2018 14:56:25,spid24s,Unknown,delete from site_updates where table_name = 'shipment_head' and update_type = 'inserted' and row_id in (select id from inserted
06/14/2018 14:56:25,spid24s,Unknown,frame procname=MyDatabase.dbo.insert_shipment_head line=5 stmtstart=152 stmtend=406 sqlhandle=0x030007000e51c2768d206101239e000000000000000000000000000000000000000000000000000000000000
06/14/2018 14:56:25,spid24s,Unknown,executionStack
06/14/2018 14:56:25,spid24s,Unknown,process id=process7a5313c28 taskpriority=0 logused=88216 waitresource=KEY: 7:345803707580416 (c8ec095a9952) waittime=8911 ownerId=3985893541 transactionname=user_transaction lasttranstarted=2018-06-14T14:56:09.940 XDES=0x152b64d90 lockMode=U schedulerid=3 kpid=8252 status=suspended spid=277 sbid=2 ecid=0 priority=0 trancount=2 lastbatchstarted=2018-06-14T14:56:16.507 lastbatchcompleted=2018-06-14T14:56:16.453 lastattention=1900-01-01T00:00:00.453 clientapp=.Net SqlClient Data Provider hostname=NTSWKS01 hostpid=1340 loginname=MyDomain\ups isolationlevel=read committed (2) xactid=3985893541 currentdb=7 lockTimeout=4294967295 clientoption1=671219744 clientoption2=128056

06/14/2018 14:56:25,spid24s,Unknown,IF @@TRANCOUNT > 0 BEGIN update order_head set address_flag = 'UR'<c/>customer_id = 0<c/> ship_name = '17106'<c/> 06/14/2018 14:56:25,spid24s,Unknown,delete from site_updates where table_name = 'order_head' and update_type = 'update' and row_id in (select id from inserted
06/14/2018 14:56:25,spid24s,Unknown,frame procname=MyDatabase.dbo.update_order_head line=5 stmtstart=168 stmtend=412 sqlhandle=0x03000700a2b0aa21d638280131a7000000000000000000000000000000000000000000000000000000000000
06/14/2018 14:56:25,spid24s,Unknown,executionStack
06/14/2018 14:56:25,spid24s,Unknown,process id=process624d9c108 taskpriority=0 logused=2000 waitresource=KEY: 7:345803707580416 (a1de22506108) waittime=9019 ownerId=3985897338 transactionname=user_transaction lasttranstarted=2018-06-14T14:56:16.413 XDES=0x86d8ecd90 lockMode=U schedulerid=3 kpid=10664 status=suspended spid=171 sbid=2 ecid=0 priority=0 trancount=2 lastbatchstarted=2018-06-14T14:56:16.423 lastbatchcompleted=2018-06-14T14:56:16.423 lastattention=1900-01-01T00:00:00.423 clientapp=.Net SqlClient Data Provider hostname=NTSWKS56 hostpid=12396 loginname=MyDomain\user2 isolationlevel=read committed (2) xactid=3985897338 currentdb=7 lockTimeout=4294967295 clientoption1=671219744 clientoption2=128056
06/14/2018 14:56:25,spid24s,Unknown,process-list
06/14/2018 14:56:25,spid24s,Unknown,deadlock victim=process624d9c108
06/14/2018 14:56:25,spid24s,Unknown,deadlock-list
06/14/2018 14:56:25,spid8s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x000000086D8ECD90 Mode: U SPID:171 BatchID:2 ECID:0 TaskProxy:(0x0000000125F1C768) Value:0x2dade880 Cost:(0/2000)
06/14/2018 14:56:25,spid8s,Unknown,Victim Resource Owner:
06/14/2018 14:56:25,spid8s,Unknown,
06/14/2018 14:56:25,spid8s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x0000000152B64D90 Mode: U SPID:277 BatchID:2 ECID:0 TaskProxy:(0x00000006E682E768) Value:0xbbe1a740 Cost:(0/88216)
06/14/2018 14:56:25,spid8s,Unknown,Requested by:
06/14/2018 14:56:25,spid8s,Unknown,Owner:0x0000000338998680 Mode: X        Flg:0x40 Ref:0 Life:02000000 SPID:171 ECID:0 XactLockInfo: 0x000000086D8ECDC8
06/14/2018 14:56:25,spid8s,Unknown,Grant List 1:
06/14/2018 14:56:25,spid8s,Unknown,KEY: 7:345803707580416 (c8ec095a9952) CleanCnt:2 Mode:X Flags: 0x1
06/14/2018 14:56:25,spid8s,Unknown,Node:2
06/14/2018 14:56:25,spid8s,Unknown,
06/14/2018 14:56:25,spid8s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x000000086D8ECD90 Mode: U SPID:171 BatchID:2 ECID:0 TaskProxy:(0x0000000125F1C768) Value:0x2dade880 Cost:(0/2000)
06/14/2018 14:56:25,spid8s,Unknown,Requested by:
06/14/2018 14:56:25,spid8s,Unknown,Owner:0x00000004E373B900 Mode: X        Flg:0x40 Ref:0 Life:02000000 SPID:277 ECID:0 XactLockInfo: 0x0000000152B64DC8
06/14/2018 14:56:25,spid8s,Unknown,Grant List 0:
06/14/2018 14:56:25,spid8s,Unknown,KEY: 7:345803707580416 (a1de22506108) CleanCnt:2 Mode:X Flags: 0x1
06/14/2018 14:56:25,spid8s,Unknown,Node:1
06/14/2018 14:56:25,spid8s,Unknown,
06/14/2018 14:56:25,spid8s,Unknown,Wait-for graph
06/14/2018 14:56:25,spid8s,Unknown,Deadlock encountered .... Printing deadlock information

* 更新 * 这是建议的 BlitzLock 输出的一部分。仍然不确定如何解释。

【问题讨论】：

如果日志中的某些数据敏感，您可能需要删除它们
为了便于阅读，您可以在 Notepad++ 等文本查看器中打开此文件，并将“”替换为“，”（不带引号的逗号），将“”替换为 \ r\n（回车\换行符）。如果您使用 Notepad++，请使用扩展模式，这样它才能正确进行 \r\n 替换。
谢谢。它的格式在我这边很好，但是 SO 用换行符输出它。我将其格式化为 SO 中的代码，因此它应该更具可读性。

标签： sql-server deadlock sql-delete database-deadlocks

【解决方案1】：

我强烈建议你使用https://www.brentozar.com/archive/2017/12/introducing-sp_blitzlock-troubleshooting-sql-server-deadlocks/ 这将使您能够以一种新的方式跟踪和了解您的死锁问题。

另外，您可能想去您的 system_helath 扩展事件并查找：

【讨论】：

谢谢！我试过这个，但我仍然不知道如何阅读或解决问题。例如，它向我展示了受害者正在插入一张桌子。但是，非受害者查询显示“Proc [Database Id = 7 Object Id = 1478959224] ”。这是什么意思？结果中是否有任何内容告诉我如何解决问题？
一旦您有受害者和非受害者查询，您可以简单地找出这两个对象，例如：SELECT DISTINCT OBJECT_NAME(object_id) --1478959224 FROM master.sys.objects;此外，如果您转到 xml 报告，您可以看到查询的哪一部分是受害者等等。基于此，您可以做很多事情： - 如果您没有熟练的 DBa，我建议您为数据库使用快照隔离级别：brentozar.com/archive/2013/01/… - 调整两个查询以减少死锁等的可能性