整理 SQLSERVER排查阻塞

SQL Server允许并发操作,BLOCKING是指在某一操作没有完成之前,其他操作必须等待,以便于保证数据的完整性。
BLOCKING的解决方法要查看BLOCKING的头是什么,为什么BLOCKING头上的语句执行的很慢。通常来讲只要我们能找到BLOCKING头上的语句,我们总能够想出各种各种的办法,来提升性能,缓解或解决BLOCKING的问题。
但是问题的关键是,我们不知道BLOCKING什么时候会发生。用户跟我们抱怨数据库性能很差,等我们连上数据库去查看的时候,那时候有可能BLOCKING可能就已经过去了。性能又变好了。或者由于问题的紧急性,我们直接重新启动服务器以恢复运营。但是问题并没有最终解决,我们不知道下次问题会在什么时候发生。
BLOCKING问题的后果比较严重。因为终端用户能直接体验到。他们提交一个订单的时候,无论如何提交不上去,通常几秒之内能完成的一个订单提交,甚至要等待十几分钟,才能提交完成。更有甚者,极严重的BLOCKING能导致SQL Server停止工作。如下面的SQL ERRORLOG所表示, 在短短的几分钟之内,SPID数据从158增长到694, 并马上导致SQL Server打了一dump, 停止工作。我们很容易推断出问题的原因是由于BLOCKING导致的,但是我们无法得知BLOCKING HEADER是什么,我们必须要等下次问题重现时,辅之以工具,才能得知BLOCKING 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:24: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:26:50.97 
Server     **Dump thread - spid = 0, EC = 0x0000000000000000
2011-06-01 16:26:50.97 
Server    ***Stack Dump being sent to D:\MSSQL10.INSTANCE\MSSQL\LOG\SQLDump0004.txt
2011-06-01 16:26:50.97 Server      * 
*******************************************************************************
2011-06-01 16:26:50.97
Server      *  
2011-06-01 16:26:50.97
Server      * BEGIN STACK DUMP:  
2011-06-01 16:26:50.97 
Server      *   06/01/11 16:26:50 spid 4124  
2011-06-01 16:26:50.97 
Server      *  
2011-06-01 16:26:50.97 
Server      * Deadlocked Schedulers  
2011-06-01 16:26:50.97 
Server      *  
2011-06-01 16:26:50.97
Server      *****************************************  
2011-06-01 16:26:50.97
Server      *-------------------------------------------------------  
2011-06-01 16:26:50.97
Server      * Short Stack Dump  
2011-06-01 16:26:51.01 
Server      Stack Signature for the dump is 0x0000000000000258
 
  
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

然后打开一个查询窗口,执行下面的语句, 该语句修改一行数据,并等待2分钟,

BEGIN TRANSACTION
 
UPDATE TESTTABLE  SET  [NAME]  = 'bbbb' WHERE  [ID]  =  1
 
WAITFOR DELAY '00:02:00'
 
-------COMMIT TRANSACTION
 
这时候,如果打开另外一个查询窗口,执行下面的语句,下面的语句就会被BLOCK住。
UPDATE  TESTTABLE  SET  [NAME]  = 'cccc' WHERE  [ID]  =  1

然后再结束 执行 COMMIT TRANSACTION 提交进程后,上条语句就可以执行。
   
方法一, 抓取 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 ( TEXTAS VARCHAR ( MAX ))
FROMMASTER .dbo . sysprocesses   p 
INNERJOIN MASTER . dbo . sysdatabases   d  
ON  p . dbid =  d . dbid
INNERJOIN MASTER . dbo . syslogins   l
ON   p . sid =  l . sid  
CROSSAPPLY sys . dm_exec_sql_text ( sql_handle )
  WHERE    p . blocked  =  0 
  ANDEXISTS ( SELECT  1   FROMMASTER .. sysprocesses.. p1 
  WHERE    p1 . blocked  =  p . spid )

这样,一次执行,就能告诉我们BLOCKING header的SPID信息,以及该SPID在做的语句。我们可以进一步研究该语句,以理解为什么该语句执行很慢。
用这个方法有一个缺点,就是使用的时候,要求BLOCKING是存在的。如果BLOCKING已经消失了,那么我们的方法就不管用了。


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

因为我们通常无法知道BLOCKING什么时候会产生,所以通常的办法是我们长期运行一个BLOCKING SCRIPT, 这样,等下次发生的时候,我们就会有足够的信息。
长期运行 BLOCKING SCRIPT 对性能基本上是没有影响的。因为我们每隔10秒钟抓取一次信息。缺点是,如果问题一个月才发生一次,那么,我们的BLOCKING日志信息会很大。
所以这种方法适用于几天之内能重现问题。
运行方法如下: (先在sql server分析器中将 BLOCKING SCRIPT的 脚本另存一份到 D盘,然后再sqlcmd中调用这个脚本)
{ 用法: Sqlcmd            [-U 登录 ID]          [-P 密码]  [-S 服务器]            [-H 主机名]          [-E 可信连接] [-d 使用数据库名称] [-l 登录超时值]     [-t 查询超时值]  [-h 标题]           [-s 列分隔符]      [-w 屏幕宽度]  [-a 数据包大小]        [-e 回显输入]        [-I 允许带引号的标识符] [-c 命令结束]            [-L[c] 列出服务器[清除输出]] [-q "命令行查询"]
   [-Q "命令 行查询" 并退出]  [-m 错误级别]        [-V 严重级别]     [-W 删除尾随空格] [-u unicode 输出]    [-r[0|1] 发送到 stderr 的消息] [-i 输入文件]         [-o 输出文件]     
   [-z 新密码]  [-f <代码页> | i:<代码页>[,o:<代码页>]] [-Z 新建密码并退出]  [-k[1|2] 删除[替换]控制字符]  [-y 可变长度类型显示宽度]  [-Y 固定长度类型显示宽度]
 [-p[1] 打印统计信息[冒号格式]]  [-R 使用客户端区域设置]  [-b 出错时中止批处理]  [-v 变量 = "值"...] [-A 专用管理连接]
 [-X[1] 禁用命令、启动脚本、环境变量[并退出]]  [-x 禁用变量情况]  [-? 显示语法摘要] }
如果要停止运行,我们按 ctrl+c 就可以了。
BLOCKING的信息存在log.out这个文件中

我们可以打开log.out这个文件, 会发现SPID 54被 SPID 53给Block住了。
-----测试运行没有看到这样的效果。不知道脚本哪里有问题
而随后,我们可以看到SPID=53在做什么事情:
DBCC INPUTBUFFER (53)

下面是 BLOCKING SCRIPT 的脚本(不在SQL分析器中执行), 我们可以把它存为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 sys.sysprocesses
--where (kpid <> 0 ) or (spid < 51)
-- Change it if you only want to see the working processes
print '*********lockinfor***********'
select convert ------- 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 'input buffer for running processes'
declare  @spid  varchar ( 6 )
declare  ibuffer  cursor fast_forward for
select cast ( spid  as varchar ( 6 )) as  spid  from
sys.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 input buffer (' +  @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 这两个表格中,如果跟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


  • 0
    点赞
  • 4
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值