SQL Server Quick Tasks – Setup Extended Event Trace For Monitoring

In my previous post I shown how easy it is to setup a server side trace to monitor for deadlocks. Server side trace is an old vintage DBA solution for all kinds of monitoring on SQL Server. However lets welcome a new weapon to the arsenal – SQL Server Extended Events that are intended to replace Profiler tracing. These were introduced in SQL Server 2008, but really came into their own with SQL Server 2012 with thousands of events and many categories. SQL Server Extended Events are built on Event Tracing for Windows (ETW) infrastructure that is taking Windows troubleshooting world by storm and are much more lightweight alternative to legacy SQL Server Trace. In SQL Server 2008, Extended Events can only be configured but using T-SQL and no user interface was available. SQL Server 2012, adds a user interface for configuring Extended Events. And evolution continues – The number of Extended Events increased from 625 in SQL Server 2012 (SP1) to 870 in SQL Server 2014 (RTM). That makes 245 new events added between versions.

Good introduction to SQL Extended Events is available in BOL.  There are also excellent posts on extended events available from Jonathan Kehayias on SQLSkills that goes way deeper than this post.

One of my customer’s DBA teams was doing pretty much what many good DBA teams do – monitoring SQL Server backend of large commercial application using a rolling server side SQL Trace.  However as application continued to grow in terms of database traffic and was migrated to SQL Server 2012 it was judged that time came to migrate SQL Trace to an Extended Event capture for obvious reasons.  That took a bit of research, but wasn’t as painful as I initially expected, below makes for an example of Extended Events capture that captures good events for analysis – rpc:completed and batch:completed, yet isn’t expensive and crazy enough to attempt a statement level capture in production system due to obvious impact on performance.

First thing that we will do is CREATE EVENT SESSION , this will create event session, identify targets we wish to monitor, etc. See BOL for complete command.

   ADD EVENT sqlserver.rpc_completed

   (    Sqlserver.sql_text, -- text
package0.collect_cpu_cycle_time )


So as you can see here I am capturing rpc:completed event that occurs as stored procedure execution completes, get execution time, user name under which it ran, application that sent it, client hostname and database id where execution occurred in SQL Server instance.

But I also want sql: batchcompleted event for all of the traffic that doesn’t come via rpc and instead executed as SQL Server batch. Let me add this event:

   ADD EVENT sqlserver.sql_batch_completed

   (    Sqlserver.sql_text, -- text
  package0.collect_cpu_cycle_time )

Now that I got what I wanted to capture let me identify target – where we will capture that information into.  There are multiple targets that Extended Events support as per BOL, including ETW, Ring Buffer, etc. In my case I will use a pretty standard way to save my info – a nice local file, just as I would with SQL Trace running server side.

ADD TARGET package0.asynchronous_file_target
      (set filename = 'test.xel',
      metadatafile = 'test.xem');

Now as I am done building this capture definition I can manually start this capture

--Start the trace that we setup above.
ALTER EVENT SESSION  xe_Test on server state = start;

To start every time we start SQL automatically use this command

ALTER EVENT SESSION  xe_Test  on server with (STARTUP_STATE = ON);

Now that everything is working and logging to a file, now we need to get relevant data from the file, I used a CTE , but you can throw that data into a real SQL table as well. I will use sys.fn_xe_file_target_read_file to read XML from the file:

SELECT CAST(event_data as XML) AS edx
   FROM sys.fn_xe_file_target_read_file( 'Test*.xel', 'Test*.xem', NULL, NULL)
   , c as (

      edx.value('(//action/value)[1]','varchar(max)') as [SQL],
      edx.value('(//action/text)[2]','varchar(max)') as [time],
      edx.value('(//action/value)[3]','varchar(max)') as [Login],
      edx.value('(//action/value)[4]','varchar(max)') as [Application],
     edx.value('(//action/value)[5]','varchar(max)') as HostName,
      edx.value('(//action/value)[6]','varchar(max)') as DatabaseID,
    edx.value('(//action/value)[7]','varchar(max)') as [CPU]
   from x
   --Coordinated Universal Time (UTC)
   --Greenwich , England
   select dateadd(HH,-7,[time]) [Time] as utc_time
   , SQL
   , HostName 
   , [LOGIN]
   , [Application] 
   , [CPU] as cpu
   , db_name([DatabaseID]) DatabaseName
   from c

How do I stop this capture? Simple , I will use ALTER EVENT SESSION command again. Let me first see if my capture is running, I can use DMV to see that:

SELECT * FROM sys.dm_xe_sessions;

If it is lets stop it.

STATE = stop

So, although when I started with XE (Extended Events) I thought these were unnecessarily difficult for your average DBA they have grown on me and I used this way to troubleshoot SQL Server now quite a bit. Hope above is useful for your troubleshooting and monitoring endeavors. 


Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google+ photo

You are commenting using your Google+ account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )


Connecting to %s