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中调用这个脚本)
SQLServer的命令行工具-sqlcmd
http://blog.csdn.net/u011679955/article/details/52152546
{
用法: 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