SQL Server擴展事件的使用ring_buffer target時「丟失」事件的緣由分析以及ring_buffer target潛在的問題

 

事情原由：
　　排查SQL Server上的死鎖問題，一開始想到的就是擴展事件，
　　第一種方案，開profile守株待兔吧，顯得太low了，至於profile的變種trace吧，垂垂老矣，也一直沒怎麼用過。
　　第二種方案是開啓TRACE flag（DBCC TRACEON (3605,1204,1222,-1)）將死鎖寫入error log，也是個不錯的選擇。
　　不過想到系統默認的擴展事件system_health已經捕獲了死鎖信息（sqlserver.xml_deadlock_report），
　　就不必再從新往error log記一次了，理論上從system_health中就能拿到死鎖信息，所以嘗試從system_health的ring_buffer target獲取死鎖信息。

排查通過：
　　從sysem_health的ring_buffer中目標中，並無捕獲到預期的曾經發生的死鎖事件信息，
　　在徹底確認發生過死鎖的狀況下（而且是最近，或者是剛剛），爲何sysem_health「沒有可以捕獲到」？
　　無奈之下單獨開了一個捕獲死鎖事件的擴展事件Session（僅捕獲sqlserver.xml_deadlock_report），target目標是存儲在ring_buffer中
　　在人爲刻意地製造一個死鎖以後，來檢驗sysem_health和自定義的捕獲擴展事件捕獲的死鎖信息
　　此時意想不到的狀況發生了，自定義的擴展事件完整地捕獲到了這個死鎖信息，而system_health仍舊沒有捕獲到對應的死鎖信息。
　　什麼狀況？

 　　以下自定義擴展事件腳本

CREATE EVENT SESSION [Deadlock_Monitor] ON SERVER
ADD EVENT sqlserver.xml_deadlock_report
ADD TARGET package0.ring_buffer(SET max_events_limit=(5000),max_memory=(4096))
WITH
(MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=10 SECONDS,
MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=ON)
 
ALTER EVENT SESSION [Deadlock_Monitor] ON SERVER STATE = start;
 

死鎖捕獲結果，sysem_health並無捕獲到預期的死鎖事件，儘管他包括了sqlserver.xml_deadlock_report事件

SELECT  xed.value('@timestamp', 'datetime') AS Creation_Date ,
        CAST(REPLACE(REPLACE(REPLACE(CAST(xed.query('.') AS NVARCHAR(MAX)),'&lt;', '<'),'&gt;', '>'),'&amp;apos;','''') AS xml) AS Extend_Event
FROM    ( SELECT    CAST([target_data] AS XML) AS Target_Data
          FROM      sys.dm_xe_session_targets AS xt
                    INNER JOIN sys.dm_xe_sessions AS xs ON xs.address = xt.event_session_address
          WHERE     xs.name = N'system_health'
                    AND xt.target_name = N'ring_buffer'
        ) AS XML_Data
        CROSS APPLY Target_Data.nodes('RingBufferTarget/event[@name="xml_deadlock_report"]')
        AS XEventData ( xed )
ORDER BY Creation_Date DESC

select * from sys.dm_xe_session_targets

SELECT    CAST([target_data] AS XML) AS Target_Data
FROM      sys.dm_xe_session_targets AS xt
                    INNER JOIN sys.dm_xe_sessions AS xs ON xs.address = xt.event_session_address
WHERE     xs.name = N'system_health'
          --AND xt.target_name = N'ring_buffer'

-- Parse the XML to show wait details
SELECT event_table.*
    FROM (
        SELECT CAST(event_data AS XML) xml_event_data 
        FROM sys.fn_xe_file_target_read_file(N'path\Log\system_health*', NULL, NULL, NULL)
    ) AS event_table
    CROSS APPLY xml_event_data.nodes('//event') n (event_xml)
WHERE  event_xml.value('(./@name)', 'varchar(1000)') IN ('xml_deadlock_report')   

 

　　因爲sysem_health有兩個輸出的target，一個ring_buffer，一個是target_file，無奈下從event_file查詢捕獲的死鎖信息，這裏又是沒問題的，正常捕獲到了。

　　

　　所以就能夠說，系統默認自帶的sysem_health擴展事件，捕獲死鎖自己是沒有問題的，問題出在擴展事件的輸出目標ring_buffer上。
　　在不過濾全部的擴展事件狀況下，從ring_buffer裏面解析出來的數據還有個特色，其不包含最近一段時間的任何一種事件信息。
　　也就是說，ring_buffer中解出來的事件信息，是當前時間前一段時間的事件信息，並不包含全部的事件信息，以及最近一段事件全部的事件信息。
　　固然你能夠說ring_buffer是先進先出的隊列模型，那也應該留下新的事件，而不是解析不出來最新的事件信息。

緣由分析：
　　參考了sqlskill上的一篇文章，這篇文章深刻地解析了這個問題，
　　簡單說就是：
　　ring_buffer並無「丟失」事件信息，至於爲何解析不出來，要從ring_buffer解析方式開始，ring_buffer擴展事件從sys.dm_xe_session_targets 這個DMV中解析的，
　　受到sys.dm_xe_session_targets 這個DMV的目標數據列target_data字段只能容納大約4 MB的XML數據的限制。
　　當ring_buffer捕獲的事件（內存中的二進制數據）轉換爲XML格式大於（大約）4MB的狀況下，超過4MB的其餘的事件會被被「截斷」，
　　從sys.dm_xe_session_targets解析出來的XML文件優先輸出更早的事件，因此咱們預期下的最近發生的事件是沒法看到的。
　　所以，正如上文中遇到的狀況同樣：「丟失」部分事件信息，而且沒有最近的事件信息。

總結：　　
　　以此來看，使用ring_buffer爲擴展事件的target，潛在如下問題
　　1，解析出來的結果並不可靠（完整），可能沒法解析到最近的部分事件。
　　2，如下譯文中還會提到，ring_buffer做爲target可能會撐爆內存的狀況，因此要謹慎使用。
　　3，一樣下文會提到，SSMS的UI對ring_buffer中的事件支持的並很差，對於ring_buffer的target，UI也僅僅是show出來一個XML文件，必需要本身解析，而不像event_file中那樣表格化展現（可讀性）
　　所以要儘可能避免在擴展事件中使用ring_buffer target。

 

 

 

 

以下是譯文，原文地址：https://www.sqlskills.com/blogs/jonathan/why-i-hate-the-ring_buffer-target-in-extended-events/

 

（標題）我爲何討厭擴展事件中的ring_buffer target

我曾經屢次遇到擴展事件中有關ring_buffer target一樣的問題,
我想我會寫一篇博客文章,解釋了我教的全部信息關於ring_buffer target和與之關聯的問題。
自從sqlserver 2012發佈以及擴展事件新UI的更新，我之後堅定不會再使用ring_buffer target
事實上，正如文章標題所言，我確實很討厭ring_buffer target，這篇文章中我將會闡述我討厭ring_buffer target的緣由，而且但願說服應該使用file_target代替。

丟失事件

這是我經過電子郵件解釋關於ring_buffer目標的最多見問題。通常來講，以下是典型的問題描述：

我從SQL Server中心的一篇文章中獲得了下面的代碼，它不起做用。我遇到的問題是，當我運行代碼時，即便我知道應用程序中剛剛發生了一個死鎖事件，它也不會顯示任何死鎖信息。
彷佛我只在system_health會話中看到較舊的死鎖，但歷來沒有看到最新的死鎖。我打開了Trace 1222並以這種方式獲取信息，那麼爲何不這樣作。

實際狀況是，事件（event）實際上在就那裏，你沒法看到（你預期的事件）是由於sys.dm_xe_session_targets 這個DMV的限制。
這個DMV的目標數據列只能輸出大約4 MB的XML數據。
Bob Ward20009年的時候在CSS SQL Server工程師博客中解釋了DMV的4 MB格式XML限制的信息。
爲了證實這種限制的結果，讓咱們來看看在SQL Server 2012 SP1+CU7服務器上的系統健康事件會話中包含的事件數量，我可使用下面的查詢來查看信息。

SELECT
    ring_buffer_event_count, 
    event_node_count, 
    ring_buffer_event_count - event_node_count AS events_not_in_xml
FROM
(    SELECT target_data.value('(RingBufferTarget/@eventCount)[1]', 'int') AS ring_buffer_event_count,
        target_data.value('count(RingBufferTarget/event)', 'int') as event_node_count
    FROM
    (    SELECT CAST(target_data AS XML) AS target_data  
        FROM sys.dm_xe_sessions as s
        INNER JOIN sys.dm_xe_session_targets AS st 
            ON s.address = st.event_session_address
        WHERE s.name = N'system_health'
            AND st.target_name = N'ring_buffer'    ) AS n    ) AS t;

ring_buffer_event_count是RingBufferTarget根元素返回的XML文檔的eventCount屬性（譯者注：ring_buffer_event_count是RingBufferTarget捕獲到的事件的總數）
event_node_count是sys.dm_xe_session_targets 這個 DMV中返回的ingBufferTarget/event nodes中事件的個數（二者的差值就是所謂丟失的事件個數）
這裏你能夠看到ring_buffer target中一共有5000個事件，（緣由是）system_health會話基於2012新的MAX_EVENTS_LIMIT選項設定在5000。
不過，僅僅有3574個事件被DMV中的XML輸出了出來，剩下有1426個事件仍然不可用（不可見，沒法解析出來），儘管他們是滯留在內存中的。
sys.dm_xe_session_targets 的XML文件優先輸出更早的事件，因此咱們預期下的最近發生的事件是沒法看到的。

譯者注，以下是system_health中ring_buffer MAX_EVENTS_LIMIT選項設定在5000的值：

咱們能夠觀察擴展事件目標占用的內存和DMV中的XML二進制數據佔用的內存狀況，使用以下查詢

SELECT
    target_data.value('(RingBufferTarget/@memoryUsed)[1]', 'int') AS buffer_memory_used_bytes,
    ROUND(target_data.value('(RingBufferTarget/@memoryUsed)[1]', 'int')/1024., 1) AS buffer_memory_used_kb,
    ROUND(target_data.value('(RingBufferTarget/@memoryUsed)[1]', 'int')/1024/1024., 1) AS buffer_memory_used_MB,
    DATALENGTH(target_data) AS xml_length_bytes,
    ROUND(DATALENGTH(target_data)/1024., 1) AS xml_length_kb,
    ROUND(DATALENGTH(target_data)/1024./1024,1) AS xml_length_MB
FROM (
SELECT CAST(target_data AS XML) AS target_data  
FROM sys.dm_xe_sessions as s
INNER JOIN sys.dm_xe_session_targets AS st 
    ON s.address = st.event_session_address
WHERE s.name = N'system_health'
 AND st.target_name = N'ring_buffer') as tab(target_data)

這裏咱們能夠看到，二進制數據佔用的內存大約爲1.7MB，不過一旦序列化爲XML，文件的大小就變爲大約4.7MB，比二進制數據空間要大
問題的本質就在於，擴展事件生成的特色，決定了他緊湊的二進制格式的，可是序列化的格式化XML會爲這些事件增長存儲空間。

system_health事件會話特別傾向於收集最多5000個事件但ring_buffer，DMV實際上只能輸出一小部分事件會話。
最有可能的是，sp_server_diagnostics_component_output和xml_deadlock_report具備至關大的事件是（佔用的空間），由於這兩個事件返回的XML的大小取決於它們什麼時候觸發的條件的具體狀況。

我發如今繁忙的服務器上出現問題時，sp_server_diagnostics_component_output事件的大小超過了512KB，
所以當輸出XML中包含其中一個事件時，對ring_buffer目標，由DMV返回的數據可能會受到很大限制。

 

沒有UI的支持

這對我來講多是我平常工做中再也不使用ring_buffer做爲輸出目標的最大緣由。
擴展事件UI不支持分解ring_buffer目標中包含的信息， UI的惟一功能是顯示由sys.dm_xe_session_targets DMV的target_data列輸出的XML。

這意味着要使用數據，您必須打開XML並掃描事件，或編寫XQuery以將XML解析爲表格形式，這要求您知道事件會話中使用的事件，列和操做定義來真正訪問數據。
若是我正在進行短時間數據收集，而且不但願它保存到SQL Server 2012上的文件系統中的文件，我只需選擇實時視圖就能夠將數據流式傳輸回UI的列表中，
在這種狀況下，我沒必要處理XML並能夠快速找到我感興趣的信息。
對於任何長期任務，甚至查看system_health事件會話中的信息，我都使用file_target，UI能夠讀取和處理事件，無需手動執行任何XQuery。

小心內存的使用

在生產服務器上配置ring_buffer目標的方式須要很是當心，這對我來講是前所未聞的。兩週以前，Andy Galbraith遇到一個全部鏈接報701系統內存不足的錯誤，通過分析，Andy發如今內存16GB，最大內存（max server memory）配置爲11000MB的服務器上，MEMORYCLERK_XE memory clerk 佔用了10GB的內存，問題就在於，一個擴展事件配置了收集最大（MAX_EVENTS_LIMIT）1,000,000 個事件，可是沒有配置最大內存限制，所以內存的使用就基於擴展事件收集到的事件個數，而且沒有最大的內存使用限制，那麼它就可使用無限的內存，在內存有限的狀況下，從而致使服務器上出現問題。