一条语句导致CPU持续100%

Posted 2020-09-22 醒嘞

一大早收到一堆CPU预警邮件，通常每天只在统计作业执行期间会收到2~3封CPU预警邮件。这次的预警来自另一台服务器，并且明细数据显示其CPU一直维持在49%。

登录到服务器，查看任务管理器(查看资源监视器更好)，CPU时不时上涨到100%，CPU被谁使用了呢？虽然猜测到是被SQLServer，还是打开性能监视器添加\\Processor(_Total)\\% Processor Time、Process(sqlservr)\\% Processor Time计数器


可以看到CPU使用率持续98%时，SQLServer占用CPU持续约为1575%，服务器有16个logical cores，平均值为1575%/16=98.44%，也就是CPU繁忙基本是由SQLServer引起。
那么就用profiler把高消耗语句拎出来(此时猜测可能是频繁执行某一高消耗的语句)，列筛选设置CPU>=100毫秒，等了十来秒没看到任何语句，不断地更改筛选条件，
终于看到一条异常语句，语句每1分钟执行一次，每次执行时长约30秒，执行期间服务器CPU接近100%！

--问题语句
SELECT TOP 100 T1.guid,
       T1.UserID,
       T1.UserChairID,
       T1.UserTreasure,
       T1.FirstRound,
       T1.SecondRound,
       T1.ThreeRound,
       T1.MachineSerial,
       T1.LoginIP,
       T1.RecordTime,
       T1.ServerID,
       T2.UserID         AS JSID,
       T2.UserChairID    AS JSChairID,
       T2.UserTreasure   AS JSUserTreasure,
       T2.FirstRound     AS JSFirstRound,
       T2.SecondRound    AS JSSecondRound,
       T2.ThreeRound     AS JSThreeRound,
       T2.MachineSerial  AS JSMachineSerial,
       T2.LoginIP        AS JSLoginIP
FROM   dbo.XxxxRecordDetail AS T1 WITH(NOLOCK)
       LEFT JOIN dbo.XxxxRecordDetail AS T2 WITH(NOLOCK)
            ON  T1.Guid = T2.Guid
            AND T1.UserID != T2.UserID
WHERE  T1.PeopleNum = 2
       AND T2.PeopleNum = 2
       AND T1.UserTreasure < 0
       AND T1.RecordTime >= \'2017-5-10 8:36:36\'
       AND T1.RecordTime < \'2017-5-10 13:36:36\'
ORDER BY
       T1.RecordTime ASC

View Code

由于语句执行期间CPU过高，因此没必要再次执行语句来查看执行计划。直接从计划缓存查找

--参考 http://www.cnblogs.com/Uest/p/6419017.html 计划缓存
--特定语句聚合性能统计µs
select top 100 SUBSTRING (c.text,(b.statement_start_offset/2) + 1
      ,((CASE WHEN b.statement_end_offset = -1 THEN LEN(CONVERT(NVARCHAR(MAX), c.text)) * 2 
       ELSE b.statement_end_offset END - b.statement_start_offset)/2) + 1) RunSQL
      ,b.creation_time --编译计划的时间
      ,b.last_execution_time --上次开始执行计划的时间
      ,b.execution_count AS SQLExCount--计划自上次编译以来所执行的次数
      ,b.last_logical_reads --上次执行计划时所执行的逻辑读取次数
      ,b.total_logical_reads/b.execution_count avg_logical_reads
      ,b.last_worker_time --上次执行计划所用的 CPU 时间(微秒)
      ,b.last_elapsed_time --最近一次完成执行此计划所用的时间(微秒)
      ,b.total_elapsed_time/b.execution_count avg_elapsed_time --上次完成执行此计划所用的总时间
      --,b.sql_handle,b.plan_handle
      ,d.query_plan
      ,c.text
FROM sys.dm_exec_query_stats b with(nolock)
CROSS APPLY sys.dm_exec_sql_text(b.sql_handle) c
CROSS APPLY sys.dm_exec_query_plan(b.plan_handle) d
where c.text like \'%KeyWords%\'

View Code

语句对应执行计划

可以看到消耗花费在聚集索引扫描，语句T2用了条件peoplenum=2进行扫描~
分析语句业务逻辑，其实就是返回Xx游戏2人局各场明细信息。T1能快速返回满足where条件的记录，何不用这些记录到T2中查找。通过指定索引，指引语句按照我们的期望的方式去执行。优化前、后跟踪对比

优化前、后性能计数器对比

可以看到修改后CPU立马降下去。在文章的开头收到的预警邮件显示最高CPU使用率为49%，但实际在某些时候达到98%+。难道sys.dm_os_ring_buffers记录数据时CPU刚好回落●-●