图片 5

《Troubleshooting SQL Server》读书笔记-CPU使用率过高(上)

 

今天我想谈下一个特别的等待类型,这个等待可以说是有时很难进行故障排除:线程池(THREADPOOL)等待。这个等待类型是SQL
Server内部线程调度机制特有的。

第三章 High CPU Utilization.

   
前言: 本文是对SQLSkills上一篇关于SQL
Server中THREADPOOL等待的博客的翻译,本文也不是完全翻译,有些地方适当加入了自己的一些认知。如有翻译不对或不好的地方,敬请指出,大家一起学习进步。尊重原创和翻译劳动成果,转载时请注明出处。谢谢!

或许你已经知道SQL
Server内部使用自有的“操作系统”来实现线程调度和内存管理——SQLOS。SQLOS提供一系列的工作者线程,用来执行提交给SQL
Server的查询。这问题就是这些工作者线程有时被耗尽——可能因为锁/阻塞(Locking/Blocking)等情况。在这个情况下,SQL
Server在引擎内部不能执行更多的请求,因为没有空闲的工作线程可用。

CPU使用率过高问题很容易被发现,但是诊断却不是很容易。CPU使用过高很多时候会成为其它问题的替罪羊,所以在确认和故障诊断时要抽丝剥茧。

 

你可以通过max worker threads选项(通过sp_configure)来配置SQLOS可用工作线程数。默认情况这个选项的值为0,这就是说SQL
Server自身可以决定可以使用的工作者线程数。可用工作者线程数取决于CPU架构(x32,x64)和你有的可用CPU数。MSDN在线帮助提供下列不同组合情况的可用工作线程数:

调查CPU压力

英文原文地址:

CPU数    32位    64位

三个主要的工具:性能监视器,SQLTrace,DMV.

 

小于等于4个  256    512

     性能监视器:首先用它来确认是SQL
Server还是其它进程使用了过多的CPU。主要计数器有:

 

8个      288    576

                     Processor/ %Privileged Time
:在特权模式下进程线程执行代码所花时间的百分比。基本可以认为是Windows核心使用的CPU
                     Processor/ %User Time
:处理器处于用户模式的时间百分比。应用程序的使用的CPU。
                     Process (sqlservr.exe)/ %Processor Time
:SQLServer.exe线程使用处理器执行指令所花的时间百分比。

翻译原文地址:

16个     
352    704

                     还有一些与SQL Server相关CPU消耗的计数器:

 

32个     
480    960

                     SQLServer:SQL Statistics/Auto-Param Attempts/sec
                     SQLServer:SQL Statistics/Failed Auto-params/sec
                     SQLServer:SQL Statistics/Batch Requests/sec
                     SQLServer:SQL Statistics/SQL Compilations/sec
                     SQLServer:SQL Statistics/SQL Re-Compilations/sec
                     SQLServer:Plan Cache/Cache hit Ratio

 

你也可以通过sys.dm_os_sys_info里的max_workers_count列来检查你的SQL
Server实例使用的工作线程数。

       SQLTrace:
通过Profiler生成SQLTrace脚本,进行服务器端跟踪,来获得高CPU使用时详细信息。

 

1 SELECT max_workers_count  FROM  sys.dm_os_sys_info

              DMV:a. 使用sys.dm_os_wait_stats来得到signal
wait,确认CPU压力的程度.

等待事件描述:

图片 1

                       b.
使用sys.dm_os_wait_stats和sys.dm_os_schedulers观察等待类型

 

用下面的例子,我想演示SQL
Server里如何获得线程耗尽(thread starvation),还有你怎么解决它。

                       c.
使用sys.dm_exec_query_stats和sys.dm_exec_sql_text找出高CPU使用的执行计划和对应的查询

这个等待类型出现是因为服务器的线程池(Thread
Pool)没有可用的线程,它可能导致登录失败或SQL语句无法正常运行。

警告:请不要在生产系统里执行下列操作!!!

                       d.
使用sys.dm_os_waiting_tasks观察当前与CPU使用相关等待类型

 

首先我们创建一个数据库并建立一个简单表作为我们样例情景。我想尽可能的特例,因此表名和列名都是特别的。

                       e.
使用sys.dm_exec_requests正在执行的查询的资源使用状况

(联机丛书描述:“当任务在等待工作线程(worker
thread)运行时出现这个等待事件。这可能表明数据库参数max worker
threads的值设置过低, 或者批处理执行时间过长,
从而减少了可用于满足其它批处理的工作线程(worker
thread)数量。(举个生活当中的例子,当你去饭店吃饭,工作线程好比餐厅的服务员,例如服务员过少或某些顾客占用服务员的时间过长,那么就会出现很多顾客郁闷地长时间等待服务的现象)

 1 USE master
 2 GO
 3  
 4 CREATE DATABASE ThreadPoolWaits
 5 GO
 6  
 7 USE ThreadPoolWaits
 8 GO
 9  
10 -- Create a new test table (this one will be unique on earth – hopefully…)
11 CREATE TABLE [SomeCrazyUniqueTableName_6EFF088F-443B-4EBC-A4C7-9FC146D2EE49]
12 (
13     [MyUniqueColumnName1_F67DAC4A-C202-49BB-829A-071130BF1160] INT IDENTITY(1, 1) NOT NULL PRIMARY KEY,
14     [MyUniqueColumnName2_438B7184-B476-48A4-B5FA-DC34B99FA0A4] INT
15 )
16 GO
17  
18 -- Insert a record
19 INSERT INTO [SomeCrazyUniqueTableName_6EFF088F-443B-4EBC-A4C7-9FC146D2EE49]
20 VALUES (1)
21 GO

 

 

从刚才的代码里我们可以看到,我们的表定义非常简单。下一步我会创建一个新的存储过程,里面封装了一些读操作。

调查CPU相关的等待统计:请求执行前,包含请求的会话必需等待,SQL
Server会记录等待原因和时间。通过sys.dm_os_wait_stats查询这些信息。

Questions/comments
on this wait type?

Click here to send Paul an
email, especially if you have any information to add to this
topic.

1 -- Create a stored procedure that encapsulates a read workload
2 CREATE
3 PROCEDURE MyCustomUniqueStoredProcedureName_ReadWorkload
4 AS
5 BEGIN
6     SELECT * FROM [SomeCrazyUniqueTableName_6EFF088F-443B-4EBC-A4C7-9FC146D2EE49]
7 END
8 GO

     信号等待时间(Signal wait
time):sys.dm_os_wait_stats的wait_time_ms表示等待类型的总共等待时间,signal_wait_time_ms表示线程收到段义和到重新执行间的等待时间,

 

最后我们开始一个新的事务,对刚才创建的表进行一个更新,但从不提交那个事务:

                                              
这些时间主要花在runnable队列里,是纯CPU等待。

Added
in SQL Server version:

1 -- Begin a transaction that never commits…
2 BEGIN TRANSACTION
3     UPDATE [SomeCrazyUniqueTableName_6EFF088F-443B-4EBC-A4C7-9FC146D2EE49] WITH (TABLOCKX)
4         SET [MyUniqueColumnName2_438B7184-B476-48A4-B5FA-DC34B99FA0A4] = 2
5 GO

    
通过以下查询得到信号等待的时间比率:

Pre-2005/2005

至此,在你的SQL
Server实例里有了个挂起的事务,因为TABLOCKX查询提示,它有排它表锁(exclusive
table
lock)。当你从不同的会话(新建查询)执行刚才创建的存储过程时,这个存储过程会等待,因为它对读取的记录需要获取共享锁(Shared
lock)。

SELECT  SUM (signal_wait_time_ms) AS TotalSignalWaitTime , 
         ( SUM (CAST(signal_wait_time_ms  AS NUMERIC(20, 2)))  
           / SUM (CAST(wait_time_ms AS NUMERIC(20, 2)))  * 100  ) 
                         AS PercentageSignalWaitsOfTotalTime 
FROM    sys .dm_os_wait_stats

 

1 EXEC MyCustomUniqueStoredProcedureName_ReadWorkload
2 GO

     也可以查询各类资源等待的比率,下面是等待top 10:

Removed
in SQL Server version:

你也可以通过DMV sys.dm_db_tran_locks来检查这个锁/阻塞(Locking/Blocking)情况,它会展示你一个等待请求:

SELECT TOP ( 10 ) 
        wait_type , 
        waiting_tasks_count , 
         ( wait_time_ms - signal_wait_time_ms ) AS resource_wait_time  , 
        max_wait_time_ms , 
         CASE waiting_tasks_count  
           WHEN 0  THEN 0 
           ELSE wait_time_ms / waiting_tasks_count  
         END  AS avg_wait_time 
FROM    sys .dm_os_wait_stats 
WHERE    wait_type NOT  LIKE '%SLEEP%'    -- remove eg. SLEEP_TASK and 
                                        -- LAZYWRITER_SLEEP waits 
         AND  wait_type NOT  LIKE 'XE%'  
         AND  wait_type NOT  IN -- remove system waits    
( 'KSOURCE_WAKEUP', 'BROKER_TASK_STOP', 'FT_IFTS_SCHEDULER_IDLE_WAIT' , 
  'SQLTRACE_BUFFER_FLUSH', 'CLR_AUTO_EVENT', 'BROKER_EVENTHANDLER', 
  'BAD_PAGE_PROCESS', 'BROKER_TRANSMITTER' , 'CHECKPOINT_QUEUE', 
  'DBMIRROR_EVENTS_QUEUE', 'SQLTRACE_BUFFER_FLUSH', 'CLR_MANUAL_EVENT', 
  'ONDEMAND_TASK_QUEUE', 'REQUEST_FOR_DEADLOCK_SEARCH' , 'LOGMGR_QUEUE', 
  'BROKER_RECEIVE_WAITFOR' , 'PREEMPTIVE_OS_GETPROCADDRESS', 
  'PREEMPTIVE_OS_AUTHENTICATIONOPS', 'BROKER_TO_FLUSH'  ) 
ORDER  BY wait_time_ms DESC 

N/A

1 SELECT
2     resource_associated_entity_id,
3     request_mode,
4     request_status,
5     request_session_id
6 FROM sys.dm_tran_locks
7 WHERE resource_database_id = DB_ID('ThreadPoolWaits') AND resource_type = 'OBJECT'
8 GO

与CPU相关的等待类型主要有SOS_SCHEDULER_YIELD,CXPACKET和CMEMTHREAD

 

图片 2

    SOS_SCHEDULER_YIELD: SQL
Server计划程序是协同的多任务计划程序。查询占用一小段时间的CPU后自发地让出CPU给后面的查询,

 

在这个简单情况下,在SQL
Server里只有一个等待查询,没啥特别发生。当你使用大量查询,大于可用最大工作线程数时,SQL
Server会作如何反应呢?我们来试下。我用ostress.exe来完成这个任务,它是微软免费提供的RML工具的一部分。在我的配置(32位系统,4个CPU)SQL
Server内部使用256个工作者线程。因为我通过下列的命令行,用ostress.exe模拟300个同时发生连接给SQL
Server(RML Utilities for SQL Server->RML Cmd
Prompt,请确认当前windows登录帐号可以正常访问当前新建的ThreadPoolWaits数据库):

                                     
并且回到可运行队列等待重新被运行,这种等待就是SOS_SCHEDULER_YIELD。

扩展事件wait_type的值:

ostress.exe -Q"EXEC ThreadPoolWaits.dbo.MyCustomUniqueStoredProcedureName_ReadWorkload" -n300

                                     
如果此等待时间在sys.dm_exec_requests或者sys.dm_os_waiting_tasks过多,则表示有高CPU使用的查询需要优化或者需要增加CPU。

 

图片 3

   
CXPACKET:多处理器运行并行查询时,当同步多个线程间的查询处理器交换迭代器时出现。

这个等待类型在sys.dm_xe_map_vlaues中对应的扩展事件为SOS_WORKER  (感谢乔纳森的博客
Mapping wait types in dm_os_wait_stats to Extended
Events)。

当你执行这个命令提示后,需要花费几秒时间,ostress.exe才会创建300个工作者线程,并没有什么特别发生,目前看起来都一切正常。

   
CMEMTHREAD:等待同步内存对象。有些内存对象是不请允许并发访问的,当多个线程试图访问此内存对象时,就会等待。

 

图片 4

   调查计划程序队列(scheduler
queues)
:scheduler_id<255的是隐藏的系统计划程序,如DAC,备份等。

sys.dm_xe_map_values中的map_key值在SQL
Server 2008和 SQL Server 2008 R2 中为113, 在SQL Server 2012和 2014
RTM中值为117。在 SQL Server 2014 RTM 之后,
您必须检查DMV视图获得它的最新的值, 因为一些map_keyvalues
的值在后续的版本中改变了。

我们现在来分析下这个情况,通过SSMS新建一个查询连接。我滴神呀,连接不上了:

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

 

图片 5

     
current_task_count表示每个计划程序上的任务数,runnable_task_count表示runnable队列中等待CPU的任务。

 

SQL
Server没响应了!!!或者说已经挂掉!!!这就对了,因为现在我们已经耗尽了最大可用工作者线程。所有提交给SQL
Server的请求当前都在等待一个共享锁(LCK_M_S等待),而且所有其他的工作线程不能加入SQL
Server内部队列,因为已经没有可用工作者线程了(THREADPOOL等待)。但是我们现在如何解决这个问题?重启SQL
Server一直不是个好选择…….