Hide & Seek With Extended Events

Here's a script I'll use to demonstrate. It creates a test database and an Event Session. The session definition includes the database_attached and database_detached events, each with a small set of actions (Global Fields) included. There are two asynchronous targets: an event_file and the ring_buffer.

CREATE DATABASE [TestDB]
ON  PRIMARY 
 ( NAME = N'TestDB', FILENAME = N'D:\DBA\TestDB.mdf')
LOG ON 
 ( NAME = N'TestDB_log', FILENAME = N'D:\DBA\TestDB_log.ldf')
GO

CREATE EVENT SESSION [XEventTest] ON SERVER 
ADD EVENT sqlserver.database_attached(
    ACTION(
  sqlserver.client_app_name,
  sqlserver.database_name,
  sqlserver.sql_text
 )
),
ADD EVENT sqlserver.database_detached(
 ACTION(
  sqlserver.client_app_name,
  sqlserver.database_name,
  sqlserver.sql_text
 )
)
ADD TARGET package0.event_file(SET filename=N'XEventTest'),
ADD TARGET package0.ring_buffer
WITH (
 MAX_MEMORY=4096 KB,
 EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
 MAX_DISPATCH_LATENCY=1 SECONDS,
 MAX_EVENT_SIZE=0 KB,
 MEMORY_PARTITION_MODE=NONE,
 TRACK_CAUSALITY=OFF,
 STARTUP_STATE=OFF
)
GO

After creating the session, I'll open SSMS and navigate to it within the object explorer. Right-click it and select "Start Session", then right-click it a second time and select "Watch Live Data", which opens a new tab in SSMS.

Now, let's detach a database and trigger the database_detached event:

EXEC master.dbo.sp_detach_db @dbname = N'TestDB';

When I switch to the "Live Data" grid, it's empty. Hmm. What happened?

Let's proceed slowly here. As noted earlier, the XEvent session was created with two targets. We can verify them with this query:

SELECT xet.*
FROM sys.dm_xe_session_targets AS xet
JOIN sys.dm_xe_sessions AS xes
 ON (xes.address = xet.event_session_address)
WHERE xes.name = 'XEventTest';

The query results show us the ring_buffer and event_file targets. But there's also an event_stream target. Why is it there? And where did it come from?

The event_stream typically only exists when the "Live Data" grid is open. SSMS uses the event_stream target to display XEvent data in the grid. We can't "query" target data from the event_stream target or otherwise access it in T-SQL. It's only accessible from .NET Framework applications via the XEvent .NET namespaces *More on this in the next post. But we can query the target data in the other targets.

--Ring Buffer
DECLARE @XEData XML

SELECT @XEData = CAST(xet.target_data AS XML)
FROM sys.dm_xe_session_targets AS xet
JOIN sys.dm_xe_sessions AS xes
 ON (xes.address = xet.event_session_address)
WHERE xes.name = 'XEventTest'
AND xet.target_name = 'ring_buffer';

SELECT t.c.value(N'(@name)[1]', N'NVARCHAR(MAX)') AS EventName,
 t.c.query('*') AS [EventData]
FROM @XEData.nodes('//RingBufferTarget/event') AS t(c)
GO

--Event File
SELECT object_name AS EventName,
 CAST(event_data AS XML) AS [EventData]
FROM sys.fn_xe_file_target_read_file (
 'XEventTest*.xel',
 'XEventTest*.xem', null, null);
GO

The database_detached event was clearly received by the ring_buffer and event_file targets. But if we return to the "Live Data" tab/grid in SSMS, we still have nothing. I don't have an explanation for this. I know, that's not exactly gratifying. Nonetheless, let's press on. I'll attach the database as follows:

EXEC sp_attach_db @dbname = N'TestDB',   
    @filename1 = N'D:\DBA\TestDB.mdf',   
    @filename2 = N'D:\DBA\TestDB_log.ldf'; 

If we query the ring_buffer and event_file targets again, we see the database_attached event was received by both targets.

Back to the "Live Data" tab/grid in SSMS. Ahhh! We have something now.

The database_detached event has been received and is in the grid. But the database_attached event that just occurred isn't there. The grid is now "one event behind". This circumstance seems to persist. If I detach (and re-attach) the database any number of times, the last event is never received by the event_stream, and accordingly, not in the "Live Data" grid either.

EXEC master.dbo.sp_detach_db @dbname = N'TestDB';
GO

EXEC sp_attach_db @dbname = N'TestDB',   
    @filename1 = N'D:\DBA\TestDB.mdf',   
    @filename2 = N'D:\DBA\TestDB_log.ldf'; 
GO

Workarounds

As has been shown above, the event_file and ring_buffer targets can be queried via T-SQL. If that's how you examine an XEvent session, you should have no worries. If you depend on the "Live Data" grid, you might consider adding a "dummy" event to the XEvent session definition. It would be an event that you could invoke on demand to displace any "hidden" events. Here's the same XEvent session from above, with an added error_reported "dummy" event:

CREATE EVENT SESSION [XEventTest] ON SERVER 
ADD EVENT sqlserver.database_attached(
 ACTION(
  sqlserver.client_app_name,
  sqlserver.database_name,
  sqlserver.sql_text
 )
),
ADD EVENT sqlserver.database_detached(
 ACTION(
  sqlserver.client_app_name,
  sqlserver.database_name,
  sqlserver.sql_text
 )
),
ADD EVENT sqlserver.error_reported(
    WHERE ([severity]=(10) AND [sqlserver].[like_i_sql_unicode_string]([message],N'%Displace Last Event%'))) 
 ADD TARGET package0.event_file(SET filename=N'XEventTest'),
 ADD TARGET package0.ring_buffer
WITH (
 MAX_MEMORY=4096 KB,
 EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
 MAX_DISPATCH_LATENCY=1 SECONDS,
 MAX_EVENT_SIZE=0 KB,
 MEMORY_PARTITION_MODE=NONE,
 TRACK_CAUSALITY=OFF,
 STARTUP_STATE=OFF
)
GO

At any time you could run this RAISERROR command:

RAISERROR('Displace Last Event', 10, 1);

This will create some "noise" in the grid, but it can easily be filtered out if desired.

Apathy?

After all of this, I suppose an important question is "Do you care?" The answer, of course is (wait for it...) "It depends". If your XEvent session includes events that occur on a frequent basis, the constant influx of event data probably makes this a moot point. However, if your events are happening infrequently enough, this might be an important issue. In my next two posts (one for C#, one for PowerShell), I'll show how to use the Microsoft.SqlServer.XEvent.Linq namespace to access an event stream programmatically. For that type of task, you'll definitely care.