合 SQL Server排查异常慢SQL及性能
Tags： MSSQLSQL Server性能慢SQL性能排查慢查询异常SQL
简介
作为数据库管理员，很多时候会遇到线上堵塞的情况，或者是客户与相关部门同事反馈系统出现等待。虽然整个架构各环节都有可能影响着业务系统的性能，但是他们往往首先把“矛头”指向数据库。那么，这时候你该如何处理呢？
即使很多时候不是数据库的问题，但是在数据库端进行排查，也可以间接发现引起系统慢的原因。比如，网络带宽、磁盘、连接、代码、SQL等各种问题。在问题发生的时刻，线上排查是最容易发现问题根源的。而有的时候，我们可能还没发现问题根源，就用了其他手段先解决了当下的问题，待后续再进行问题溯源。
作为数据库的管理员，我们应该知道如何在线上排查问题，或者在事件过后确认问题，以防止此类事件再次发生。在SQL Server中，大部分的问题都反映在连接和执行的SQL上，如果你知道如何查找这些连接和SQL，你就可以从中判断系统问题了。
线上堵塞如何排查？
- 通过监控系统或告警信息确认数据库系统是否正常运行；
- 通过监控系统或告警信息确认CPU、Mem、IO、带宽是否异常；
- 通过监控系统确认数据库实例的连接数、堵塞/死锁情况、长事务、QPS/TPS、命中率等是否异常；
- 通过数据库系统记录的历史运行数据，确认是否异常；
- 通过数据库错误日志及Windows系统日志是否报错；
以上的排查问题在事发前、中、后的基本处理方案。但是，一个平时稳定运行的系统，通常很少出现异常。除非你对操作系统或数据库实例进行了相关补丁和更改参数。如果仅仅是日常的产品升级、SQL脚本升级，在数据库中几乎都可以通过连接发现其中的问题。
首先了解几个系统DMV，用于查看当前的连接信息。
- sys.dm_exec_connections 记录当前连接到实例的连接协议、网络信息等。
- sys.dm_exec_sessions 记录当前连接到实例的客户端信息、配置信息、操作统计信息等。
- sys.dm_exec_requests 记录当前正在请求的信息，如执行参数、等待信息、资源消耗信息等。
- sys.sysprocesses 记录当前活动连接（包括正在请求）的客户端信息、等待信息、资源消耗信息等。
以上几个DMV，我们可以从中获取到以下的关键信息：
| 关键信息 | dm_exec_connections | dm_exec_sessions | dm_exec_requests | sysprocesses |
|---|---|---|---|---|
| sql_handle | 1 | 0 | 1 | 1 |
| plan_handle | 0 | 0 | 1 | 0 |
| Blocked Session | 0 | 0 | 1 | 1 |
| Status | 0 | 1 | 1 | 1 |
| WaittypeWait Resources | 0 | 0 | 1 | 1 |
| CPU/IO/Men/Rows | 1 | 1 | 1 | 1 |
| Running Time | 1 | 1 | 1 | 1 |
| Client info | 0 | 1 | 0 | 1 |
其中dm_exec_requests与sysprocesses可以确认当前系统正在执行中的连接、该连接处于什么状态、是否被堵塞、堵塞类型及等待资源、执行了多长时间、消耗的资源如何、客户端信息等。这些都是非常重要关键信息，在表中都有相应的字段对应。此外，还可以通过sql_handle与sys.dm_exec_sql_text()查看最近执行的SQL语句。
首先在线查看当前数据库连接的运行情况（如通过sysprocesses查看），重点关注正在运行的连接（kpid>0）、堵塞连接（blocked>0）、未提交的连接（open_tran>0）
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 | -- 当前正在执行的SQL(包括等待的SQL、当前正在堵塞与被堵塞SQL) SELECT spid, blocked blocking, P.dbid, db_name(P.dbid) dbname, (waittime/1000) waittime, lastwaittype, waitresource, open_tran, status, cpu, physical_io, memusage, login_time, last_batch, hostname, [program_name], hostprocess, cmd, nt_domain, nt_username, net_address, net_library, loginame, sql_handle, TEXT , 'kill '+cast(spid as varchar) kill1 FROM master.dbo.sysprocesses P CROSS apply sys.dm_exec_sql_text ( P.sql_handle ) s WHERE P.spid <>@@spid and (P.status !='sleeping' or (P.status='sleeping' and P.spid IN(select blocked from master.dbo.sysprocesses nb where blocked > 0 ))) order by waittime desc GO SELECT req.session_id , req.total_elapsed_time AS duration_ms , req.cpu_time AS cpu_time_ms , req.total_elapsed_time - req.cpu_time AS wait_time , req.logical_reads , SUBSTRING (REPLACE (REPLACE (SUBSTRING (ST.text, (req.statement_start_offset/2) + 1, ((CASE statement_end_offset WHEN -1 THEN DATALENGTH(ST.text) ELSE req.statement_end_offset END - req.statement_start_offset)/2) + 1) , CHAR(10), ' '), CHAR(13), ' '), 1, 512) AS statement_text FROM sys.dm_exec_requests AS req CROSS APPLY sys.dm_exec_sql_text(req.sql_handle) AS ST ORDER BY total_elapsed_time DESC; -- 当前正在执行的SQL select session_id,db_name(dbid) as dbname,transaction_id,wait_type,last_wait_type,wait_resource ,start_time,status,command,estimated_completion_time,cpu_time,logical_reads ,text,open_transaction_count,open_resultset_count,percent_complete from sys.dm_exec_requests r cross apply sys.dm_exec_sql_text(r.sql_handle)s where session_id>50 and session_id<>@@spid go select spid,blocked,db_name(p.dbid),waittime,lastwaittype,waitresource,open_tran,status ,p.dbid,cpu,physical_io,memusage,login_time,last_batch,hostname,[program_name] ,hostprocess,cmd,nt_domain,nt_username,net_address,net_library,loginame,sql_handle,text from master.dbo.sysprocesses p cross apply sys.dm_exec_sql_text(p.sql_handle) s where kpid >0 and p.spid>50 and p.spid<>@@spid go -- 当前正在堵塞与被堵塞SQL select spid,blocked,waittime,lastwaittype,waitresource,open_tran,status ,p.dbid,cpu,physical_io,memusage,login_time,last_batch,hostname,[program_name] ,hostprocess,cmd,nt_domain,nt_username,net_address,net_library,loginame,sql_handle,text from master.dbo.sysprocesses p cross apply sys.dm_exec_sql_text(p.sql_handle) s where blocked >0 or spid in(select sp.blocked from master.dbo.sysprocesses sp where sp.blocked>0) go -- 是否有未提交事务 Select spid,blocked,waittime,waittype,waitresource,db_name(p.dbid) dbname,cpu,physical_io,memusage,open_tran ,status,login_time,last_batch,hostname,program_name,hostprocess,loginame,cmd,text from master.dbo.sysprocesses p cross apply sys.dm_exec_sql_text(p.sql_handle) s where open_tran <> 0 --and last_batch < dateadd(minute,-15,getdate()) go -- 历史 select top 10 * from sys.dm_os_wait_stats d where d.wait_time_ms > 0 order by d.wait_time_ms desc; |
按这几类确认当前连接数是否过多，或在确认线程情况sys.dm_os_threads是否充足。
重点关注status与waittype，可以确定当前连接正在等待什么资源，如网络IO等待ASYNC_NETWORK_IO（说明网络堵塞、或者客户端读取大量数据）、线程等待CXPACKET（说明并发执行SQL）、日志写等待WRITELOG（说明大量数据更改、或者磁盘问题）、线程调度等待SOS_SCHEDULER_YIELD（CPU或线程不足、或是没有索引、任务耗时长等）……waittype类型几百个，从该类型的等待情况，可以间接判断问题发生在哪里。（更多等待事件说明请参考：https://www.sqlskills.com/help/waits/ ）
有哪些异常SQL，如何确认？
在线SQL（正在运行的SQL、堵塞SQL、未提交的SQL）
慢SQL
堵塞SQL
死锁SQL
在线SQL/在线连接：通过上文中的SQL脚本，我们可以查询到正在运行的SQL、堵塞SQL、未提交的SQL，但是只能查询到系统当前时刻正在连接或运行的SQL。通过当前连接情况判断此刻堵塞的原因。线上的SQL如果出现大量堵塞，评估影响情况后，可以把堵塞的SQL连接进行kill回滚。
慢SQL：慢SQL需要跟踪收集才能发现，不可能每次都在线查询SQL去判断，且在线查询不能准确得到慢SQL的资源开销情况。通过扩展事件rpc_completed与sql_batch_completed来记录SQL的运行结果，注意添加筛选条件duration（单位为微妙）。此时慢SQL跟踪的是执行结束的SQL，只有执行结束，才能确认具体开销情况。
堵塞SQL：堵塞SQL也需要跟踪收集才能被记录。通过扩展事件blocked_process_report记录堵塞的事件。记录信息为XML格式。
死锁SQL：系统自动启用的扩展事件system_health可以捕获到死锁，只不过捕获不全且会被循环覆盖。你也可以通过跟踪标志1222或者1204进行捕获，死锁信息则记录到SQL Server 错误日志中，但这并不好筛选。可以通过扩展事件xml_deadlock_report记录死锁事件。记录信息为XML格式。
事后排查方法
我们已经通过线上排查，或者通过SQL跟踪，可以找到异常的连接和异常SQL。那么，如果问题已经结束。我们还能如何确认系统的历史运行情况呢？
