如何有效抓取SQL Server的BLOCKING信息

BLOCKING的信息抓取有很多种方法。这里罗列了几种。并且对每种分析它的优缺点。以便我们选择。在枚举方法之前，我们先简单演示一下BLOCKING. 

我们首先创建一个测试表:

DROP TABLE [TESTTABLE]
GO 

CREATE TABLE [dbo].[TESTTABLE](
      [ID] [int] NULL,
      [NAME] [nvarchar](50) NULL
)
GO 

INSERT 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 Profiler里面包含大量的信息。其中有一个事件在Errors and Warnings->Blocked Process Report专门用来获得blocking的情况。但是因为信息量比较大，而且我们并不能很好的估算在什么时候会产生blocking，另外在生产环境使用Profiler, 对性能可能会有影响，所以SQL Profiler并不是最合适的工具。我们在这里并不对它赘述。

方法二, 执行查询

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

如果我们检查问题的时候，blocking还存在，那么，我们可以直接可以运行几个查询，得知BLOCKING HEADER的信息 

SELECT * FROM sys.sysprocesses where spid>50

上述查询只是告诉我们，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.status,
       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   MASTER..sysprocesses p1
                   WHERE  p1.blocked = p.spid)

这样，一次执行，就能告诉我们BLOCKING header的SPID信息，以及该SPID在做的语句。我们可以进一步研究该语句，以理解为什么该语句执行很慢。 

用这个方法有一个缺点，就是使用的时候，要求BLOCKING是存在的。如果BLOCKING已经消失了，那么我们的方法就不管用了。 

方法三,长期执行一个BLOCKING SCRIPT

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

因为我们通常无法知道BLOCKING什么时候会产生，所以通常的办法是我们长期运行一个BLOCKING SCRIPT, 这样，等下次发生的时候，我们就会有足够的信息。长期运行BLOCKING SCRIPT对性能基本上是没有影响的。因为我们每隔10秒钟抓取一次信息。缺点是，如果问题一个月才发生一次，那么，我们的BLOCKING日志信息会很大。所以这种方法适用于几天之内能重现问题。 

运行方法如下: 

如果要停止运行，我们按ctrl+c就可以了。

BLOCKING的信息存在log.out这个文件中 

我们可以打开log.out这个文件, 会发现SPID 54被 SPID 53给Block住了。 

而随后，我们可以看到SPID=53在做什么事情: 

下面是BLOCKING SCRIPT的脚本, 我们可以把它存为blocking.sql 

use 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 sysprocesses
	--where (kpid <> 0 ) or (spid < 51)
	-- Change it if you only want to see the working processes

	print '*********lockinfor***********'

	select convert (smallint, req_spid) As spid,
		rsc_dbid As dbid,
		rsc_objid As ObjId,
		rsc_indid As IndId,
		substring (v.name, 1, 4) As Type,
		substring (rsc_text, 1, 16) as Resource,
		substring (u.name, 1, 8) As Mode,
		substring (x.name, 1, 5) As Status
	from master.dbo.syslockinfo,
		master.dbo.spt_values v,
		master.dbo.spt_values x,
		master.dbo.spt_values u
	where master.dbo.syslockinfo.rsc_type = v.number
		and v.type = 'LR'
		and master.dbo.syslockinfo.req_status = x.number
		and x.type = 'LS'
		and master.dbo.syslockinfo.req_mode + 1 = u.number
		and u.type = 'L'
	order by spid

	print 'inputbuffer for running processes'

	declare @spid varchar(6)
	declare ibuffer cursor fast_forward for
		select cast (spid as varchar(6)) as spid from sysprocesses where 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会比较巨大，会占用很大的空间，如果blocking一个月甚至更长时间才发生一次，那我们的这个方法就不太适宜。 

方法四,我们用Agent Job来检查BLOCKING

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

长期运行一个BLOCKING SCRIPT的缺点是我们每隔一段时间，去查询信息，但是大多数收集的信息是无用的。所以会导致日志文件巨大，对于一个生产系统来讲，磁盘空间满可不是个好事情，另外，有一些客户对于用命令行来长期运行TSQL脚本有所顾忌，所以我们做了一个改进。这次，我们只收集有用的信息。对于无用的信息我们不关注。这样能极大减少日志大小。 

我们首先创建一个观察数据库，然后建立两张表格 Blocking_sysprocesses和Blocking_SQLText, 建立一个存储过程和一个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] 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(128),
      [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
)
GO

CREATE TABLE [dbo].[Blocking_SqlText](
      [spid] [smallint],
      [sql_text] [nvarchar](2000),
      [Capture_Timestamp] [datetime]
)
GO 

CREATE PROCEDURE [dbo].[checkBlocking]
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] smallint,
      [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(128),
      [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],
      [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 #Blocks_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_UserName],
      src.[net_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_handle 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_Handle, @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 = N'MonitorBlocking';
GO 

EXEC sp_add_jobstep
	@job_name = N'MonitorBlocking',
	@step_name = N'execute blocking script', 
	@subsystem = N'TSQL',
	@command = N'exec checkBlocking',
	@database_name=N'MonitorBlocking';
GO    

EXEC sp_add_jobSchedule
      @name = N'ScheduleBlockingCheck',
      @job_name = N'MonitorBlocking',
      @freq_type = 4, -- daily
      @freq_interval = 1,
      @freq_subday_type = 4,
      @freq_subday_interval = 1 

EXEC sp_add_jobserver @job_name = N'MonitorBlocking', @server_name = N'(local)' 

当Blocking发生一段时间后，我们可以查询下面的两个表格，以得知当时问题发生时的blocking信息: 

use MonitorBlocking
GO   

SELECT * from Blocking_sqlText
SELECT * FROM Blocking_sysprocesses 

引自：http://blogs.msdn.com/b/apgcdsd/archive/2011/12/12/sql-server-blocking.aspx