SQL Server 性能调优札记

发现问题

今天服务器检查的时候发现SQL Server 2005服务器的CPU负载很高，而且一直居高不下，这是我当时在现场的截图:

 

服务器是一台4路服务器有4颗XEON 3GHz的CPU，8G的内容，SQL Server 2005是32位，打了SP2。

该服务器上跑了很多个业务系统的数据其中属于JT的数据库就有好几个，业务量还是挺大的。

排除是其他进程搞的鬼，确定是SQL Server 进程把服务器搞得这么忙。

 

定位问题

打开活动监视器按照CPU排序，得到如下信息，可见jt_user在jt_ComitOA上面的连接所作所为都是大动作啊。

 

 

接下来换一个工具，SQL Server Profiler 出场，调整跟踪的属性，调整为只是监视“SQL:Batch Completed”，而且将“DatabaseName”这个列选上，再调整一下列筛选器，如图：

这个列筛选器有个小Bug，输入完条件后最好按一下回车，否则有可能输入无效，OK开始我们的跟踪之旅。我这里简单地设置了一下DatabaseName，LoginName，CPU和Duration ，以便过滤掉一些无关紧要的值。

经过半个小时的收集，我得到了如下的跟踪信息：

 

我将部分语句Copy出来，顺便整理了一下格式。

exec oa_SWLIST 
'glzyf',
'(s.fileSerialNumber like ''%%'' or s.title like ''%%'' or s.keywords like ''%%'' or s.fileZi like ''%%'') and ',
' (  ft.userid=''glzyf'' ) '

exec oa_DBSX 'cwkfss',''

exec oa_FlowTurning 'jgstyb'

update FlowTurning set readStatus=1 where type='sw' and pkid='21712' and userid='cwkfss'

其中第一条语句的的占用率最严重，比其他的语句足足多了一个数量级。

 

 

分析问题

将数据库备份到一台测试的服务器上，查看一下数据库的数据文件和日志文件情况，发现日志文件比较大，貌似这也是一个SQL Server 存在的问题，具体原因不清楚，但是解决方法已经非常成熟，该问题暂时不影响使用，先不管它。

上一篇定位了问题，找出了多条Top SQL，其中这条最过分。

exec oa_SWLIST 
'glzyf',
'(s.fileSerialNumber like ''%%'' or s.title like ''%%'' or s.keywords like ''%%'' or s.fileZi like ''%%'') and ',
' (  ft.userid=''glzyf'' ) '

 

分析一下这个存储过程，我习惯是先看看SQL语句的结构，而不是马上看执行计划，或者直接跑语句获得统计信息。

ALTER PROCEDURE [dbo].[oa_SWLIST]
    @userID varchar(20),
    @sql varchar(1000),
    @userIDs varchar(1000)

AS
DECLARE @SQL1 nchar(4000) ;
DECLARE @SQL2 nchar(4000) ;

create table #employees(
[id] [int] IDENTITY(1,1) NOT NULL,parentId int,pkId int,status int,title nvarchar(1500),comeOrg nvarchar(100),
fileDate DateTime,fileName nvarchar(4000),filePath nvarchar(4000),readStatus nvarchar(10),optionStatus nvarchar(10), 
depId nvarchar(20),urgencyLevel nvarchar(10));

set @SQL1='insert into #employees (parentId,pkId,status,title,comeOrg,fileDate,fileName,filePath,readStatus,optionStatus,depId,urgencyLevel)
select distinct s.parentId,s.pkId,0,s.title,s.comeOrg,s.fileDate,
    s.fileName,s.filePath,ft.readStatus,0,s.remark3,
case 
when urgencyLevel=''普通'' then 0
when urgencyLevel=''急件'' then 1
when urgencyLevel=''特办'' then 2
when urgencyLevel=''特急件'' then 3
when urgencyLevel=''限时'' then 4
else 0
end as urgencyLevel
      from ShouWen as s ,  
FlowTurning as ft where '+@sql+' ft.status=0 and ft.type=''sw'' 
and s.pkid=ft.pkid and s.status<>''4'' and '+@userIDs+' order by urgencyLevel desc,s.filedate desc'

set @SQL2='insert into #employees (parentId,pkId,status,title,comeOrg,fileDate,
fileName,filePath,readStatus,optionStatus,depId,urgencyLevel)
select distinct s.parentId,s.pkId,1,s.title,s.comeOrg,s.fileDate,
    s.fileName,s.filePath,1,l.optionstatus,s.remark3,urgencyLevel
    from shouwen as s, log as l where '+@sql+' s.status<>''4'' and s.pkid in
(
select distinct(mid) from log where uid='''+@userID+''' and typeid=''shouwen''
)and l.mid=s.pkid and uid='''+@userID+''' and typeid=''shouwen''
order by s.fileDate desc'
print (@SQL1);
exec (@SQL1)
print ('+++++++++++++++++++++++++++++++++++');    
print (@SQL2);
exec (@SQL2)
select * from #employees
delete from #employees

从结果来看该存储过程其实就是执行了两条动态SQL，分别存在@SQL1和SQL2。我稍微修改了一下存储过程，加入了一些调试信息，打开统计器。

SET STATISTICS IO on; 
SET STATISTICS TIME on; 

执行存储过程，这里由于信息量比较大，我就不贴了，上一张图吧。

 

可见@SQL1的语句耗时并不多，@SQL2资源占用是非常厉害的。其中 Log 表扫描530次，这个表的数据量有257417条，说大不大，说小也不小了，而且还得扫描530次，唉，啥也不说了，而shouwen这张表就小很多也有25000+条记录。

我将@SQL2的语句整理出来，去掉那个讨厌的 insert into #employees。

select distinct s.parentId,s.pkId,1,s.title,s.comeOrg,s.fileDate,
    s.fileName,s.filePath,1,l.optionstatus,s.remark3,urgencyLevel
    from shouwen as s, 
    log as l 
    where 
    (s.fileSerialNumber like '%%' or s.title like '%%' 
     or s.keywords like '%%' or s.fileZi like '%%') 
     and  s.status<>'4' 
     and s.pkid in
        (select distinct(mid) from log where uid='glzyf' and typeid='shouwen')
     and l.mid=s.pkid and uid='glzyf' and typeid='shouwen'
order by s.fileDate desc  

看看这个select 语句的执行计划啦。

以下才是重点，两个在Log表上面的“聚集索引扫描”：

无论哪个RDBMS的语句调优，绝大部分的情况下都是将执行计划中的“扫描”转变为“查找”。下一篇讲解如何将“扫描”变为“查找”。

 

 

 

提出方案

以下是找出来的TOP SQL 。

select distinct s.parentId,s.pkId,1,s.title,s.comeOrg,s.fileDate,
    s.fileName,s.filePath,1,l.optionstatus,s.remark3,urgencyLevel
    from shouwen as s, 
    jt_ComitOA.dbo.log as l 
    where 
    (s.fileSerialNumber like '%%' or s.title like '%%' 
     or s.keywords like '%%' or s.fileZi like '%%') 
     and  s.status<>'4' 
     and s.pkid in
        (select distinct(mid) from log where uid='glzyf' and typeid='shouwen')
     and l.mid=s.pkid and uid='glzyf' and typeid='shouwen'
order by s.fileDate desc  

从执行计划中可以看到两个比较大操作，两个对Log表“聚集索引扫描”，观察语句不难以下发现就是导致两个“聚集索引扫描”的原因。

(select distinct(mid) from log where uid='glzyf' and typeid='shouwen')

and l.mid=s.pkid and uid='glzyf' and typeid='shouwen'

这次运气比较好，mid、uid和typeid都在这两个语句里面，于是我计划在Log表的mid、uid和typeid上面建索引

CREATE NONCLUSTERED INDEX [idx_log__uid_typeid] ON [Log] 
(
    [uid] ASC,
    [typeID] ASC,
    [mid] ASC
);

看一下执行计划新的执行计划：

留意左上角对ShouWen这个表的聚集索引扫描，由原先的相对比例0%（其实是接近0%），上升到27%，可见整体的资源消耗已经大大降低了。

表 'Log'。扫描计数 2，逻辑读取 3272 次，物理读取 0 次，预读 0 次，lob 逻辑读取 0 次，lob 物理读取 0 次，lob 预读 0 次。
表 'ShouWen'。扫描计数 1，逻辑读取 1436 次，物理读取 0 次，预读 0 次，lob 逻辑读取 0 次，lob 物理读取 0 次，lob 预读 0 次。

SQL Server 执行时间:
   CPU 时间 = 62 毫秒，占用时间 = 293 毫秒。

对Log表的访问量大大减少，这可是有25万条数据的表啊，总的执行时间更是大大减少，疗效相当的不错啊。

至此，可以认为该调优已经达到很好的效果了，从26秒的执行时间缩减到0.3秒，非常不错的成绩了。

 

审视方案

在新的执行计划中有两个键查找，键查找用来检索筛选索引没有涵盖的剩余列,说白了，就有一些输出列不在这个索引的覆盖范围中。看一下select的输出，的确有一个Log表的optionstatus字段，于是将索引的创建语句调整为：

CREATE NONCLUSTERED INDEX [idx_log__uid_typeid] ON [Log] 
(
    [uid] ASC,
    [typeID] ASC,
    [mid] ASC
)
INCLUDE ( [optionstatus])

 

同样以左上角的ShouWen表的“聚集索引扫描”为参照点，就执行计划来看，的确资源占用率再次大大降低了，看看执行的统计信息。

表 'Log'。扫描计数 2，逻辑读取 16 次，物理读取 0 次，预读 0 次，lob 逻辑读取 0 次，lob 物理读取 0 次，lob 预读 0 次。
表 'ShouWen'。扫描计数 1，逻辑读取 1436 次，物理读取 0 次，预读 0 次，lob 逻辑读取 0 次，lob 物理读取 0 次，lob 预读 0 次。

SQL Server 执行时间:
   CPU 时间 = 78 毫秒，占用时间 = 282 毫秒。

Log表的逻辑读取数大大减少，执行时间并没有太大变化。这是由于这次缩减的是逻辑读，即在缓存中读取，通常缓存是在内存中的，内存可是比磁盘快多了。

 

 

真凶

谨慎起见，我并没有马上将索引应用到生产的JT数据库上面，晚上12点，再次登陆数据库服务器，查看以下CPU的负载，把我吓了一跳。负载还是那么高，按我们的经验晚上该数据库服务应该是非常空闲的，为什么还会有这么大的负载呢。

马上打开活动监视器，发现结果还是和以前的一样，还是jt_user的用户CPU和IO最高，但是晚上jt_user对应的应用系统应该没有人用。

马上打开SQL Profiler，事件仅选BatchCompleted，将CPU的阀值设为5，Duration的阀值设为10，这个阀值其实已经很低的了，也就晚上12点我才敢这么设定。

结果收集的结果吓我一跳，

在短短的13分钟内，竟然同一条语句执行了1479次。

select top 1 end_time from Log_Network_circs order by end_time desc

Log_Network_circs这张表有2657563条记录，平均每秒查询1.89次，每分钟查询113.8次，说白了就是秒对一个265万条记录的表进行排序。而且这条语句明显能写成：

select max(end_time) from Log_Network_circs

 

又短效率比原来的还高，想不明白。以下是统计信息。

表 'Log_Network_circs'。扫描计数 3，逻辑读取 16352 次，物理读取 0 次，预读 0 次，lob 逻辑读取 0 次，lob 物理读取 0 次，lob 预读 0 次。

SQL Server 执行时间:
   CPU 时间 = 1156 毫秒，占用时间 = 619 毫秒。

更要命的是，我发现这个表的记录数是时刻增长的，每秒4~5条。insert 语句肯定肯定是让我那个这么低的阀值过滤掉了。

 

这个明显属于应用系统设计的问题，找开发商聊了。

 

不是办法的办法

与开发商联系后，问清楚情况，确认该表的数据可以删除，以防万一，将数据库备份，然后truncate了这个表。但是这个不是一个最好的解决办法，我个人认为该问题应该在应用层上面解决。我向开发商提出了以下几点建议：

1。将查询的频率调低一点。
2。select max(end_time) from Log_Network_circs 能比原来这条语句性能好很多，如果只是为了查最后一条。
3。直接写个触发器，在插入的时候把end_time存到别的表里面去，然后在这个表里面取end_time的值。
4。定时执行清空这个表的数据。