SqlServer数据库性能问题解决实例

关键字：sys.dm_os_wait_stats, sys.dm_os_latch_stats, PAGELATCH_UP, BUFFER, CXPACKET, EXECSYNC,

在SqlServer 2005当中，引入了不少的系统视图，对系统性能的优化，以及解决具体的问题提供了非常多的帮助。但是，也因为提供的视图太多，新手也许就会无从下手。对于执行语句的性能调优，一般来说只要简单的使用“数据库引擎优化顾问”（Database Engine Tuning Advisor）即可。因此，不在这一篇文章当中进行阐述了。

对于线上系统的性能问题，我们通常会使用下面的几个手段：

1. 查看最近更新的源代码当中涉及数据库查询的改动；
2. 使用Sql Server Profiler对数据进行跟踪；
3. 在Sql Server Management Studio当中，点击“包括实际的执行计划”（include actual execution plan），然后对有怀疑的语句进行执行查看和分析；
4. 通过一些脚本查看是否存在死锁问题。

这几种手段可以单独实施，也可以组合事实。通常来说，上面这些手段基本上已经足矣。其中最为有效的，是使用方法2，找到CPU高，或者Duration高的语句。然后通过方法3去验证，以及根据计划所显示的不正常内容（例如，出现全表扫描），进行相应的处理。例如：

1. 添加索引；
2. 修改查询语句；
3. 修改其它表结构。

对于持续运行的系统来说（比如某些大型的电子商务门户），上面这几种手段的实施难度是按顺序逐步增加的，但效果却不一定同样逐步提高。很多时候添加索引就可以解决大部分的问题，而有的时候在不修改查询语句的前提下，是无论如何也不可能得到任何有价值的提升的。当然，某些特定情况下，修改表结构相当容易，而且效果极为夸张，例如：添加一个自增标示字段，同时添加其为主键。不过，这种情况通常都是基于原来表结构设计不合理的前提之下。

上述这些步骤，基本上就是一个入门级维护人员的基本工具。而在实际的战斗当中，有时候会比较复杂。比如说，有可能因为数据库太大导致性能损失，或者因为IO问题导致性能瓶颈等等。因此，稍微进阶一点的思路还应该包括：

1. 思考数据库是否真的过大（比如，超过500GB），或者处理量过大（比如，性能计数器Sql Server:SQL statistics下的Batch Request/s 达到1000以上）；
2. 思考数据库结构是否存在不合理的问题（比如，数据库当中有image字段，且平均大小非常大，而查询又经常取出这些字段）；
3. 思考是否软件架构本身出现了问题，比如前面提到的这些字段，是否真的需要每次都取出，或者是否应该具有合理的各级缓存手段；
4. 是否存在某些Bug（例如数据库链接没有释放）。

可以看出来，上面所提到的问题，已经不仅仅限于“某条Sql语句写得不好”，或者“数据表结构设计出现严重纰漏”这种方向。在实战当中，甚至很多时候根本就不能够确定问题是否真的和数据库有关。那么，最重要的、首先必须要解决的问题就出现了：到底问题出在哪里？

在这里，我们仅通过一个实际的案例，来看看如何进行一个数据库问题的排出的。（由于某种原因，这里面给出的数据并不真实，仅用于演示其大约规模）

场景：

WEB网站，较典型的OLTP应用，查询多，插入和修改比较少。数据库巨大，比如1TB，且当中个别表（例如3个表，分别简称A、B、C）包含一些二进制类型字段。这些二进制类型字段中的数据总量达到，比如说600GB，平均每一行当中该字段大小比如是10MB。同时这些表的总大小占据数据库的绝大部分，比如800GB。而整个系统的拓扑包含了CDN、前端缓存、负载均衡、Web服务器、数据库服务器以及专业SAN存储设备。

现象：

大量用户报告访问很慢，数据库CPU较高（60%），磁盘IO量巨大（3000tps），Web服务器CPU均较高60%，Web连接数较大（正常时例如200tps，受攻击时可达到比如2000tps）。每到月底销售需要赶任务时，会有大量报告访问慢的情况。而受到攻击的时候，也有类似的反应。Web服务器可见大量的数据库超时日志，而数据库端用Profiler则可见不少1秒以上的操作。甚至在Profiler长期跟踪的时候，会看到不时有一批数据库操作因为超时被服务器主动放弃执行。

解决过程：

首先，通过对数据库的二进制字段表进行一些简单的缓存处理，以及对存储硬件进行升级，解决了一部分潜在可能的IO问题。然后通过进行一些防火墙设置，例如前端缓存对特定状况下的动态内容，进行极为短暂的缓存，避免受到攻击时出现大量攻击涌入后面的Web服务器，进而造成数据库压力。除此之外，通过profiler检验所有CPU或者Duration较高的可疑Sql，并进行优化。

然而在这些措施之后，仅仅是有轻微的改善，无实质性的变化。甚至以较长的时间观测，例如一个月，发现实质趋于严重化：在经过多种改善措施之后，尤其是数据库服务器的CPU升级为原先的5倍以上，仍然CPU高，伴有数据库操作超时的问题。因此，基本上怀疑仍然是结构性问题——也许是拓扑结构的问题，也许是前端代码的问题，也许是数据库查询语句或者结构性问题。在经过对经常被使用的主要表格A、B、C当中的表结构、索引、查询语句乃至程序设计和拓扑结构的反复检查、推敲、验证后，均没有发现值得怀疑的地方（那个很大的二进制字段已经通过缓存来读取，基本上不通过数据库来进行查询）。而通过类似如下的这类语句

SELECT SUBSTRING(qt.TEXT, (qs.statement_start_offset/2)+1,
((CASE qs.statement_end_offset
WHEN -1 THEN DATALENGTH(qt.TEXT)
ELSE qs.statement_end_offset
END - qs.statement_start_offset)/2)+1),
qs.execution_count,
qs.total_logical_reads, qs.last_logical_reads,
qs.total_logical_writes, qs.last_logical_writes,
qs.total_worker_time,
qs.last_worker_time,
qs.total_elapsed_time/1000000 total_elapsed_time_in_S,
qs.last_elapsed_time/1000000 last_elapsed_time_in_S,
qs.last_execution_time,
qp.query_plan
FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
ORDER BY qs.total_worker_time DESC -- CPU time

所查询得到的Sql语句，其执行计划也没有看出任何问题，在结构完全一致的测试数据库当中进行查询，性能均没有任何问题。最慢也就100ms执行完毕，而且这个测试数据库的配置要比线上配置低很多。当时，这个问题基本上已经卡壳无解。

由于有人怀疑可能是系统存在某种Sql事务死锁，或者某种语句执行时间较长导致其加锁不被释放，于是后续Sql语句基本处于等待。因此，我开始转向查找系统自带的dmv。下面分别叙述曾经尝试过的主要视图，并简述其效果和结论。

dm_os_waiting_tasks

这个视图可以显示目前正被阻塞的任务，以及阻塞该任务的来源。通过使用CROSS APPLY dm_exec_sql_text(handle)，通常可以查看出被阻塞和引起阻塞的语句是什么。实际上有不少的脚本，就是通过这一个试图来查找阻塞乃至死锁链条。但实际的情况是，如果并非死锁而是某条语句执行时间较长，并且线上执行语句的吞吐量很大，这个试图是无法看出问题的。原因很简单：如果某个语句出现问题，导致其锁或闩阻碍大量语句的执行，则你查看该视图的时刻，很可能会在该语句已经执行完毕后续语句开始得以执行的时候。这样，你看到的“罪魁祸首”很可能其实是一个受害者。我就是过分相信着一个试图，导致大量的时间消耗在调查受害者上面。

sys.dm_exec_query_stats

这个视图可以看到从本次实例启动开始为止，曾经执行过的语句的统计情况。配合CROSS APPLY sys.dm_exec_query_plan(plan_handle)，可以看到其执行计划。通过这一个视图，可以找到累计执行时间较长的，或者最长时间最长的，或者次数较多的，或者读、写次数较高的语句。但是这一个视图无法显示出这些语句曾经经历过什么类型的锁和闩，换句话说，这只是一个统计。在这一个实战当中，这个试图无法发挥重要作用。因为累计执行时间较长的，也正好是执行次数最多的，而这些语句的平均执行时间都较小。而单词执行最长时间较高的，通常是因为有前面语句阻塞导致当前语句超时的超时时间。

sys.dm_exec_requests

这个视图可以看到当前正在请求执行的语句。一开始我一直认为这一视图对于解决问题的意义并不大，因为这只是显示当前正在执行的语句，既不象dm_exec_query_stats能给出关于各项耗时的统计，又不象dm_os_waiting_tasks那样，可以知道前因后果。再加上不少的脚本，都是通过join这个视图再CROSS APPLY dm_exec_sql_text来获得其sql语句，因此一直以为起作用也就仅限于此，除此以外也就走马观花而已。

sys.dm_tran_locks
这个视图主要是用于解决事务锁的，一般该视图用于解决死锁问题（或者锁过多的问题）。在本次实战当中，并没有发现死锁，而锁的内容不停发生变化，可见并没有出现长期持有事务的问题。因此本表在这一实战当中并没有发挥多大的作用。

sys.dm_tran_database_transactions
这个视图用于了解目前正在进行的事务，作用基本同上。这两个视图在解决事务导致的死锁问题上有很重要的意义。然而一般来说大家都会想到这一点，很快便能排除，因此这里也不做叙述。

sys.dm_os_wait_stats
这是一个对于性能而言至关重要的视图，也是在本次实战中起到启发作用的表。该视图显示了从实例本次启动（或者上一次清零）到现在为止，因为何种原因导致了等待，其总时间、总次数、最耗时一次所用时间等分别是多少。根据最耗时一次所用时间通常可以找到值得怀疑的等待原因。关于各种等待类型，请参考这里的官方说明。其中需要注意的是，某些类型的长时间等待也许是正常的，例如：
SQLTRACE_BUFFER_FLUSH、BROKER_RECEIVE_WAITFOR等。在本实战当中，早期就已经发现有大量的最大等待类型时间超出10秒，尤其是一个叫做LCK_M_IS的锁。但是当时没有执行清零重新进行统计，因此这一统计其实体现的是自上一次启动以来的情况，并不真实。基于这一步真实的观测结果，所进一步进行的排查，仍然没分析出所以然。后来仔细查看帮助，发现这个试图（以及下面提到的dm_os_latch_stats），是可以通过下面这个语句清零的：


DBCC SQLPERF ('sys.dm_os_wait_stats', CLEAR);


在访问高峰期进行清零之后，很快就能发现主要的可疑wait类型有下面这几个：
PAGELATCH_UP
MSQL_XP
LCK_M_X
SOS_SCHEDULER_YIELD
CXPACKET
EXESYNC

其中最值得怀疑的是后三者，其中SOS_SCHEDULER_YIELD的含义是，正在等待调度器将当前已经可以执行的语句调度到CPU当中进行执行。换句话说，就是CPU忙于处理某种任务，导致后续的查询在等待。其实在之前经过简单的搜索，发现可以通过安装这一个报表来查看详细的性能问题。这个报表就提示SOS_SCHEDULER_YIELD占总等待时间的22%以上，正是因为这一提示，我才再一次尝试查询本视图。而这一篇文章当中的“CPU Bottlenecks”一节，以及这篇博客中的“SOS_SCHEDULER_YIELD Explanation”当中均提出，SOS_SCHEDULER_YIELD占比较高的话，可以通过下列语句进一步排查：


SELECT scheduler_id, current_tasks_count, runnable_tasks_count, work_queue_count,pending_disk_io_count
FROM sys.dm_os_schedulers
WHERE scheduler_id < 255

实际上这个语句的执行结果，相当于各个CPU当中正在执行的任务数量，可以执行（但正在等待）的任务数量，以及正在等待IO结果的任务数量情况等。其中后者提到了，如果大部分CPU长时间出现2位数的runnable_tasks_count（就是可以执行但还在等CPU的任务数量），就表明任务负载过高。本文一开始所引用的脚本，就是该篇博客中后续提到的进一步方法。（然而很可能你和我一样，用这个方法找出来的都是一些正常的语句。）

而CXPACKET的含义是，要执行的SQL语句正在被分割成多组，发往多个不同的CPU进行执行。而EXESYNC则是并行计算完成时，等待多个不同CPU上的计算结果全部结束。根据这里提到的手册（简称手册A）说明，发现一般来说OLTP的应用不应该出现长时间这样的锁（甚至根本不应该出现）。如果出现这种情况，则说明SQL语句或者数据库结构出现问题。同时，这个手册中还提到一个叫做“get_statements_in_waiter_list”的存储过程，可以找到当前正在执行的语句当中，存在指定等待类型的SQL语句是什么。这一个存储过程可以在这里搜索到，实际正确的名称叫做“get_statements_from_waiter_list”。通过执行语句

Exec get_statements_from_waiter_list @wait_type = 'CXPACKET'

立刻找到了等待类型为CXPACKET的语句，这个语句大致长这样：
select row_number() over (order by xtime) as rownum, * from messages
  inner join message_comment on
  messages.messageId = message_comment.messageId
where
  messages.userId=1000 and
  ... and
  rownum between 100 and 110

由于使用了row_number（以及很可能还有另一个原因，下面会提到），其执行计划被设定为进行并行计算。而实际上经过检查发现，messages表没有做userId相关的索引，同时message_comment也没有做messageId的索引。尽管这两个表非常的小，分别只有比如30MB和6MB，然而由于需要进行全表的检索，外加并行计算占用了所有的CPU，因此几乎所有的查询都必须等待该查询执行完毕才能得以进行。而且似乎该闩之后，还需要对缓存进行操作，会进一步引起一些PAGELATCH_xx类型的闩处于等待状态，而PAGELATCH_xx这种等待，却不知因何原因在dm_os_waiting_tasks视图中显示为没有阻塞来源，仿佛都是因为这个闩本来就需要这么长的时间。然而实际上仔细分析，却觉得不太可能，因为这种闩本来就是对内存当中的缓存数据进行操作，这种闩如果不是因为被其它任务对相同的闩进行了锁操作，不可能需要这么长的时间仍然需要等待。就目前看到的情况推测，很可能CXPACKET引起的等待，不会被显示在dm_os_waiting_tasks的阻塞来源字段中。

通过改善这一个表的索引状况，CPU占用率很快从60%以上下降到10%左右，网站的访问速度也迅速提升恢复。将dm_os_wait_stats清零之后重新观察，发现除了那些正常的长时间等待类型之外，所有的等待类型的平均等待时间，例如SOS_SCHEDULER_YIELD、LCK_M_X、CXPACKET等，已经下降到100ms以下，甚至10ms以下。至此，问题已经得以解决。


总结

在某种特殊状况下，通过使用常规的Profiler分析很可能找不出原因。例如：引起问题的语句执行时间非常之长，并且出现频率并不高，同时又进行了并发计算，而且这一查询还锁住大量的资源。此时由于该语句引起大量其它语句执行时间变得非常长，这些被迫等待执行的语句本身并没有问题，所查询表格的结构与索引也没有问题，恰巧罪魁祸首又不会通过dm_os_waiting_tasks显出原形。甚至在使用Profiler的时候，可以看到几乎所有的Sql语句，甚至极为简单的根据主键找一条记录的一个简单字段这样的Sql语句，其执行时间也较长，并且是时快时慢。如果你遇到这样的状况，甚至在另一台无负载的机器上重复执行各种被怀疑的语句，仍无法复现查询缓慢的现象时，你可能就需要查看视图dm_os_wait_types，看看是否存在什么不正常的长时间等待了。

这个实战告诉我们，一个并不怎么经常会用到的、共不超过35MB的两张表，因为结构上的问题，外加特殊的查询语句的共同作用下，导致一个1TB数据库近乎无法访问，并且几乎无法找出原因。

最后多嘴两句：
1、除了dm_os_wait_stats，还有一个成为dm_os_latch_stats的视图，用于对闩（Latch）的原因进行分类分析。如果你的wait类型主要集中在xxx_latch的时候，可以参照这里面提供的信息进行一下分析。这一个视图也同样可以通过DBCC SQLPERF来清零；
2、本文当中提到的文档和资料，一定要仔细阅读，对于SqlServer一类的问题排查非常有价值。