揭秘数据库性能杀手-等待

在上一篇文章《揭秘数据库性能杀手 - 等待》中提到，等待是揭秘数据库性能故障的有效手段。

比如下面的 5 分钟采样图，可以帮我们解析平均等待 CPU 执行时间：

此图展示了平均等待 CPU 执行的时间是均衡的，会有一个峰值，但是会回落到正常区间。最大等待也不会超越总计等待时间的 10.82%.

再次回顾下，查询的生命周期：等待，执行，等待，执行。过程中会经历这些状态：

Running - 正在 CPU 上执行

Runnable - 等待分配 CPU 的执行时间，此时 CPU 正在执行其他 Query 而无暇分配执行资源

Suspended - 等待资源的分配，等到资源分配之后，重新进入 CPU 队列，等待 CPU 执行

只有在 Suspended 状态下，是在等待除了 CPU 资源外，其他系统资源的释放。

平均等待 CPU 执行时间，当然是越小越好。但实际情况，总是在一个范围内波动。一旦超过这个波动范围，我们就要着手分析，超出的原因。怎么分析，我的下篇文章《用好三个 DMV, 检测 80%的性能故障问题》中会着重讲解。

这篇文章，预先跟大家分享下捕获性能指标用到的脚本，以及捕获性能数据之后，怎么来分析。

脚本是开了一个窗口，连续 5 分钟的来获取性能数据。如果 5 分钟太频繁，影响系统性能了（这会在性能指标展示图中，分析出来，我们的捕获动作是不是对系统性能影响过大），就设置的时间间隔再长一些，并且仅捕获一些常用的性能指标数据。

CREATE TABLE T_GLOBAL_WAIT_COLLECT_PROGRESS_CONTROL

(ENABLED_FLAG INT ) ;

INSERT INTO T_GLOBAL_WAIT_COLLECT_PROGRESS_CONTROL(ENABLED_FLAG) VALUES(1);

CREATE TABLE T_GLOBAL_WAIT_STATS_HISTORY

(

CHECKPOINT_SEQUENCE BIGINT IDENTITY(1,1)

,WAIT_TYPE NVARCHAR(60)

,WAITING_TASKS_COUNT BIGINT

,WAIT_TIME_MS BIGINT

,MAX_WAIT_TIME_MS BIGINT

,SIGNAL_WAIT_TIME_MS BIGINT

,CHECKPOINT_DATETIME DATETIME

)

DECLARE @INC_TIME_PERIOD INT = 5 ;

DECLARE @WAIT_DELAY VARCHAR(20) = '' ;

SET @WAIT_DELAY = LEFT( '00:' + RIGHT('00'+CONVERT(VARCHAR,@INC_TIME_PERIOD),2),5 )

WHILE(EXISTS(SELECT * FROM T_GLOBAL_WAIT_COLLECT_PROGRESS_CONTROL WHERE ENABLED_FLAG=1))

BEGIN

INSERT INTO T_GLOBAL_WAIT_STATS_HISTORY(WAIT_TYPE

,WAITING_TASKS_COUNT

,WAIT_TIME_MS

,MAX_WAIT_TIME_MS

,SIGNAL_WAIT_TIME_MS

,CHECKPOINT_DATETIME

)

SELECT wait_type

,waiting_tasks_count

,wait_time_ms

,max_wait_time_ms

,signal_wait_time_ms

,getutcdate()

FROM sys.dm_os_wait_stats WITH(NOLOCK)

WHERE waiting_tasks_count + wait_time_ms + max_wait_time_ms + signal_wait_time_ms 0

WAITFOR DELAY @WAIT_DELAY ;

END

; WITH BASE_QUERY AS (

SELECT CHECKPOINT_DATETIME, ROW_NUMBER() OVER ( ORDER BY CHECKPOINT_DATETIME) AS RNK

FROM (SELECT DISTINCT CHECKPOINT_DATETIME FROM T_GLOBAL_WAIT_STATS_HISTORY WITH(NOLOCK) ) TMP

)

, CAL_QUERY AS ( SELECT HIS.*, BQ.RNK

FROM T_GLOBAL_WAIT_STATS_HISTORY HIS

INNER JOIN BASE_QUERY BQ ON HIS.CHECKPOINT_DATETIME = BQ.CHECKPOINT_DATETIME

)

SELECT CHECKPOINT_DATETIME,

CONVERT(NUMERIC(9,2),

100.00* SUM( SIGNAL_WAIT_TIME_MS ) / SUM( WAIT_TIME_MS) )

FROM CAL_QUERY

GROUP BY CHECKPOINT_DATETIME

这就是上图中用到的脚本了。

平均占比有时候能看到全局的波动，掌握大趋势。但对细小的波动可能就会略去，尤其是平均数还会掩盖小细节的异常。

比如下图所示，其实每种 wait 都在剧烈的变化着，如果我们忘记观察他们，就很难得到诸如客户端访问异常的情况，比如有大量的读在被客户调用：

红色波峰其实是 Async_IO_COMPLETION 等待的异常。

(图中线非常多，多亏 Excel 能即点即示。你能很快找到你感兴趣的那几条线。要追求完美，自己动手写 D3.js 吧）

Async_IO_COMPLETION 是由于客户端接收数据能力偏弱造成的。可能的原因是客户端在按批次处理数据，但批次量太多，而每批次的数据量客户端处理繁忙，把剩余数据留在服务器端等待客户端接收。这一般是报表抓取了过多的数据，或者开发在帮忙导大批量数据（很多开发都会有头痛的帮用户抓取数据的情况）。

针对这种情况，就要想办法善后了，尤其在业务系统繁忙的情况下，大量数据抓取极大影响了用户体验。这张图就是帮你开脱的好帮手。

上图脚本如下:

WITH BASE_QUERY

AS (

SELECT CHECKPOINT_DATETIME

,ROW_NUMBER() OVER (

ORDER BY CHECKPOINT_DATETIME

) AS RNK

FROM (

SELECT DISTINCT CHECKPOINT_DATETIME

FROM T_GLOBAL_WAIT_STATS_HISTORY WITH (NOLOCK)

) TMP

)

,CAL_QUERY_CURRENT

AS (

SELECT HIS.*

,BQ.RNK

FROM T_GLOBAL_WAIT_STATS_HISTORY HIS

INNER JOIN BASE_QUERY BQ ON HIS.CHECKPOINT_DATETIME = BQ.CHECKPOINT_DATETIME

)

,CAL_QUERY_PREVIOUS

AS (

SELECT HIS.*

,BQ.RNK

FROM T_GLOBAL_WAIT_STATS_HISTORY HIS

INNER JOIN BASE_QUERY BQ ON HIS.CHECKPOINT_DATETIME = BQ.CHECKPOINT_DATETIME

)

,CAL_QUERY_DETAL

AS (

SELECT CUR.WAIT_TYPE

,CUR.SIGNAL_WAIT_TIME_MS - PRE.SIGNAL_WAIT_TIME_MS AS DELTA

,CUR.CHECKPOINT_DATETIME

,CUR.WAIT_TIME_MS - PRE.WAIT_TIME_MS AS DELTA_WAIT

FROM CAL_QUERY_CURRENT CUR

INNER JOIN CAL_QUERY_PREVIOUS PRE ON CUR.WAIT_TYPE = PRE.WAIT_TYPE

AND CUR.RNK = PRE.RNK + 1

)

SELECT TOP 5000 *

FROM CAL_QUERY_DETAL

WHERE DELTA > 0

ORDER BY CHECKPOINT_DATETIME DESC

除了捕获sys.dm_os_wait_stats 的数据，还可以使用 sql trace, extended events, sql profiler 等手段，同样也在《用好三个 DMV, 检测 80%的性能故障问题》中会着重讲解。

感谢阅读与分享，欢迎关注【有关SQL】公众号