扩展事件,事件的原因分析以及ring_buffer

 

SQL Server 扩展事件(Extended
Event)是用于服务器的常规事件处理系统,是追踪SQL
Server系统运行状态的神器,同时也是一个日志记录工具,扩展事件完全可以取代SQL追踪(SQL
Trace),扩展事件的设计功能:

事情起因:
  排查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获取死锁信息。

  • 由于扩展事件引擎不识别事件,因此,引擎可以将任何事件绑定到任何目标,因为引擎不受事件内容约束。
  • 事件与事件使用者不同,后者在扩展事件中称为“目标”(Target),也就是说任何目标可以接收任何事件。此外,引发的任何事件均可供目标自动使用,这样可以记录或提供额外的事件上下文。
  • 事件不同于在事件激发时要执行的操作。因此,任何操作可以与任何事件相关联。
  • 谓词可以动态筛选事件的激发,从而增强了扩展事件基础结构的灵活性。

排查经过:
  从sysem_health的ring_buffer中目标中,并没有捕获到预期的曾经发生的死锁事件信息,
  在完全确认发生过死锁的情况下(并且是最近,或者是刚刚),为什么sysem_health“没有能够捕获到”?
  无奈之下单独开了一个捕获死锁事件的扩展事件Session(仅捕获sqlserver.xml_deadlock_report),target目标是存储在ring_buffer中
  在人为刻意地制造一个死锁之后,来检验sysem_health和自定义的捕获扩展事件捕获的死锁信息
  此时意想不到的情况发生了,自定义的扩展事件完整地捕获到了这个死锁信息,而system_health仍旧没有捕获到对应的死锁信息。
  什么情况?

扩展事件可以同步生成事件数据(并异步处理该数据),这为事件处理提供了灵活的解决方案。此外,扩展事件提供以下功能:

   如下自定义扩展事件脚本

  • 一种跨服务器系统处理事件的统一方法,同时使用户可以隔离特定的事件进行故障排除。
  • 基于 Transact-SQL 的完全可配置的事件处理机制。
  • 可以动态监视活动进程,同时对这些进程的影响最小。
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;

使用TSQL创建扩展事件的过程比较复杂,但是,我们可以使用另外一种简单的方法:使用扩展时间的创建向导。

死锁捕获结果,sysem_health并没有捕获到预期的死锁事件,尽管他包括了sqlserver.xml_deadlock_report事件

一,创建扩展事件的会话

图片 1

step1,打开新建会话向导(New Session Wizard)

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'pathLogsystem_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')   

图片 2

 

step2,设置会话属性(Set Session Properties)

  由于sysem_health有两个输出的target,一个ring_buffer,一个是target_file,无奈下从event_file查询捕获的死锁信息,这里又是没问题的,正常捕获到了。

图片 3

  图片 4

step3,选择模板(Choose Template)

  因此就可以说,系统默认自带的sysem_health扩展事件,捕获死锁本身是没有问题的,问题出在扩展事件的输出目标ring_buffer上。
  在不过滤所有的扩展事件情况下,从ring_buffer里面解析出来的数据还有个特点,其不包含最近一段时间的任何一种事件信息。
  也就是说,ring_buffer中解出来的事件信息,是当前时间前一段时间的事件信息,并不包含所有的事件信息,以及最近一段事件所有的事件信息。
  当然你可以说ring_buffer是先进先出的队列模型,那也应该留下新的事件,而不是解析不出来最新的事件信息。

图片 5

原因分析:
  参考了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文件优先输出更早的事件,所以我们预期下的最近发生的事件是无法看到的。
  因此,正如上文中遇到的情况一样:“丢失”部分事件信息,并且没有最近的事件信息。

step4,选项捕获的事件(Select Events to Capture)

总结:  
  以此来看,使用ring_buffer为扩展事件的target,潜在以下问题
  1,解析出来的结果并不可靠(完整),可能无法解析到最近的部分事件。
  2,以下译文中还会提到,ring_buffer作为target可能会撑爆内存的情况,所以要谨慎使用。
  3,同样下文会提到,SSMS的UI对ring_buffer中的事件支持的并不好,对于ring_buffer的target,UI也仅仅是show出来一个XML文件,必须要自己解析,而不像event_file中那样表格化展示(可读性)
  因此要尽量避免在扩展事件中使用ring_buffer target。

该Tab分为两个Pane,左边Pane用于搜索Event,在Event
library中,输入需要进行追踪的Event
名称,在选择一个Event之后,Wizard会显示出该Event的Description和 Event
Fields,Event fields
是描述Event输出的字段。右边Pane用于列出已经选中的Events 列表。

 

图片 6

 

Step5,选择捕获的字段(Capture Global Fields)

 

选择Event发生时其他信息,这些信息一般跟Session相关,例如Database_id 和
Database_id 就是Event发生的database
信息。一般会将sql_text也选中,便于查看触发Event的SQL语句。

 

图片 7

如下是译文,原文地址:

Step6,设置会话时间的过滤器(Set Session Event Filters)

 

图片 8

(标题)我为什么讨厌扩展事件中的ring_buffer target

Step7,指定会话数据的存储(Specify Session Data Storage)

我曾经多次遇到扩展事件中有关ring_buffer target同样的问题,
我想我会写一篇博客文章,解释了我教的所有信息关于ring_buffer
target和与之关联的问题。
自从sqlserver
2012发布以及扩展事件新UI的更新,我以后坚决不会再使用ring_buffer
target
事实上,正如文章标题所言,我确实很讨厌ring_buffer
target,这篇文章中我将会阐述我讨厌ring_buffer
target的原因,并且希望说服应该使用file_target代替。

制定输出数据存储的目标(target),该tab中列出 Event File target 和 ring
buffer target。

丢失事件

Event File target使用File来存储Session
Output,当需要存储大量数据集时,使用该选项。

这是我通过电子邮件解释关于ring_buffer目标的最常见问题。一般来说,如下是典型的问题描述:

Ring buffer target使用Memory buffer来存储Session
Output,如果分配的memory
buffer用完,target会将最老的Events删除,以容纳新的Events,使memory
buffers中存储的是most recent data。

我从SQL Server中心的一篇文章中得到了下面的代码,它不起作用。我遇到的问题是,当我运行代码时,即使我知道应用程序中刚刚发生了一个死锁事件,它也不会显示任何死锁信息。
似乎我只在system_health会话中看到较旧的死锁,但从来没有看到最新的死锁。我打开了Trace 1222并以这种方式获取信息,那么为什么不这样做。

图片 9

实际情况是,事件(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服务器上的系统健康事件会话中包含的事件数量,我可以使用下面的查询来查看信息。

Step8,查看扩展事件会话的汇总信息,开始创建事件会话。

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;

二,查看扩展事件捕获的消息

图片 10

SQL Server
扩展事件捕获的消息,叫做Target,使用Target来存储Events,Target
能够把捕获的消息存储到文件中(扩展名是 .xel),或 memoy buffer 中(Ring
Buffer),Target能够以同步或异步方式处理数据,事件的数据都是以XML格式存储。

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文件优先输出更早的事件,所以我们预期下的最近发生的事件是无法看到的。

三,以文件存储Target的数据

译者注,如下是system_health中ring_buffer
MAX_EVENTS_LIMIT选项设定在5000的值:

Target对于扩展事件产生的数据,总是先缓存在内存buffer中,等到内存buffers积累足够数量的数据之后,再将内存中的所有数据写入到文件中。文件中的数据滞后于内存
buffer,这就是异步写(Async
Write),能够减少IO的次数,提高IO效率。事件文件类型的taget的扩展名是xel,以XML格式存储Target
数据,使用 sys.fn_xe_file_target_read_file
函数查看事件文件中存储的数据。

图片 11

1,以Rollover 方式复用事件文件

我们可以观察扩展事件目标占用的内存和DMV中的XML二进制数据占用的内存情况,使用如下查询

事件文件类型的Target 以 rollover 方式复用文件,例如,如果
max_rollover_files=3,那么系统中最多保留 3个
xel文件,文件命名:xxx_0.xel,xxx_1.xel,xxx_2.xel。当文件xxx_0.xel达到Max_File_Size时,Target执行一次rollover,将文件:xxx_0.xel删除,创建新文件:xxx_3.xel,并用该文件存储事件数据。

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)

2,从 sys.dm_xe_session_targets 中查看事件文件的存储路径

图片 12

select s.name as xe_session_name,
    cast(st.target_data as xml) as target_data
from sys.dm_xe_sessions s 
inner join sys.dm_xe_session_targets st 
    on s.address=st.event_session_address
where s.name='xe_session_name'

发表评论

电子邮件地址不会被公开。 必填项已用*标注