SQLServer中使用擴展事件獲取Session級別的等待信息以及SQLServer 2016中Session級別等待信息的增強
本文出處：http://www.cnblogs.com/wy123/p/6835939.html
什麽是等待
簡單說明一下什麽是等待：
當應用程序對SQL Server發起一個Session請求的時候，這個Session請求在數據庫中執行的過程中會申請其所需要的資源，
比如可能會申請內存資源，表上的鎖資源，物理IO資源，網絡資源等等，
如果當前Session運行過程中需要申請的某些資源無法立即得到滿足，就會產生等待。
SQL Server會以不用的方式來展現這個等待信息，比活動Session的等待信息，實例級的等待信息等等。
SQL Server中，等待事件是作為DBA進行TroubleShooting的重要參考信息之一，SQL Server中可以通過多中方式來獲取等待信息。
但是對於SQL Server 2016之前的版本來說，不管是活動Session級別的等待和實例級的等待，參考意義都有限，
更多的時候是想要更加詳細的且可以事後分析的等待，這就需要收集那些曾經已執行過的Session產生的等待信息，也就是特定Session等待信息的歷史記錄
本文重點介紹使用擴展事件來捕獲等待信息，但不介紹擴展事件本身的使用，重點放在如何使用擴展事件來獲取想要的等待事件信息。
需要對擴展事件有一定的了解。
等待信息的獲取途徑
在SQL Server中有一個系統視圖sys.dm_os_wait_stats記錄了自數據庫服務啟動以來累積產生的等待信息，
如下圖，這個結果是實例級的，也就是記錄的整個數據庫服務器所有的等待事件的累積。
但是到了第二天或者什麽時候，網絡變好了，但是sys.dm_os_wait_stats中記錄的ASYNC_NETWORK_IO等待信息是不變的
也就是說sys.dm_os_wait_stats無法反映實時等待情況。
當然要獲取實時的等待信息也簡單，記錄兩個時間點之間sys.dm_os_wait_stats中等待時間的差值，可以間接地反映出來某一段時間的數據的等待信息。
但是這個信息仍然比較粗略，依舊是實例級的，某些時候依舊是不足夠作為參考的。
另外一個是通過sys.dm_exec_requests這個系統視圖的wait_type，wait_time等獲取活動Session的等待信息
如截圖，但是這個是活動Session的信息，當Session完成之後，它的等待信息就看不到曾經都產生了那些等待，分別是多久。
也就說，你無法追溯歷史上某一個Session或者某一個SQL（存儲過程）執行過程中的都產生了什麽類型的等待，等待了多長時間。
實話說，不管是sys.dm_os_wait_stats還是sys.dm_exec_requests，在正常情況下，獲取到的等待信息實用價值都是不高或者是適用場景有限。
更多的時候我們是想要更細一級的等待，比如某一個Login、某一部分Session、甚至某些特定的SQL（存儲過程）的執行過程中產生的等待信息。
舉個實際例子，數據庫又10個Login給10個不同的應用程序訪問，其中只有1個應用程序端反饋說訪問數據庫慢，或者有性能問題，其他Login都反饋正常
那麽很有可能是這個Login請求自己的問題，此時就需要針對這一個Login的情況進行針對性分析，而不是在實例級分析診斷。
如果能夠拿到這個Login執行的Session的等待情況，或者這個Login某些特定的數據庫對象的執行過程中的等待信息，對定位問題的針對性的就比較強了。
本文就以此為切入點，針對如何獲取Session級別的等待信息展開說明和演示。
SQL Server 2016中獲取Session級別的等待信息
在SQL Server 2016中，獲取Session級別的等待信息是比較方便的，有直接的系統視圖sys.dm_exec_session_wait_stats可以使用
當前情況下，想要知道某一個Session的等待信息就很簡單了，
在sql語句開始的時候把當前Session的等待信息記錄下來
在sql語句結束的時候把當前Session的等待信息再次記錄出來
計算兩次等待信息的差值，就可以知道當前Session運行的過程中有哪些等待，分別是多少。
sqlserver開發團隊可能也意識到了對於等待信息，更多的時候，需要的是較為具體的等待，而不是一個籠統的實例級的等待
因此在SQL Server 2016中增加了sys.dm_exec_session_wait_stats這個支持統計Session級別的等待的視圖
很不幸的SQL Server2016之前的版本中是沒有這個系統視圖可以很方便地記錄Session級別的等待。
但是可以借助擴展事件來實現類似的功能。
使用擴展事件來捕獲Session級別的等待信息
因為這裏是是用擴展事件來實現的，這裏要求讀者要對擴展事件有一個基本的認識，擴展事件本身就不多說了。
上代碼，啟動一個擴展事件，來記錄執行時間超過三秒的SQL語句，其執行過程中等待時間大於0的等待事件信息。
當然這個捕獲的信息可以加上各種過濾條件。具體參考代碼備註。
IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name=‘CollectionSessionWaitStats‘) DROP EVENT session CollectionSessionWaitStats ON SERVER; GO -- 創建事件會話 CREATE EVENT SESSION CollectionSessionWaitStats ON SERVER ADD EVENT sqlserver.rpc_completed ( ACTION ( sqlos.task_time, sqlserver.database_name, sqlserver.nt_username, sqlserver.username, sqlserver.sql_text, sqlserver.session_id, sqlserver.transaction_id ) WHERE [duration]>=3000000 ), ADD EVENT sqlserver.sql_batch_completed ( ACTION ( sqlos.task_time, sqlserver.database_name, sqlserver.nt_username, sqlserver.username, sqlserver.sql_text, sqlserver.session_id, sqlserver.transaction_id ) WHERE [duration]>=3000000 ), ADD EVENT sqlos.wait_info ( ACTION ( sqlos.task_time, sqlserver.database_name, sqlserver.nt_username, sqlserver.sql_text, sqlserver.username, sqlserver.session_id, sqlserver.transaction_id ) WHERE session_id>50 and opcode=1 and duration>0 and sql_text not like ‘%sp_MScdc_capture_job%‘ --排除某些信息 --and username = ‘‘ --限定只記錄某些信息 ), ADD EVENT sqlos.wait_info_external ( ACTION ( sqlos.task_time, sqlserver.database_name, sqlserver.nt_username, sqlserver.username, sqlserver.sql_text, sqlserver.session_id, sqlserver.transaction_id ) WHERE session_id>50 and opcode=1 and duration>0 and sql_text not like ‘%sp_MScdc_capture_job%‘ --and username = ‘‘ ) ADD TARGET package0.event_file ( SET filename=N‘D:\XEventFiles\CollectionSessionWaitStats‘, max_file_size=(1024), max_rollover_files=(10) ) WITH ( MAX_MEMORY=4096 KB, EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS, MAX_DISPATCH_LATENCY=30 SECONDS, MAX_EVENT_SIZE=0 KB, MEMORY_PARTITION_MODE=NONE, TRACK_CAUSALITY=OFF, STARTUP_STATE=ON ) GO -- 啟用（停止）事件會話（START / STOP） ALTER EVENT SESSION CollectionSessionWaitStats ON SERVER STATE=START GO
是用擴展事件收集的Session級別的等待信息有以下幾個特點
1，SessionId是可以重復的
舉例說明就是:比如一個SessionId = 80的Session，可以第一次執行一個SQLA，第二次執行一個SQLB.
同時這兩個SQL的執行與其執行過程中產生的等待信息都可以被捕獲出來
2，同一個時間段內，一個同一個SessionId不可能同時執行，
比如16：46：36秒到16：46：46秒到這個時間內，SessionId = 80的Session正在執行，擴展事件捕獲到了其產生的等待信息
但是在16：46：36秒到16：46：46這個時間段內，不可能有另外一個SessionId = 80也在執行，這個邏輯不難理解
為什麽要特意說明這個問題？
因為擴展事件收集到的事件信息中SQL語句完成事件（rpc_completed或者sql_batch_completed）與產生的等待之間，沒有一個直接的對應關系。
怎麽理解？動起手來才能發現問題，我是這個糾結了大半天，截圖示例。
如下截圖，擴展事件捕獲到的兩個目標事件的SessionId都是58，但是執行的SQL是不一樣的，
如下截圖是不區分事件類型，捕獲到的所有的事件信息。
也就是上面說的，對於58號Session:
第一次運行了SELECT COUNT(1) FROM TestCollectionSessionWaitStats
第二次運行了SELECT COUNT(1) FROM TestCollectionSessionWaitStats WHERE Id>10
兩次運行的SQL一致或者不一致問題不大，關鍵是捕獲到的等待事件信心的SessionId也是58，怎麽區分產生的事件是歸屬於哪一次的運行？
比如58號Session運行兩次sql，產生了10條等待信息，怎麽區分這10條等待信息哪些歸屬於第一次運行生成的，哪些歸屬於第二次運行生成的？
這個就依靠上面說的第二點“同一個時間段內，一個同一個SessionId不可能同時執行”
對於同一個SessionId，在sql_batch_completed事件中，從時間的維度來看
小於第一次sql_batch_completed事件完成時間的必然是58號Session第一次執行生成的
大於第一次sql_batch_completed事件完成事件的且小於第二次sql_batch_completed的必然是58號Session第二次執行生成的
有了這個理論基礎，我們統計Session級別的等待就比較容易了，相信這個邏輯的實現並不難。
如下圖是58號Session執行某SQL語句產生的等待詳細信息，可以看到多次產生了CXPACKET和 PAGEIOLATCH_SH等待
鑒於截圖問題，下面還有另外一個同樣是58號Session的執行另外一個SQL捕獲到的等待信息
這個統計辦法就是上面提到的，在兩次sql_batch_completed事件中，雖然等待事件的SessionId一樣，
但是其發生的時候是處於當前事件的sql_batch_completed之前，上一次sql_batch_completed之後，
這樣就可以完美地匹配到sql_batch_completed事件與其對應的wait_info事件。
在這種情況下，統計得到類似於SQL Server 2016中的sys.dm_os_wait_stats的結果也就不難了。
與sys.dm_os_wait_stats 等待信息的結果相比，上述通過擴展事件獲取的等待信息，是不是更加詳細和具體？
比如對於CXPACKET等待時間，
不難發現，如果計算計算其產生的次數（count），就類似於sys.dm_os_wait_stats 中的waiting_tasks_count，計算其產生的總時間（sum），就類似於wait_time_ms
但是上述時間的信息已經細化到Session級別了，比sys.dm_os_wait_stats 中的等待信息更有參考價值。
對於問題的診斷和分析，也會是更加有效。
上述統計結果的SQL語句
-- Parse the XML to show rpc_completed,sql_batch_completed details if object_id(‘tempdb..#t1‘) is not null drop table #t1 SELECT event_xml.value(‘(./action[@name="session_id"]/value)[1]‘, ‘INT‘) as session_id, event_xml.value(‘(.[email protected])‘, ‘varchar(1000)‘) as timestamp, event_xml.value(‘(./data[@name="statement"]/value)[1]‘, ‘varchar(max)‘) as statement, event_xml.value(‘(./data[@name="batch_text"]/value)[1]‘, ‘varchar(max)‘) as batch_text, event_xml.value(‘(.[email protected])‘, ‘varchar(1000)‘) as Event_Name, event_xml.value(‘(./data[@name="duration"]/value)[1]‘, ‘bigint‘) as Duration, event_xml.value(‘(./data[@name="cpu_time"]/value)[1]‘, ‘bigint‘) as cpu_time, event_xml.value(‘(./data[@name="physical_reads"]/value)[1]‘, ‘bigint‘) as physical_reads, event_xml.value(‘(./data[@name="logical_reads"]/value)[1]‘, ‘bigint‘) as logical_reads, event_xml.value(‘(./action[@name="username"]/value)[1]‘, ‘varchar(max)‘) as username INTO #t1 FROM ( SELECT CAST(event_data AS XML) xml_event_data FROM sys.fn_xe_file_target_read_file(N‘D:\XEventFiles\CollectionSessionWaitStats*‘, NULL, NULL, NULL) ) AS event_table CROSS APPLY xml_event_data.nodes(‘//event‘) n (event_xml) WHERE event_xml.value(‘(.[email protected])‘, ‘varchar(1000)‘) in (‘rpc_completed‘,‘sql_batch_completed‘) order by Event_Name -- Parse the XML to show wait_info,wait_info_external details if object_id(‘tempdb..#t2‘) is not null drop table #t2 SELECT cast(event_xml.value(‘(.[email protected])‘, ‘varchar(1000)‘) as DATETIME2) as timestamp, event_xml.value(‘(./data[@name="duration"]/value)[1]‘, ‘bigint‘) as duration, event_xml.value(‘(./action[@name="session_id"]/value)[1]‘, ‘INT‘) as session_id, event_xml.value(‘(./data[@name="wait_type"]/text)[1]‘, ‘VARCHAR(200)‘) as wait_type INTO #t2 FROM ( SELECT CAST(event_data AS XML) xml_event_data FROM sys.fn_xe_file_target_read_file(N‘D:\XEventFiles\CollectionSessionWaitStats*‘, NULL, NULL, NULL) ) AS event_table CROSS APPLY xml_event_data.nodes(‘//event‘) n (event_xml) WHERE event_xml.value(‘(.[email protected])‘, ‘varchar(1000)‘) in (‘wait_info‘,‘wait_info_external‘) if object_id(‘tempdb..#t3‘) is not null drop table #t3 SELECT a.session_id AS SessionId, isnull(statement,batch_text) AS SQLTEXT, a.Duration AS TotalExecuteTime, CAST(a.timestamp AS DATETIME2) AS CompletedTime, CAST(b.timestamp AS DATETIME2) AS WaitTypeStartTime, b.wait_type AS WaitType, b.duration AS WaitDuration INTO #t3 FROM #t1 a INNER JOIN #t2 b on a.session_id = b.session_id and b.timestamp < a.timestamp and b.timestamp>( select top 1 timestamp from #t1 c where a.session_id = a.session_id and a.timestamp > b.timestamp order by a.timestamp ) select case when rn = 1 then SessionId else NULL end as SessionId, case when rn = 1 then SQLTEXT else NULL end as SQLTEXT, case when rn = 1 then TotalExecuteTime else NULL end as TotalExecuteTime, CompletedTime as CompletedTime, WaitType, WaitTypeStartTime as WaitTypeStartTime, WaitDuration from ( select ROW_NUMBER()over(partition by SessionId,SQLTEXT,TotalExecuteTime,CompletedTime order by CompletedTime,WaitTypeStartTime) as rn, * FROM #t3 )t
當然該語句僅供參考，目的是為了收集Session級的統計信息，當收集到Session級別的統計信息之後，具體的統計方式也不難。
總結
等待事件可以幫助我們診斷SQL Server上的一些資源瓶頸，對於問題的處理和解決有著比較重要的參考意義，如果能夠細化地收集等待事件，對於解決問題的參考意義會更大。
本文通過一個簡單的示例，使用擴展事件來收集SQL Server中一些特定場景下的等待信息，來更加有針對性地進行問題的診斷和識別，使得問題的分析更加高效和具有針對性。
SQLServer中使用擴展事件獲取Session級別的等待信息以及SQLServer 2016中Session級別等待信息的增強