SQL Server性能问题案例解析 (1)

今天的博客将分享一个死锁的案例。阅读本文之前,需要对SQL Server的锁,事务,隔离级别有基本的了解。网络中有很多文章,我就不在这里复述了。

SQL Server中有一个叫做deadlock monitor的线程,会定期去检测死锁。如果检测到死锁发生,deadlock monitor会选择一个session作为victim 终止,从而解决死锁。在排查死锁时,我们通常建议客户开启trace flag 1222并抓取sql server trace用于分析。当开启了trace flag1222, SQL Server会将死锁的相关信息打印到ERROLROG中,包含信息有死锁的victim session, 各个参与死锁的session, 以及这些session正在等待的资源和锁。但如果同一时刻有多个死锁发生,这些死锁的信息会混杂在一起,很难区分。这时候如果有SQL trace,会相对容易很多。

我们的案例就是这个情况—同时发生了很多死锁。首先我们要找出死锁中牵扯到的所有session,整理出一个deadlock框架。

这是sql trace的一个截图


 

我们可以看到,session 71和session 121都在等待资源6cd5adef219d。

打开 SQL Server ERRORLOG,我们可以得知,当时的deadlock victim session的隔离级别, session id和等待资源。 deadlock victim是session 71。

 

 

ERRORLOG里也记录了session 71当时在等待什么资源,以及当时资源的的owner。对于session 71,我们可以得出如下信息:

session id :71

Process id: process107bdf4cf8

isolation level:read committed

status=suspened

wait resource: 6cd5adef219d

Resource-list关键字记录了当时涉及的资源等待情况,source owner,resource waiters以及等待的锁类型。

 

我们可以看到,当时session 71在成为deadlock vicitm 前处于等待状态(requestType=wait),请求的lock mode为更新锁(U)。而process107b591c38是当时资源的所有者(owner id),并且lock mode为U锁。

 

根据这个信息,我们就要可以查找process107b591c38的具体情况了,搜索process107b591c38关键字,得到如下信息:

session id :98

Process id:process107b591c38

isolation level:read committed

status=suspened

wait resource: 73da75056a30

own resource:

 

 

类似地,我们也可以得到session 98正在等待什么, 从而推理出整个deadlock chain。 具体的步骤和之前的方法相同,我就不一一列出了。以下是整个死锁的框架。

 

session id :71

Process id: process107bdf4cf8

isolation level:read committed

status=suspened

wait resource: KEY: 6:72057594045333504 (6cd5adef219d)

own resource: KEY: 6:72057594045333504 (6cd5adef219d)

blocked by: session 98

block sessoin: 121

 

session id :98

Process id:process107b591c38

isolation level:read committed

status=suspened

wait resource: KEY: 6:72057594045333504 (73da75056a30)

own resource: KEY: 6:72057594045333504 6cd5adef219d

blocked by:sessoin 123

block sessoin:71

 

session id : 123

Process id: process107b5b9868

isolation level:read committed

status=suspened

wait resource: KEY: 6:72057594045333504 73da75056a30

own resource: KEY: 6:72057594045333504 73da75056a30

blocked by 121

block sessoin: 98

 

spid=121

Process id: process107da05c38

isolation level:read committed

status=suspened

waitresource=KEY: 6:72057594045333504 (6cd5adef219d)

own resource:KEY: 6:72057594045333504 (73da75056a30)

blocked by: session 71

block sessoin:123

 

这些语句都在等待同一个表上的资源,下面是这张表的定义:

Column_name          Type                Computed                           Length Prec

--------------------------------------------------------------------------------------------------------

ENTITY_NAME      char                     no                                 10              

OTHER_KEY                char                     no                                 10             

SYS_GENERATED_ID         decimal                  no                                 9 18 

MAX_FOR_RANGE            decimal          no                                 9 10 

MAX_FOR_ENTITY           decimal                  no                                 9 18 

WARNING_LEVEL            decimal                  no                           9          18 

                                                                                                        

index_name               index_description                    Index_keys           

--------------------------------------------------------------------------------------------------------

CSSITLA1x                clustered, unique, primary key located on  PRIMARY ENTITY_NAME, OTHER_KEY

下面是这些session正在执行的语句:

71

exec sp_executesql N'SELECT
SYS_ID_CNTL_TBL01."ENTITY_NAME",SYS_ID_CNTL_TBL01."OTHER_KEY",SYS_ID_CNTL_TBL01."SYS_GENERATED_ID",SYS_ID_CNTL_TBL01."MAX_FOR_RANGE",SYS_ID_CNTL_TBL01."MAX_FOR_ENTITY",SYS_ID_CNTL_TBL01."WARNING_LEVEL"
FROM "SYS_ID_CNTL_TBL" SYS_ID_CNTL_TBL01 WITH (UPDLOCK) WHERE
(SYS_ID_CNTL_TBL01."ENTITY_NAME" = @0 AND
SYS_ID_CNTL_TBL01."OTHER_KEY" = @1)',N'@0 nvarchar(10),@1
nvarchar(10)',@0=N'VAC      
',@1=N'74 '

98

exec sp_executesql N'UPDATE
"SYS_ID_CNTL_TBL" SET "SYS_GENERATED_ID" = @0 WHERE
"ENTITY_NAME" = @1 AND "OTHER_KEY" = @2',N'@0 float,@1
nvarchar(10),@2
nvarchar(10)',@0=223658585,@1=N'VAC      
',@2=N'82 '

 

121

exec sp_executesql N'SELECT
SYS_ID_CNTL_TBL01."ENTITY_NAME",SYS_ID_CNTL_TBL01."OTHER_KEY",SYS_ID_CNTL_TBL01."SYS_GENERATED_ID",SYS_ID_CNTL_TBL01."MAX_FOR_RANGE",SYS_ID_CNTL_TBL01."MAX_FOR_ENTITY",SYS_ID_CNTL_TBL01."WARNING_LEVEL"
FROM "SYS_ID_CNTL_TBL" SYS_ID_CNTL_TBL01 WITH (UPDLOCK) WHERE
(SYS_ID_CNTL_TBL01."ENTITY_NAME" = @0 AND
SYS_ID_CNTL_TBL01."OTHER_KEY" = @1)',N'@0 nvarchar(10),@1
nvarchar(10)',@0=N'VAC      
',@1=N'39 '

 

123

exec sp_executesql N'SELECT
SYS_ID_CNTL_TBL01."ENTITY_NAME",SYS_ID_CNTL_TBL01."OTHER_KEY",SYS_ID_CNTL_TBL01."SYS_GENERATED_ID",SYS_ID_CNTL_TBL01."MAX_FOR_RANGE",SYS_ID_CNTL_TBL01."MAX_FOR_ENTITY",SYS_ID_CNTL_TBL01."WARNING_LEVEL"
FROM "SYS_ID_CNTL_TBL" SYS_ID_CNTL_TBL01 WITH (UPDLOCK) WHERE
(SYS_ID_CNTL_TBL01."ENTITY_NAME" = @0 AND
SYS_ID_CNTL_TBL01."OTHER_KEY" = @1)',N'@0 nvarchar(10),@1
nvarchar(10)',@0=N'VAC ',@1=N'75'

 

我们可以看到死锁设计到的多个select语句都是相同的,它们指定了updlock hint,所以会申请U锁并需要等待U锁。这一般是业务需要,所以我们不能简单的去掉这个hint来解决问题。

 

接下来仔细分析下select语句,它在where中的条件涉及到ENTITY_NAME列和OTHER_KEY列,但如果我们查看表SYS_ID_CNTL_TBL的定义后会发现,ENTITY_NAME列和OTHER_KEY列组成了这张表的unique cluster index。 这样就保证了所有的语句只会返回一行,并且只会在需要查找的数据上加锁。但trace 1222显示这些session已经获得了一个U锁,当仍然去尝试获得另外一行数据的U锁。这是为什么呢?

 

我们再看一下从SQL trace中获得的执行计划:

 

我们可以看到,这个语句确实只会返回一行,而且也用了Clustered Index Seek。但其中一步做了GetRangeThrouhConvert,这代表什么意思呢?我们在过去的博客中对此做过讲解,请参考https://blogs.msdn.com/b/apgcdsd/archive/2012/04/20/sql-server-2008.aspx

我们可以看到sp_executesql里指定的参数类型为nvarchar(),而ENTITY_NAME列和OTHER_KEY列的实际类型为varchar()。这样便使得SQL Server 要做一个数据类型转换,从而查询更多的本来不需要的行。那为什么程序会将参数类型设为nvarchar()呢?我们和客户进一步沟通后发现,客户的程序是Java, 并使用Microsoft JDBC driver, 这个 driver 会将客户端发过来的 character data 默认都声明成 nvarchar()。

如何改变这个行为呢?Microsoft JDBC drive链接字符中可以设定一个叫做sendStringParametersAsUnicode 的属性,它默认为true, 只要把它设置为false, 那问题就解决了!客户端发来的参数将会声明成varchar(),这样我们就不会再做数据类型转换了,那Select语句需要查询的数据就不会重叠,自然也就不会发生死锁了。类似问题也可以参考这个博客https://blogs.msdn.com/b/sqlcat/archive/2010/04/05/character-data-type-conversion-when-using-sql-server-jdbc-drivers.aspx

这就是今天的分享,更多SQL Server案例学习请持续关注本博客的更新。