线程池等待故障排除

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

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

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

CPU数    32位    64位

小于等于4个  256    512

8个      288    576

16个      352    704

32个      480    960

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

1 SELECT max_workers_count  FROM  sys.dm_os_sys_info

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

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

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

 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

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

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

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

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

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

1 EXEC MyCustomUniqueStoredProcedureName_ReadWorkload
2 GO

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

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

在这个简单情况下,在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数据库):

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

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

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

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

幸运的是,自SQL Server 2005开始提供了数据库管理员专用连接(Dedicated Admin Connection) (DAC)。你可以使用这个连接登录到SQL Server,即使当工作者线程耗尽或内存压力太大,因为在SQLOS内部DAC有它自己特有的

  • 调度(Scheduler)
  • 内存节点(Memory Node)
  • TCP端口

因此SQL Server能接受并提供服务给DAC连接——即使像现在这个高度复杂的故障排除情况。但必须注意,对于整个SQL Server实例,只有1个可用的DAC连接。当你想通过DAC连接时,你必须使用下列语法:admin:<servername> ,这里<servername>就是你SQL Server实例名称。因为让我们启动新的SSMS实例,通过DAC登录到SQL Server。请注意,你不是通过DAC连接到对象浏览器(Object Explorer)。通过DAC连接只能使用简单的查询窗口:

当你通过DAC成功连接后,你就能运行你的诊断查询。你必须知道:DAC不支持自动完成(智能提示),因为自动完成在背后使用它特有的连接——因此你要知道想用来故障排除的DMV。第1步我们可以检查下sys.dm_exec_requests,看看在SQL Server里当前等待的请求:

 1 SELECT
 2     r.command,
 3     r.sql_handle,
 4     r.plan_handle,
 5     r.wait_type,
 6     r.wait_resource,
 7     r.wait_time,
 8     r.session_id,
 9     r.blocking_session_id
10 FROM sys.dm_exec_requests r INNER JOIN sys.dm_exec_sessions s ON r.session_id = s.session_id
11 WHERE s.is_user_process = 1
12 GO

在我的配置里,这个查询返回我237行,这就是说237个用户的请求(WHERE s.is_user_process = 1)在SQL Server里,当前在等待。但我们同时用300个连接的用户启动我们的存储过程。sys.dm_exec_requests向你展示的只是那些在SQL Server内部潜在的工作者线程,因为这些请求当前正在SQL Server内部执行。但其他的呢?那些其他的挂起的请求通过sys.dm_os_waiting_tasks可以看到——它们都有THREADPOOL的等待:

1 SELECT * FROM sys.dm_os_waiting_tasks
2 WHERE wait_type = 'THREADPOOL'
3 GO

它们正在等待一个新的工作线程从工作池里释放。但在我们的情况里,每个线程当前都暂停并束缚于用户请求,因此这些请求会永远等下去!你会看到THREADPOOL只在sys.dm_os_waiting_tasks里,从不在sys.dm_exec_requests里,因为在sys.dm_exec_requests里的请求已经束缚于SQL Server里的工作者线程。当你看sys.dm_exec_requests的输出结果,在记录集的最后你会看到 session_id 列和blocking_session_id列。这2列向你展示了SQL Server内部的阻塞链(blocking chain):

 1 SELECT
 2     r.command,
 3     r.sql_handle,
 4     r.plan_handle,
 5     r.wait_type,
 6     r.wait_resource,
 7     r.wait_time,
 8     r.session_id,
 9     r.blocking_session_id
10 FROM sys.dm_exec_requests r INNER JOIN sys.dm_exec_sessions s ON r.session_id = s.session_id
11 WHERE s.is_user_process = 1

可以看到,几乎每个会话都有一个59的blocking_session_id,而且session_id59有一个53的blocking_session_idsession_id53就是我们阻塞头(head blocker)!让我们进一步分析下阻塞头(head blocker)会话53:

 1 -- Analyze the head blocker session
 2 SELECT
 3     login_time,
 4     [host_name],
 5     [program_name],
 6     login_name
 7 FROM sys.dm_exec_sessions
 8 WHERE session_id = 53
 9 GO
10  
11 -- Analyze the head blocker connection
12 SELECT
13     connect_time,
14     client_tcp_port,
15     most_recent_sql_handle
16 FROM sys.dm_exec_connections
17 WHERE session_id = 53
18 GO

 这里最有意思的列,是来自sys.dm_exec_connectionsmost_recent_sql_handle列,这里我们可以获得执行的SQL语句。

但你使用DMF sys.dm_exec_sql_text传入most_recent_sql_handle列值时,你就可以拿到执行的SQL语句:

1 SELECT text FROM  sys.dm_exec_sql_text(0x01001400B883BC05A8831D06000000000000000000000000)
2 GO

我们把语句复制出来看看:

BEGIN TRANSACTION   UPDATE [SomeCrazyUniqueTableName_6EFF088F-443B-4EBC-A4C7-9FC146D2EE49] WITH (TABLOCKX)    SET [MyUniqueColumnName2_438B7184-B476-48A4-B5FA-DC34B99FA0A4] = 2 

这不就是我们最先的查询么?我们把事务打开,但一直没提交。现在我们跟踪到了有问题的查询,它导致了THREADPOOLLCK_M_S等待,最后可以通过DAC的把这个会话杀掉:

1 KILL 53
2 GO

这个会话杀掉的话要花几秒钟,最后你的阻塞情况也消失了。现在你的SQL Server又能接受新的连接,可以正常工作了。当你通过DAC连接解决完问题后,不要忘记关闭这个连接,因为在SQL Server实例里只有1个可用DAC连接。然后当你查看SQL Server错误日志时,你可以看到类似下列的信息:
(管理->SQL Server 日志->存档编号1)

看不懂,没关系,俺们再到Windows日志里看看:

这也象征着在你SQL Server实例内部工作者线程耗尽。这个情况的副作用也导致所谓的调度死锁(Deadlocked Schedulers) 。当SQL Server遇到调度死锁,SQL Server会在你的日志目录写入堆栈转储(Deadlocked Schedulers)

有时我会看见在SQL Server内部盲目重新配置max worker threads设置,因为他们认为服务器的工作量需要更多的工作者线程。但是SQL Server里的每个问题,都有导致问题的根本原因,就如你刚才看到的一样。刚才情况的根源是一个未提交的事务,导致阻塞情况,引起线程耗尽,最后导致SQL Server无响应。从这个解释你可以发现,在你找到根源前都有很长的问题链——在你下次处理故障排除时,记住这个。

对你的操作,造成服务器几乎当机,别放在心上,因为俺们只是演习,不是在生产系统。重要的是我们学会了如何处理这个问题。请继续关注!

参考文章:

https://www.sqlpassion.at/archive/2011/10/25/troubleshooting-threadpool-waits/

posted @ 2015-06-19 21:54  Woodytu  阅读(3093)  评论(4编辑  收藏  举报