使用SQL Server事件探查器分析死锁原因

核心提示：最近因为在近一期的测试结果中，发现在数据库竟然存在此死锁症状，使用SQL Server事件探查器分析死锁原因，于是上头下达命令，必须把死锁原因找出来，所以不能导入数据成功，字段不匹配．根据错误信息在事件监测里面添加：SQL:BatchStarting, SP:StmtStarting, SP:StmtCompleted

最近因为在近一期的测试结果中，发现在数据库竟然存在此死锁症状，于是上头下达命令，必须把死锁原因找出来，也就是执行的ＳＱＬ语句定位出来．

以前对于Oracle的定位倒是做过，但SQL Server没有做过．

在同事的建议下，开始的事件探查器的使用过程．

第一步：下载ＲＭＬ工具，地址直接去微软的官方网站下载，１ＭＢ多一点．因为事件探测器不能看到标准的ＳＱＬ语句，所以需要ＲＭＬ来转换．

第二步：安装好后，直接新建一空的ＤＢ　没有多mydb，并且新建存储过程如下：

Create procedure usp_GetAccessPattern
@duration_filter int=-1 --传入的参数，可以按照语句执行的时间过滤统计
as begin
/*首先得到全部语句的性能数据的总和*/
declare @sum_total float,@sum_cpu float,@sum_reads float,@sum_duration float,@sum_writes float
select @sum_total=count(*)*0.01,--这是所有语句的总数。
@sum_cpu=sum(cpu)*0.01, --这是所有语句耗费的CPU时间
@sum_reads=sum(reads)*0.01, --这是所有语句耗费的Reads数目，8K为单位。
@sum_writes=sum(writes)*0.01,--这是所有语句耗费的Writes数目，8K为单位。
@sum_duration=sum(duration)*0.01--这是所有语句的执行时间总和。
from tblBatches --这是Read80Trace产生的表，包括了Trace文件中所有的语句。
where duration>=@duration_filter --是否按照执行时间过滤
/*然后进行Group by，得到某类语句占用的比例*/
Select ltrim(str(count(*))) exec_stats,''+ str(count(*)/@sum_total,4,1)+'%' ExecRatio,
ltrim(str(sum(cpu)))+' : '++ltrim(str(avg(cpu))) cpu_stats,''+str(sum(cpu)/@sum_cpu,4,1)+'%' CpuRatio,
ltrim(str(sum(reads) ))+' : '+ltrim(str(avg(reads) )) reads_stats,''+str(sum(reads)/@sum_reads,4,1)  +'%' ReadsRatio ,
--ltrim(str(sum(writes) ))+' : '+ltrim(str(avg(writes) )) --writes_stats,''+str(sum(writes)/@sum_writes,4,1) +'%)',
ltrim(str(sum(duration) ))+' : '+ltrim(str(avg(duration))) duration_stats,''+str(sum(duration)/@sum_duration,4,1)+'%' DurRatio ,
textdata,count(*)/@sum_total tp,sum(cpu)/@sum_cpu cp,sum(reads)/@sum_reads rp,sum(duration)/@sum_duration dp
into #queries_staticstics from
/* tblUniqueBatches表中存放了所有标准化的语句。*/
(select reads,cpu,duration,writes,convert(varchar(2000),NormText)textdata from tblBatches inner join tblUniqueBatches on tblBatches.HashId=tblUniqueBatches.hashid where duration>@duration_filter) B group by textdata --这个group by很重要，它对语句进行归类统计。
print 'Top 10 order by cpu+reads+duration'
select top 10 * from #queries_staticstics order by cp+rp+dp desc
print 'Top 10 order by cpu'
select top 10 * from #queries_staticstics order by cp desc
print 'Top 10 order by reads'
select top 10 * from #queries_staticstics order by rp desc
print 'Top 10 order by duration'
select top 10 * from #queries_staticstics order by dp desc
print 'Top 10 order by batches'
select top 10 * from #queries_staticstics order by tp desc
End
 
 
第三步：基本步骤已经完成，在开始菜单中打开事件探查器，新建一个trace

使用默认模板，并另存为trc文件夹，选择你监听的事件，点击运行，运行完后，直接在ＣＭＤ里面运行命令：

Read80trace -f -dmydb -Id:\test\aaa.trc　　　mydb:databasename,aaa.trc:另存为文件名．

碰到错误信息：

C:\Program Files\rml>Read80trace -f -dmydb -ID:\eip_320.trc
Output path was not specified; defaulting to C:\Program Files\rml\output
10/19/07 11:18:54 -----------------------------------------------------
10/19/07 11:18:54 Read80Trace version 8.10.0010
10/19/07 11:18:54 -f
10/19/07 11:18:54 -dmydb
10/19/07 11:18:54 -ID:\eip_320.trc
10/19/07 11:18:54 Establishing database connections:
10/19/07 11:18:54 Server: (local)
10/19/07 11:18:54 Database: mydb
10/19/07 11:18:54 Authentication: Windows
10/19/07 11:18:57 Processing: D:\eip_320.trc
10/19/07 11:18:57 WARNING: The following trace events were not captured: SQL:BatchStarting, SP:StmtStarting, SP:StmtCompleted, Showplan Statistics. Review the help file to ensure that you have collected the appropriate set of events and columns for your intended analysis.
10/19/07 11:18:57 ERROR: Event 10 does not contain the following required column(s): 15
10/19/07 11:18:57 WARNING: Event 10 does not contain the following recommended column(s): 3
10/19/07 11:18:57 WARNING: Event 11 does not contain the following recommended column(s): 3
10/19/07 11:18:57 ERROR: Event 12 does not contain the following required column(s): 15
10/19/07 11:18:57 WARNING: Event 12 does not contain the following recommended column(s): 3
10/19/07 11:18:57 ERROR: Event 14 does not contain the following required column(s): 15
10/19/07 11:18:57 ERROR: Event 15 does not contain the following required column(s): 15
10/19/07 11:18:57 ERROR: Event 17 does not contain the following required column(s): 15
10/19/07 11:18:57 ERROR: Performance analysis has been disabled because one or more events is missing required columns. Consult the help file for the recommended set of trace events and necessary columns.
10/19/07 11:18:57 Reads completed - Global Error Status 120
10/19/07 11:18:58 READER: Total Read Count: 5 Read Stall Count: 1 accounting for 16 ms in reader thread
10/19/07 11:18:58 Signaling all workers to complete
10/19/07 11:18:58 Handling final IOs and closing open files
10/19/07 11:18:58 Flushing and Compressing SPID Files
10/19/07 11:18:58 Total Events Processed: 0
 
错误信息意思就是有事件没有监测到，所以不能导入数据成功，字段不匹配．根据错误信息在事件监测里面添加：

SQL:Bat
chStarting, SP:StmtStarting, SP:StmtCompleted, Showplan Statistics

再一次运行．
 
错误信息如下：

10/19/07 15:59:53 ERROR: Event 10 does not contain the following required column(s): 15
10/19/07 15:59:53 WARNING: Event 10 does not contain the following recommended column(s): 3
10/19/07 15:59:53 WARNING: Event 11 does not contain the following recommended column(s): 3
10/19/07 15:59:53 ERROR: Event 12 does not contain the following required column(s): 15
10/19/07 15:59:53 WARNING: Event 12 does not contain the following recommended column(s): 3
10/19/07 15:59:53 WARNING: Event 13 does not contain the following recommended column(s): 3
10/19/07 15:59:53 ERROR: Event 14 does not contain the following required column(s): 15
10/19/07 15:59:53 ERROR: Event 15 does not contain the following required column(s): 15
10/19/07 15:59:53 ERROR: Event 17 does not contain the following required column(s): 15
10/19/07 15:59:53 WARNING: Statement level analysis is disabled because the SP:StmtStarting/SP:StmtCompleted event(s) do not contain the following required columns: 22, 29
10/19/07 15:59:53 WARNING: Event 45 does not contain the following recommended column(s): 3, 25
10/19/07 15:59:53 ERROR: Performance analysis has been disabled because one or more events is missing required columns. Consult the help file for the recommended set of trace events and necessary columns.
 
这个错误是因为监测的数据列没有添加进来导致的．如果怕嫌麻烦的话，直接把数据列全部添加进来．再次运行：

C:\Program Files\rml>Read80trace -f -dmydb -Id:\test\aaa.trc
Output path was not specified; defaulting to C:\Program Files\rml\output
10/19/07 16:13:19 -----------------------------------------------------
10/19/07 16:13:19 Read80Trace version 8.10.0010
10/19/07 16:13:19 -f
10/19/07 16:13:19 -dmydb
10/19/07 16:13:19 -Id:\test\aaa.trc
10/19/07 16:13:19 Establishing database connections:
10/19/07 16:13:19 Server: (local)
10/19/07 16:13:19 Database: mydb
10/19/07 16:13:19 Authentication: Windows
10/19/07 16:13:20 Processing: d:\test\aaa.trc
10/19/07 16:13:20 Processing: d:\test\aaa_1.trc
10/19/07 16:13:20 Processing: d:\test\aaa_2.trc
10/19/07 16:13:20 Processing: d:\test\aaa_3.trc
10/19/07 16:13:21 Processing: d:\test\aaa_4.trc
10/19/07 16:13:21 Processing: d:\test\aaa_5.trc
10/19/07 16:13:21 Processing: d:\test\aaa_6.trc
10/19/07 16:13:21 Events Read/Processed: 50000/11764 EPS: 50000/11764
10/19/07 16:13:22 Processing: d:\test\aaa_7.trc
10/19/07 16:13:22 Processing: d:\test\aaa_8.trc
10/19/07 16:13:22 Processing: d:\test\aaa_9.trc
10/19/07 16:13:23 Processing: d:\test\aaa_10.trc
10/19/07 16:13:25 Processing: d:\test\aaa_11.trc
10/19/07 16:13:25 Processing: d:\test\aaa_12.trc
10/19/07 16:13:25 Events Read/Processed: 100000/57561 EPS: 20000/11512
10/19/07 16:13:25 Processing: d:\test\aaa_13.trc
10/19/07 16:13:25 Processing: d:\test\aaa_14.trc
10/19/07 16:13:26 Processing: d:\test\aaa_15.trc
10/19/07 16:13:26 Processing: d:\test\aaa_16.trc
10/19/07 16:13:27 Reads completed - Global Error Status 0
10/19/07 16:13:31 READER: Total Read Count: 701 Read Stall Count: 45 accounting for 422 ms in reader thread
10/19/07 16:13:31 Signaling all workers to complete
10/19/07 16:13:31 Handling final IOs and closing open files
10/19/07 16:13:31 Flushing and Compressing SPID Files
10/19/07 16:13:31 Total Events Processed: 133899
10/19/07 16:13:31 Table dbo.tblUniqueBatches: loaded ~15 rows
10/19/07 16:13:31 Table dbo.tblUniqueStatements: loaded ~55 rows
10/19/07 16:13:31 Table dbo.tblUniquePlans: loaded ~51 rows
10/19/07 16:13:31 Table dbo.tblUniquePlanRows: loaded ~2707 rows
10/19/07 16:13:31 Table dbo.tblBatches: loaded ~3398 rows
10/19/07 16:13:31 Table dbo.tblStatements: loaded ~2200 rows
10/19/07 16:13:31 Table dbo.tblPlans: loaded ~1159 rows
10/19/07 16:13:31 Table dbo.tblPlanRows: loaded ~12106 rows
10/19/07 16:13:31 Table dbo.tblInterestingEvents: loaded ~0 rows
10/19/07 16:13:31 Table dbo.tblConnections: loaded ~7 rows
10/19/07 16:13:31 Indexing tables...
10/19/07 16:13:32 Doing post-load data cleanup...
10/19/07 16:13:32
10/19/07 16:13:32 Dumping error record 1 of 4:
10/19/07 16:13:32 --------------------------------------------------------------------------
10/19/07 16:13:32　  Description =
10/19/07 16:13:32　  Source　　  = Microsoft OLE DB Provider for SQL Server
10/19/07 16:13:32　  ERRORINFO.hrError = 0x80004005
10/19/07 16:13:32　  ERRORINFO.dwMinor = 3621
10/19/07 16:13:32　  ERRORINFO.clsid　 = {0C7FF16C-38E3-11D0-97AB-00C04FC2AD98}
10/19/07 16:13:32　  SQL State　　　　 = 01000
10/19/07 16:13:32　  Native Error　　  = 3621
10/19/07 16:13:32
10/19/07 16:13:32
10/19/07 16:13:32 Dumping error record 4 of 4:
10/19/07 16:13:32 --------------------------------------------------------------------------
10/19/07 16:13:32　  Description =
10/19/07 16:13:32　  Source　　  = Microsoft OLE DB Provider for SQL Server
10/19/07 16:13:32　  ERRORINFO.hrError = 0x80004005
10/19/07 16:13:32　  ERRORINFO.dwMinor = 512
10/19/07 16:13:32　  ERRORINFO.clsid　 = {0C7FF16C-38E3-11D0-97AB-00C04FC2AD98}
10/19/07 16:13:32　  SQL State　　　　 = 21000
10/19/07 16:13:32　  Native Error　　  = 512
10/19/07 16:13:32 Computing partial aggregates...
10/19/07 16:13:32 Exporting analysis data...
10/19/07 16:13:34 Data load completed.
10/19/07 16:13:35 In the future, analysis results are available by opening "C:\Program Files\rml\output\index.htm" with Internet Explorer.
 
好啦，执行成功啦．数据导入到数据库啦．直接运行刚才的存储过程；
 
use mydb
exec 存储过程名
 
结果出来啦．