什么是等待
簡(jiǎn)單說明一下什么是等待：
當(dāng)應(yīng)用程序?qū)QL Server發(fā)起一個(gè)Session請(qǐng)求的時(shí)候，這個(gè)Session請(qǐng)求在數(shù)據(jù)庫中執(zhí)行的過程中會(huì)申請(qǐng)其所需要的資源，
比如可能會(huì)申請(qǐng)內(nèi)存資源，表上的鎖資源，物理IO資源，網(wǎng)絡(luò)資源等等，
如果當(dāng)前Session運(yùn)行過程中需要申請(qǐng)的某些資源無法立即得到滿足，就會(huì)產(chǎn)生等待。
SQL Server會(huì)以不用的方式來展現(xiàn)這個(gè)等待信息，比活動(dòng)Session的等待信息，實(shí)例級(jí)的等待信息等等。
SQL Server中，等待事件是作為DBA進(jìn)行TroubleShooting的重要參考信息之一，SQL Server中可以通過多中方式來獲取等待信息。
但是對(duì)于SQL Server 2016之前的版本來說，不管是活動(dòng)Session級(jí)別的等待和實(shí)例級(jí)的等待，參考意義都有限，
更多的時(shí)候是想要更加詳細(xì)的且可以事后分析的等待，這就需要收集那些曾經(jīng)已執(zhí)行過的Session產(chǎn)生的等待信息，也就是特定Session等待信息的歷史記錄
本文重點(diǎn)介紹使用擴(kuò)展事件來捕獲等待信息，但不介紹擴(kuò)展事件本身的使用，重點(diǎn)放在如何使用擴(kuò)展事件來獲取想要的等待事件信息。
需要對(duì)擴(kuò)展事件有一定的了解。
等待信息的獲取途徑
在SQL Server中有一個(gè)系統(tǒng)視圖sys.dm_os_wait_stats記錄了自數(shù)據(jù)庫服務(wù)啟動(dòng)以來累積產(chǎn)生的等待信息，
如下圖，這個(gè)結(jié)果是實(shí)例級(jí)的，也就是記錄的整個(gè)數(shù)據(jù)庫服務(wù)器所有的等待事件的累積。
多數(shù)時(shí)候參考意義不是很大，比如某一天的網(wǎng)絡(luò)延時(shí)很高，sys.dm_os_wait_stats中累計(jì)記錄了大量的ASYNC_NETWORK_IO等待信息。
但是到了第二天或者什么時(shí)候，網(wǎng)絡(luò)變好了，但是sys.dm_os_wait_stats中記錄的ASYNC_NETWORK_IO等待信息是不變的
也就是說sys.dm_os_wait_stats無法反映實(shí)時(shí)等待情況。
當(dāng)然要獲取實(shí)時(shí)的等待信息也簡(jiǎn)單，記錄兩個(gè)時(shí)間點(diǎn)之間sys.dm_os_wait_stats中等待時(shí)間的差值，可以間接地反映出來某一段時(shí)間的數(shù)據(jù)的等待信息。
但是這個(gè)信息仍然比較粗略，依舊是實(shí)例級(jí)的，某些時(shí)候依舊是不足夠作為參考的。
另外一個(gè)是通過sys.dm_exec_requests這個(gè)系統(tǒng)視圖的wait_type，wait_time等獲取活動(dòng)Session的等待信息
如截圖，但是這個(gè)是活動(dòng)Session的信息，當(dāng)Session完成之后，它的等待信息就看不到曾經(jīng)都產(chǎn)生了那些等待，分別是多久。
也就說，你無法追溯歷史上某一個(gè)Session或者某一個(gè)SQL（存儲(chǔ)過程）執(zhí)行過程中的都產(chǎn)生了什么類型的等待，等待了多長時(shí)間。
實(shí)話說，不管是sys.dm_os_wait_stats還是sys.dm_exec_requests，在正常情況下，獲取到的等待信息實(shí)用價(jià)值都是不高或者是適用場(chǎng)景有限。
更多的時(shí)候我們是想要更細(xì)一級(jí)的等待，比如某一個(gè)Login、某一部分Session、甚至某些特定的SQL（存儲(chǔ)過程）的執(zhí)行過程中產(chǎn)生的等待信息。
舉個(gè)實(shí)際例子，數(shù)據(jù)庫又10個(gè)Login給10個(gè)不同的應(yīng)用程序訪問，其中只有1個(gè)應(yīng)用程序端反饋說訪問數(shù)據(jù)庫慢，或者有性能問題，其他Login都反饋正常
那么很有可能是這個(gè)Login請(qǐng)求自己的問題，此時(shí)就需要針對(duì)這一個(gè)Login的情況進(jìn)行針對(duì)性分析，而不是在實(shí)例級(jí)分析診斷。
如果能夠拿到這個(gè)Login執(zhí)行的Session的等待情況，或者這個(gè)Login某些特定的數(shù)據(jù)庫對(duì)象的執(zhí)行過程中的等待信息，對(duì)定位問題的針對(duì)性的就比較強(qiáng)了。
本文就以此為切入點(diǎn)，針對(duì)如何獲取Session級(jí)別的等待信息展開說明和演示。
SQL Server 2016中獲取Session級(jí)別的等待信息
在SQL Server 2016中，獲取Session級(jí)別的等待信息是比較方便的，有直接的系統(tǒng)視圖sys.dm_exec_session_wait_stats可以使用
當(dāng)前情況下，想要知道某一個(gè)Session的等待信息就很簡(jiǎn)單了，
在sql語句開始的時(shí)候把當(dāng)前Session的等待信息記錄下來
在sql語句結(jié)束的時(shí)候把當(dāng)前Session的等待信息再次記錄出來
計(jì)算兩次等待信息的差值，就可以知道當(dāng)前Session運(yùn)行的過程中有哪些等待，分別是多少。
sqlserver開發(fā)團(tuán)隊(duì)可能也意識(shí)到了對(duì)于等待信息，更多的時(shí)候，需要的是較為具體的等待，而不是一個(gè)籠統(tǒng)的實(shí)例級(jí)的等待
因此在SQL Server 2016中增加了sys.dm_exec_session_wait_stats這個(gè)支持統(tǒng)計(jì)Session級(jí)別的等待的視圖
很不幸的SQL Server2016之前的版本中是沒有這個(gè)系統(tǒng)視圖可以很方便地記錄Session級(jí)別的等待。
但是可以借助擴(kuò)展事件來實(shí)現(xiàn)類似的功能。
使用擴(kuò)展事件來捕獲Session級(jí)別的等待信息
因?yàn)檫@里是是用擴(kuò)展事件來實(shí)現(xiàn)的，這里要求讀者要對(duì)擴(kuò)展事件有一個(gè)基本的認(rèn)識(shí)，擴(kuò)展事件本身就不多說了。
上代碼，啟動(dòng)一個(gè)擴(kuò)展事件，來記錄執(zhí)行時(shí)間超過三秒的SQL語句，其執(zhí)行過程中等待時(shí)間大于0的等待事件信息。
當(dāng)然這個(gè)捕獲的信息可以加上各種過濾條件。具體參考代碼備注。
|
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
|
IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name='CollectionSessionWaitStats') DROP EVENT session CollectionSessionWaitStats ON SERVER;GO-- 創(chuàng)建事件會(huì)話 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-- 啟用（停止）事件會(huì)話（START / STOP） ALTER EVENT SESSION CollectionSessionWaitStats ON SERVER STATE=START GO |
是用擴(kuò)展事件收集的Session級(jí)別的等待信息有以下幾個(gè)特點(diǎn)
1，SessionId是可以重復(fù)的
舉例說明就是:比如一個(gè)SessionId = 80的Session，可以第一次執(zhí)行一個(gè)SQLA，第二次執(zhí)行一個(gè)SQLB.
同時(shí)這兩個(gè)SQL的執(zhí)行與其執(zhí)行過程中產(chǎn)生的等待信息都可以被捕獲出來
2，同一個(gè)時(shí)間段內(nèi)，一個(gè)同一個(gè)SessionId不可能同時(shí)執(zhí)行，
比如16：46：36秒到16：46：46秒到這個(gè)時(shí)間內(nèi)，SessionId = 80的Session正在執(zhí)行，擴(kuò)展事件捕獲到了其產(chǎn)生的等待信息
但是在16：46：36秒到16：46：46這個(gè)時(shí)間段內(nèi)，不可能有另外一個(gè)SessionId = 80也在執(zhí)行，這個(gè)邏輯不難理解
為什么要特意說明這個(gè)問題？
因?yàn)閿U(kuò)展事件收集到的事件信息中SQL語句完成事件（rpc_completed或者sql_batch_completed）與產(chǎn)生的等待之間，沒有一個(gè)直接的對(duì)應(yīng)關(guān)系。
怎么理解？動(dòng)起手來才能發(fā)現(xiàn)問題，我是這個(gè)糾結(jié)了大半天，截圖示例。
如下截圖，擴(kuò)展事件捕獲到的兩個(gè)目標(biāo)事件的SessionId都是58，但是執(zhí)行的SQL是不一樣的，
如下截圖是不區(qū)分事件類型，捕獲到的所有的事件信息。
也就是上面說的，對(duì)于58號(hào)Session:
第一次運(yùn)行了SELECT COUNT(1) FROM TestCollectionSessionWaitStats
第二次運(yùn)行了SELECT COUNT(1) FROM TestCollectionSessionWaitStats WHERE Id>10
兩次運(yùn)行的SQL一致或者不一致問題不大，關(guān)鍵是捕獲到的等待事件信心的SessionId也是58，怎么區(qū)分產(chǎn)生的事件是歸屬于哪一次的運(yùn)行？
比如58號(hào)Session運(yùn)行兩次sql，產(chǎn)生了10條等待信息，怎么區(qū)分這10條等待信息哪些歸屬于第一次運(yùn)行生成的，哪些歸屬于第二次運(yùn)行生成的？
這個(gè)就依靠上面說的第二點(diǎn)“同一個(gè)時(shí)間段內(nèi)，一個(gè)同一個(gè)SessionId不可能同時(shí)執(zhí)行”
對(duì)于同一個(gè)SessionId，在sql_batch_completed事件中，從時(shí)間的維度來看
小于第一次sql_batch_completed事件完成時(shí)間的必然是58號(hào)Session第一次執(zhí)行生成的
大于第一次sql_batch_completed事件完成事件的且小于第二次sql_batch_completed的必然是58號(hào)Session第二次執(zhí)行生成的
有了這個(gè)理論基礎(chǔ)，我們統(tǒng)計(jì)Session級(jí)別的等待就比較容易了，相信這個(gè)邏輯的實(shí)現(xiàn)并不難。
如下圖是58號(hào)Session執(zhí)行某SQL語句產(chǎn)生的等待詳細(xì)信息，可以看到多次產(chǎn)生了CXPACKET和 PAGEIOLATCH_SH等待
鑒于截圖問題，下面還有另外一個(gè)同樣是58號(hào)Session的執(zhí)行另外一個(gè)SQL捕獲到的等待信息
這個(gè)統(tǒng)計(jì)辦法就是上面提到的，在兩次sql_batch_completed事件中，雖然等待事件的SessionId一樣，
但是其發(fā)生的時(shí)候是處于當(dāng)前事件的sql_batch_completed之前，上一次sql_batch_completed之后，
這樣就可以完美地匹配到sql_batch_completed事件與其對(duì)應(yīng)的wait_info事件。
在這種情況下，統(tǒng)計(jì)得到類似于SQL Server 2016中的sys.dm_os_wait_stats的結(jié)果也就不難了。
與sys.dm_os_wait_stats 等待信息的結(jié)果相比，上述通過擴(kuò)展事件獲取的等待信息，是不是更加詳細(xì)和具體？
比如對(duì)于CXPACKET等待時(shí)間，
不難發(fā)現(xiàn)，如果計(jì)算計(jì)算其產(chǎn)生的次數(shù)（count），就類似于sys.dm_os_wait_stats 中的waiting_tasks_count，計(jì)算其產(chǎn)生的總時(shí)間（sum），就類似于wait_time_ms
但是上述時(shí)間的信息已經(jīng)細(xì)化到Session級(jí)別了，比sys.dm_os_wait_stats 中的等待信息更有參考價(jià)值。
對(duì)于問題的診斷和分析，也會(huì)是更加有效。
上述統(tǒng)計(jì)結(jié)果的SQL語句
|
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
|
-- Parse the XML to show rpc_completed,sql_batch_completed detailsif object_id('tempdb..#t1') is not null drop table #t1SELECT event_xml.value('(./action[@name="session_id"]/value)[1]', 'INT') as session_id, event_xml.value('(./@timestamp)', '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('(./@name)', '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 usernameINTO #t1FROM ( 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_tableCROSS APPLY xml_event_data.nodes('//event') n (event_xml)WHERE event_xml.value('(./@name)', 'varchar(1000)') in ('rpc_completed','sql_batch_completed')order by Event_Name-- Parse the XML to show wait_info,wait_info_external detailsif object_id('tempdb..#t2') is not null drop table #t2SELECT cast(event_xml.value('(./@timestamp)', '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_typeINTO #t2FROM ( 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('(./@name)', 'varchar(1000)') in ('wait_info','wait_info_external')if object_id('tempdb..#t3') is not null drop table #t3SELECT 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 WaitDurationINTO #t3FROM #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, WaitDurationfrom( select ROW_NUMBER()over(partition by SessionId,SQLTEXT,TotalExecuteTime,CompletedTime order by CompletedTime,WaitTypeStartTime) as rn, * FROM #t3) |
當(dāng)然該語句僅供參考，目的是為了收集Session級(jí)的統(tǒng)計(jì)信息，當(dāng)收集到Session級(jí)別的統(tǒng)計(jì)信息之后，具體的統(tǒng)計(jì)方式也不難。
總結(jié)
等待事件可以幫助我們?cè)\斷SQL Server上的一些資源瓶頸，對(duì)于問題的處理和解決有著比較重要的參考意義，如果能夠細(xì)化地收集等待事件，對(duì)于解決問題的參考意義會(huì)更大。
本文通過一個(gè)簡(jiǎn)單的示例，使用擴(kuò)展事件來收集SQL Server中一些特定場(chǎng)景下的等待信息，來更加有針對(duì)性地進(jìn)行問題的診斷和識(shí)別，使得問題的分析更加高效和具有針對(duì)性。
以上所述是小編給大家介紹的SQLServer中使用擴(kuò)展事件獲取Session級(jí)別的等待信息及SQLServer 2016中Session級(jí)別等待信息的增強(qiáng)，希望對(duì)大家有所幫助，如果大家有任何疑問請(qǐng)給我留言，小編會(huì)及時(shí)回復(fù)大家的。在此也非常感謝大家對(duì)服務(wù)器之家網(wǎng)站的支持！
原文鏈接：http://www.cnblogs.com/wy123/archive/2017/05/11/6835939.html
