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案例学习请持续关注本博客的更新。