浅谈一次恼火的死锁追踪经历

最近，刚跳槽到一新公司，就遇到生产数据库晚上突然出现大面积中断，并持续近一小时，而发生事故时，我没有在现场，错过了直接获取信息的机会；过后boss要求追查原因，于是艰难的排查过程开始了。

开始以为是数据库某个JOB运行出现异常引起或者是因为程序里面哪个鸟人写了垃圾语句造成了大面积的死锁，于是将收集的trace信息拿到本地分析，从收集到的trace信息看，数据库在19：49：28时出现了锁，系统cancel了它，而且是连续三个，之后数据库大部分连接都是Abort了。

初步估计应该是死锁了，首先想到的就是因为数据库更新语句造成，于是查找Agent里面是否有对应时间的JOB运行，结果没有匹配的，然后分析trace文件里面是否有该时间段内运行的长Update、Insert或者Delete语句，查了半天也没发现，汗。。。，调查长查询，还是没有，狂汗。。。

Trace文件分析来分析去也没办法定位到具体语句（Trace 文件中只抓取了运行时间超过2秒或者读大于10000的记录），看来问题不是那么简单了；光根据Trace文件信息想要找到凶手估计不可能了，于是把Windows日志和数据库错误日志都查了一遍，也没有发现任何异常，难道是无头案。。。（没查到任何信息，担心饭碗不保了）

想来想去，也问了一些牛人，都没有啥结果，看来通过手头上现有的资料估计要找出问题是没多少希望了，只能另辟蹊径；既然可以肯定是因为死锁造成的，那说明数据库里面肯定存在资源的不一致访问或者竞争，那就从死锁下手，于是先清空掉当前的数据库错误日志文件，再打开1204和1222跟踪标志，等待鱼儿上钩。

DBCC errorlog 
DBCC TRACEON (1204, 1222, -1); 
DBCC tracestatus 

收集了几天数据，准备收网了，将ERROR.LOG从服务器拷贝到本地，用UE打开，认真一行行看，找到如下信息：

Deadlock encountered .... Printing deadlock information 

果然是死锁，总算找到真凶了，用UE查找一把，不查不知道，一查吓一跳，一堆死锁… 

死锁信息如下：

查看一下页面信息：

DBCC TRACEON (3604)   
DBCC PAGE('XXXX',1,22664690,3) WITH TABLERESULTS  
DBCC TRACEOFF (3604) 

这些页面信息都正常。

再根据信息，Input Buf 的信息，反过来查询Trace文件（Input Buffer 只能存放255个字节，信息显示不全，只能反过来找）：

select top 10 * from fn_trace_gettable('F:\perfmon\Trace_xxxx_20110406A.trc',default)   
where TextData like '%@SMESSAGE varchar(8000),@SINMATERECID varchar(8000),@SREFRECID varchar(8000)%' 

select top 10 * from fn_trace_gettable('F:\perfmon\Trace_xxxx_20110406A.trc',default)   
where TextData like '%@P0_ varchar(7),@P1_ datetime,@P2_ datetime,@P3_ varchar(7),@P4_ datetime%' 

 发现，死锁在表Rec_Main表上，一个是修改，一个是查询，而这个表数据量达700多W，又一个汗…..

不过很奇怪的是，死锁显示的信息都是些简单的修改（单条记录修改）和查询操作，不至于引起这么多死锁呀，继续头大中…

继续追查后发现，这两个操作在数据库中比较频繁（一天的trace记录）：

select COUNT(0) from fn_trace_gettable('F:\perfmon\Trace_xxxx_20110406A.trc',default)   
where TextData like '%@P0_ varchar(7),@P1_ datetime,@P2_ datetime,@P3_ varchar(7),@P4_ datetime%' 

select COUNT(0) from fn_trace_gettable('F:\perfmon\Trace_xxxx_20110406A.trc',default)   
where TextData like '%@SMESSAGE varchar(8000),@SINMATERECID varchar(18),@SREFRECID varchar(8000)%' 

一天的死锁次数大概有20次左右，Update一次只有一条记录，但是为啥会出现如此频繁的死锁呢？ 除了这个表本身的数据量大
以及查询超级变态之外（后面发现是主因），还有没有其他的原因呢？

最后，实在找不出问题所在，将问题反映到微软，和微软的人经过几天的沟通，最终给出的结果是数据库的Bug（吐血，运气真好呀），微软回答如下：

问题分析：

========

您的数据库版本是：Microsoft SQL Server 2005 – 9.00.4207.00 (Intel IA-64)  Enterprise Edition，SP3 CU1

我检查了您提供的死锁相关信息后发现，如您所说，您的这个死锁问题正是SQL2005的Bug所引起，详细可以参考文档：<http://support.microsoft.com/kb/975090>

处理方法：

============

您可以单独安装SP3 CU6，也可以直接安装SP4来解决您的这个问题

SP3 CU6下载地址：<http://support.microsoft.com/kb/974648>

SP4下载地址：<http://www.microsoft.com/downloads/en/details.aspx?FamilyID=b953e84f-9307-405e-bceb-47bd345baece>

您的SQL Server是IA64的版本，所以请选择正确对应的安装文件

——-补充—

微软虽然给出了一个可能的原因（还不知道靠不靠谱），但是基于目前系统的情况，boss不建议打补丁（要留到定期维护的时候再做），于是要我提改进方案，有了以上的追踪信息，再来提改进方案就不是什么难事了，于是mail给了boss：

根据这些信息，我们可以知道：

死锁主要发生在表Rec_main上，这个表的数据量有700多万；

 主要是由一个Update和一个Select语句引起了死锁，这两条语句运行频率比较高，并且查询语句非常长（见附件，这样的查询不可能使用到索引）；

主要问题出在这个复杂的查询和表的数据量上（还包括微软说的bug）；

目前这种死锁在我们数据库里面还是频繁的发生。

为处理这种情况，有以下建议：

业务上，是否能够将该表的信息分开，减少数据量；

开发人员能否改进这个查询语句；

查询是否可以考虑加上with（nolock），Update 语句可以加上 with（rowlock）；

其他（考虑分区表等）。

最终，将表中数据搬移掉一部分，修改了查询的语句，同时加上了with（nolock），问题得到解决（至于微软的方案，要见下回分解了）

原文链接：http://www.cnblogs.com/fygh/archive/2011/04/12/DeadLock.html

【编辑推荐】

1. SQL Server & 死锁
2. SQL Server死锁的解除方法
3. SQL Server死锁监控的语句写法
4. 深度探究SQL Server死锁的原因