SQLSERVER排查阻塞Word格式文档下载.docx

1、BLOCKING 问题的后果比较严重。因为终端用户能直接体验到。他们提交一个订单的时候，无论如何提交不上去，通常几秒之内能完成的一个订单提交，甚至要等待十几分钟，才能提交完成。更有甚者，极严重的 BLOCKING 能导致 SQL Server 停止工作。如下面的 SQL ERRORLOG 所表示,在短短的几分钟之内，SPID 数据从 158增长到 694,并马上导致 SQL Server 打了一个 dump,停止工作。我们很容易推断出问题的原因是由于 BLOCKING 导致的，但是我们无法得知 BLOCKING HEADER 是什么，我们必须要等下次问题重现时，辅之以工具，才能得知 BLOCK

2、ING HEADER 在做什么事情。如果信息抓取时机不对，我们可能要等问题发生好几次，才能抓到。这时候，客户和经理就会有抱怨了。因为我们的系统是生产系统，问题每发生一次，都会对客户带来损失。2011-06-01 16:22:30.98 spid1931 Alert There are 158 Active database sessions which is too high.2011-06-01 16:23:31.16 spid3248 Alert There are 342 Active database sessions which is too high.2011-06-01 16:2

3、4:31.06 spid3884 Alert There are 517 Active database sessions which is too high.2011-06-01 16:25:31.08 spid3688 Alert There are 694 Active database sessions which is too high.2011-06-01 16:26:50.93 Server Using dbghelp.dll version 4.0.5 2011-06-01 16:50.97 Server *Dump thread-spid=0,EC=0 x0000000000

4、000000 2011-06-01 16:50.97 Server *Stack Dump being sent to D:MSSQL10.INSTANCEMSSQLLOGSQLDump0004.txt 2011-06-01 16:50.97 Server *2011-06-01 16:50.97 Server *BEGIN STACK DUMP:50.97 Server *06/01/11 16:50 spid 4124 2011-06-01 16:50.97 Server *Deadlocked Schedulers 2011-06-01 16:50.97 Server *-2011-06

5、-01 16:50.97 Server *Short Stack Dump 2011-06-01 16:51.01 Server Stack Signature for the dump is 0 x0000000000000258 BLOCKING 的信息抓取有很多种方法。这里罗列了几种。并且对每种分析它的优缺点。以便我们选择。在枚举方法之前，我们先简单演示一下 BLOCKING.我们首先创建一个测试表:DROP TABLE TESTTABLE GO CREATE TABLE dbo.TESTTABLE（ID int NULL,NAME nvarchar（50）NULL）GO INSERT

6、INTO TESTTABLE VALUES（1,aaaa）GO 然后打开一个查询窗口，执行下面的语句,该语句修改一行数据，并等待 3 分钟，然后在结束 transaction BEGIN TRANSACTION UPDATE TESTTABLE SET NAME=bbbb WHERE ID=1 WAITFOR DELAY 00:03:00 COMMIT TRANSACTION 这时候，如果打开另外一个查询窗口，执行下面的语句，下面的语句就会被BLOCK住。UPDATE TESTTABLE SET NAME=cccc WHERE ID=1 方法一,抓取 SQL Profiler=SQL Prof

7、iler 里面包含大量的信息。其中有一个事件在 Errors and Warnings-Blocked Process Report 专门用来获得 blocking的情况。但是因为信息量比较大，而且我们并不能很好的估算在什么时候会产生 blocking，另外在生产环境使用Profiler,对性能可能会有影响，所以 SQL Profiler 并不是最合适的工具。我们在这里并不对它赘述。方法二,执行查询=如果我们检查问题的时候，blocking还存在，那么，我们可以直接可以运行几个查询，得知 BLOCKING HEADER 的信息 SELECT*FROM sys.sysprocesses wher

8、e spid50 上述查询只是告诉我们，BLOCKING HEADER 的头是 SPID=53,但是并没有告诉我们 SPID=53 在做什么事情。我们可以用下面的查询，得到 SPID=53 的信息 DBCC INPUTBUFFER（53）我们可以把上述的两个查询合并起来，用下面的查询:SELECT SPID=p.spid,DBName=convert（CHAR（20）,d.name）,ProgramName=program_name,LoginName=convert（CHAR（20）,l.name）,HostName=convert（CHAR（20）,hostname）,Status=p.s

9、tatus,BlockedBy=p.blocked,LoginTime=login_time,QUERY=CAST（TEXT AS VARCHAR（MAX）FROM MASTER.dbo.sysprocesses p INNER JOIN MASTER.dbo.sysdatabases d ON p.dbid=d.dbid INNER JOIN MASTER.dbo.syslogins l ON p.sid=l.sid CROSS APPLY sys.dm_exec_sql_text（sql_handle）WHERE p.blocked=0 AND EXISTS（SELECT 1 FROM M

10、ASTER.sysprocesses p1 WHERE p1.blocked=p.spid）这样，一次执行，就能告诉我们 BLOCKING header 的 SPID信息，以及该 SPID在做的语句。我们可以进一步研究该语句，以理解为什么该语句执行很慢。用这个方法有一个缺点，就是使用的时候，要求 BLOCKING 是存在的。如果BLOCKING 已经消失了，那么我们的方法就不管用了。方法三,长期执行一个 BLOCKING SCRIPT=因为我们通常无法知道 BLOCKING 什么时候会产生，所以通常的办法是我们长期运行一个 BLOCKING SCRIPT,这样，等下次发生的时候，我们就会有足够

11、的信息。长期运行 BLOCKING SCRIPT 对性能基本上是没有影响的。因为我们每隔 10秒钟抓取一次信息。缺点是，如果问题一个月才发生一次，那么，我们的 BLOCKING 日志信息会很大。所以这种方法适用于几天之内能重现问题。运行方法如下:如果要停止运行，我们按 ctrl+c就可以了。BLOCKING 的信息存在 log.out 这个文件中 我们可以打开 log.out 这个文件,会发现 SPID 54 被 SPID 53给 Block 住了。而随后，我们可以看到 SPID=53 在做什么事情:下面是 BLOCKING SCRIPT 的脚本,我们可以把它存为 blocking.sql u

12、se master go while 1=1 begin print Start time:+convert（varchar（26）,getdate（）,121）Print Running processes select spid,blocked,waittype,waittime,lastwaittype,waitresource,dbid,uid,cpu,physical_io,memusage,login_time,last_batch,open_tran,status,hostname,program_name,cmd,net_library,loginame from syspro

13、cesses -where（kpid 0）or（spid 50 open ibuffer fetch next from ibuffer into spid while（fetch_status!=-1）begin print print DBCC INPUTBUFFER FOR SPID +spid exec（dbcc inputbuffer（+spid+）fetch next from ibuffer into spid end deallocate ibuffer waitfor delay 0:0:10 End 这种方法的缺陷就是，log.out 会比较巨大，会占用很大的空间，如果 b

14、locking一个月甚至更长时间才发生一次，那我们的这个方法就不太适宜。方法四,我们用 Agent Job 来检查 BLOCKING=长期运行一个 BLOCKING SCRIPT 的缺点是我们每隔一段时间，去查询信息，但是大多数收集的信息是无用的。所以会导致日志文件巨大，对于一个生产系统来讲，磁盘空间满可不是个好事情，另外，有一些客户对于用命令行来长期运行 TSQL脚本有所顾忌，所以我们做了一个改进。这次，我们只收集有用的信息。对于无用的信息我们不关注。这样能极大减少日志大小。我们首先创建一个观察数据库，然后建立两张表格 Blocking_sysprocesses 和Blocking_SQLT

15、ext,建立一个存储过程和一个 Job,该 Job 每隔一段时间去调用存储过程。只有发现有 blocking的，我们才记录到表格 Blocking_sysprocesses 和Blocking_SQLText 这两个表格中。如果跟 blocking无关，我们就不对它进行记录。下面是 TSQL语句:CREATE DATABASE MonitorBlocking GO USE MonitorBlocking GO CREATE TABLE Blocking_sysprocesses（spid smallint,kpid smallint,blocked smallint,waitType bina

16、ry（2）,waitTime bigInt,lastWaitType nchar（32）,waitResource nchar（256）,dbID smallint,uid smallint,cpu int,physical_IO int,memusage int,login_Time datetime,last_Batch datetime,open_Tran smallint,status nchar（30）,sid binary（86）,hostName nchar（128）,program_Name nchar（128）,hostProcess nchar（10）,cmd nchar（

17、16）,nt_Domain nchar（128）,nt_UserName nchar（128）,net_Library nchar（12）,loginName nchar（128）,context_Info binary（128）,sqlHandle binary（20）,CapturedTimeStamp datetime）GO CREATE TABLE dbo.Blocking_SqlText（spid smallint,sql_text nvarchar（2000）,Capture_Timestamp datetime ）GO CREATE PROCEDURE dbo.checkBloc

18、king AS BEGIN SET NOCOUNT ON;SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED declare Duration int-in milliseconds,1000=1 sec declare now datetime declare Processes int select Duration=100-in milliseconds,1000=1 sec select Processes=0 select now=getdate（）CREATE TABLE#Blocks_rg（spid smallint,kpid sma

19、llint,blocked smallint,waitType binary（2）,waitTime bigInt,lastWaitType nchar（32）,waitResource nchar（256）,dbID smallint,uid smallint,cpu int,physical_IO int,memusage int,login_Time datetime,last_Batch datetime,open_Tran smallint,status nchar（30）,sid binary（86）,hostName nchar（128）,program_Name nchar（1

20、28）,hostProcess nchar（10）,cmd nchar（16）,nt_Domain nchar（128）,nt_UserName nchar（128）,net_Library nchar（12）,loginName nchar（128）,context_Info binary（128）,sqlHandle binary（20）,CapturedTimeStamp datetime）INSERT INTO#Blocks_rg SELECT spid,kpid,blocked,waitType,waitTime,lastWaitType,waitResource,dbID,uid,

21、cpu,physical_IO,memusage,login_Time,last_Batch,open_Tran,status,sid,hostName,program_name,hostProcess,cmd,nt_Domain,nt_UserName,net_Library,loginame,context_Info,sql_Handle,now as Capture_Timestamp FROM master.sysprocesses where blocked 0 AND waitTime Duration SET Processes=rowcount INSERT into#Bloc

22、ks_rg SELECT src.spid,src.kpid,src.blocked,src.waitType,src.waitTime,src.lastWaitType,src.waitResource,src.dbID,src.uid,src.cpu,src.physical_IO,src.memusage,src.login_Time,src.last_Batch,src.open_Tran,src.status,src.sid,src.hostName,src.program_name,src.hostProcess,src.cmd,src.nt_Domain,src.nt_UserN

23、ame,_Library,src.loginame,src.context_Info,src.sql_Handle ,now as Capture_Timestamp FROM master.sysprocesses src inner join#Blocks_rg trgt on trgt.blocked=src.spid if Processes 0 BEGIN INSERT dbo.Blocking_sysprocesses SELECT*from#Blocks_rg DECLARE SQL_Handle binary（20）,SPID smallInt;DECLARE cur_hand

24、le CURSOR FOR SELECT sqlHandle,spid FROM#Blocks_rg;OPEN cur_Handle FETCH NEXT FROM cur_handle INTO SQL_Handle,SPID WHILE（FETCH_STATUS=0）BEGIN INSERT dbo.Blocking_SqlText SELECT SPID,CONVERT（nvarchar（4000）,text）,now as Capture_Timestamp from:fn_get_sql（SQL_Handle）FETCH NEXT FROM cur_handle INTO SQL_H

25、andle,SPID END CLOSE cur_Handle DEALLOCATE cur_Handle END DROP table#Blocks_rg END GO USE msdb;GO EXEC dbo.sp_add_job job_name=NMonitorBlocking;GO EXEC sp_add_jobstep job_name=NMonitorBlocking,step_name=Nexecute blocking script,subsystem=NTSQL,command=Nexec checkBlocking,database_name=NMonitorBlocki

26、ng;GO EXEC sp_add_jobSchedule name=NScheduleBlockingCheck,job_name=NMonitorBlocking,freq_type=4,-daily freq_interval=1,freq_subday_type=4,freq_subday_interval=1 EXEC sp_add_jobserver job_name=NMonitorBlocking,server_name=N（local）当 Blocking发生一段时间后，我们可以查询下面的两个表格，以得知当时问题发生时的 blocking信息:use MonitorBlocking GO SELECT*from Blocking_sqlText SELECT*FROM Blocking_sysprocesses