SQL SERVER – Introduction to Extended Events – Finding Long Running Queries

The job of an SQL Consultant is very interesting as always. The month before, I was busy doing query optimization and performance tuning projects for our clients, and this month, I am busy delivering my performance in Microsoft SQL Server 2005/2008 Query Optimization and & Performance Tuning Course. I recently read white paper about Extended Event by SQL Server MVP Jonathan Kehayias. You can read the white paper here: Using SQL Server 2008 Extended Events. I also read another appealing chapter by Jonathan in the book, SQLAuthority Book Review – Professional SQL Server 2008 Internals and Troubleshooting. After reading these excellent notes by Jonathan, I decided to upgrade my course and include Extended Event as one of the modules.

This week, I have delivered Extended Events session two times and attendees really liked the said course. They really think Extended Events is one of the most powerful tools available. Extended Events can do many things. I suggest that you read the white paper I mentioned to learn more about this tool. Instead of writing a long theory, I am going to write a very quick script for Extended Events. This event session captures all the longest running queries ever since the event session was started. One of the many advantages of the Extended Events is that it can be configured very easily and it is a robust method to collect necessary information in terms of troubleshooting. There are many targets where you can store the information, which include XML file target, which I really like.

In the following Events, we are writing the details of the event at two locations: 1) Ringer Buffer; and 2) XML file. It is not necessary to write at both places, either of the two will do.

-- Extended Event for finding *long running query*
IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name='LongRunningQuery')
DROP EVENT SESSION LongRunningQuery ON SERVER
GO
-- Create Event
CREATE EVENT SESSION LongRunningQuery
ON SERVER
-- Add event to capture event
ADD EVENT sqlserver.sql_statement_completed
(
-- Add action - event property
ACTION (sqlserver.sql_text, sqlserver.tsql_stack)
-- Predicate - time 1000 milisecond
WHERE sqlserver.sql_statement_completed.duration > 1000
)
-- Add target for capturing the data - XML File
ADD TARGET package0.asynchronous_file_target(
SET filename='c:\LongRunningQuery.xet', metadatafile='c:\LongRunningQuery.xem'),
-- Add target for capturing the data - Ring Bugger
ADD TARGET package0.ring_buffer
(SET max_memory = 4096)
WITH (max_dispatch_latency = 1 seconds)
GO
-- Enable Event
ALTER EVENT SESSION LongRunningQuery ON SERVER
STATE
=START
GO
-- Run long query (longer than 1000 ms)
SELECT *
FROM AdventureWorks.Sales.SalesOrderDetail
ORDER BY UnitPriceDiscount DESC
GO
-- Stop the event
ALTER EVENT SESSION LongRunningQuery ON SERVER
STATE
=STOP
GO
-- Read the data from Ring Buffer
SELECT CAST(dt.target_data AS XML) AS xmlLockData
FROM sys.dm_xe_session_targets dt
JOIN sys.dm_xe_sessions ds ON ds.Address = dt.event_session_address
JOIN sys.server_event_sessions ss ON ds.Name = ss.Name
WHERE dt.target_name = 'ring_buffer'
AND ds.Name = 'LongRunningQuery'
GO
-- Read the data from XML File
SELECT event_data_XML.value('(event/data[1])[1]','VARCHAR(100)') AS Database_ID,
event_data_XML.value('(event/data[2])[1]','INT') AS OBJECT_ID,
event_data_XML.value('(event/data[3])[1]','INT') AS object_type,
event_data_XML.value('(event/data[4])[1]','INT') AS cpu,
event_data_XML.value('(event/data[5])[1]','INT') AS duration,
event_data_XML.value('(event/data[6])[1]','INT') AS reads,
event_data_XML.value('(event/data[7])[1]','INT') AS writes,
event_data_XML.value('(event/action[1])[1]','VARCHAR(512)') AS sql_text,
event_data_XML.value('(event/action[2])[1]','VARCHAR(512)') AS tsql_stack,
CAST(event_data_XML.value('(event/action[2])[1]','VARCHAR(512)') AS XML).value('(frame/@handle)[1]','VARCHAR(50)') AS handle
FROM
(
SELECT CAST(event_data AS XML) event_data_XML, *
FROM sys.fn_xe_file_target_read_file
('c:\LongRunningQuery*.xet',
'c:\LongRunningQuery*.xem',
NULL, NULL))
T
GO
-- Clean up. Drop the event
DROP EVENT SESSION LongRunningQuery
ON SERVER
GO

Just run the above query, afterwards you will find following result set.

This result set contains the query that was running over 1000 ms. In our example, I used the XML file, and it does not reset when SQL services or computers restarts (if you are using DMV, it will reset when SQL services restarts).

This event session can be very helpful for troubleshooting. Let me know if you want me to write more about Extended Events. I am totally fascinated with this feature, so I’m planning to acquire more knowledge about it so I can determine its other usages.

Reference : Pinal Dave (http://blog.SQLAuthority.com)

About these ads

24 thoughts on “SQL SERVER – Introduction to Extended Events – Finding Long Running Queries

  1. Dear Pinal, have a question that When I am attaching database files in other computer having same database Server SQL Server 2008 its showing that Database ReadOnly, what should I do in this scenario..why its showing ReadOnly and how can I make this readable for this server.?

    • Hello Abdul,

      Alter the database with ALTER DATABASE statement as below:

      ALTER DATABASE yourDatabase SET READWRITE;

      Or change the Database Read-Only option value to False from database Properties > Option page.

      Regards,
      Pinal Dave

  2. HI Pinal,
    Thanks for the article, usually used DMV’s for checking running queries. This mehtod looks really interesting.

    Thank you
    Ramdas

  3. Wonderful! I’d like to see more of this!

    Is the duration in microseconds? Is there a way I can see the duration of queries inside a stored procedure?

    Thanks!

    DA

  4. Pinal, why would we use this when we can get the same exact information from SQL Trace, much more easily and without any XML?

  5. Dave
    ally appriciate your help and assistence on these Extended events feature and usability.
    Recently i also started looking at them as we can see deeply inside OS and SQLSERVER. I strongly believe knowladge in this area benifits every DBA.
    i would encorage you to write or put togather On CPU ,Memory and Perticularly DISKIO’S
    I appriciate your help on this..,

  6. Hello Pinal, I would like to add the database name. What would I need to do to modify this query?

    Thanks for your posts. They are very helpful.

    Christal

  7. I noticed that the duration column in your example screen shot is 3,328,125 and on my own tests the number is usually around 1 million, and I’m getting a lot of results for things that take under a second to run…so do we need to change the initial WHERE sqlserver.sql_statement_completed.duration > 1000 to a number closer to 1000000 to limit to things taking longer than a second?

    I’d be interested in hearing about your ideas on what Extended Events we should be turning on..I’ve seen a lot of examples on your and other sites, but not a list of “here are the top 5 must have Extended Events” or something like that.

    Also, should we turn these on and just let them run non-stop, or should we run them while we debug issues and drop them when we are done?

  8. Hi Pinal,

    When I run the above DMV it dose capture the queries running behond 1000 ms but when I run the below query I get an error message, have you seen below error before ??

    Msg 9455, Level 16, State 1, Line 1
    XML parsing: line 7, character 80, illegal qualified name character

    SELECT event_data_XML.value(‘(event/data[1])[1]’,’VARCHAR(100)’) AS Database_ID,
    event_data_XML.value(‘(event/data[2])[1]’,’INT’) AS OBJECT_ID,
    event_data_XML.value(‘(event/data[3])[1]’,’INT’) AS object_type,
    event_data_XML.value(‘(event/data[4])[1]’,’INT’) AS cpu,
    event_data_XML.value(‘(event/data[5])[1]’,’INT’) AS duration,
    event_data_XML.value(‘(event/data[6])[1]’,’INT’) AS reads,
    event_data_XML.value(‘(event/data[7])[1]’,’INT’) AS writes,
    event_data_XML.value(‘(event/action[1])[1]’,’VARCHAR(512)’) AS sql_text,
    event_data_XML.value(‘(event/action[2])[1]’,’VARCHAR(512)’) AS tsql_stack,
    CAST(event_data_XML.value(‘(event/action[2])[1]’,’VARCHAR(512)’) AS XML).value(‘(frame/@handle)[1]’,’VARCHAR(50)’) AS handle
    FROM
    (
    SELECT CAST(event_data AS XML) event_data_XML, *
    FROM sys.fn_xe_file_target_read_file
    (‘D:\Extended_Events\LongRunningQuery*.xet’,
    ‘D:\Extended_Events\LongRunningQuery*.xem’,
    NULL, NULL)) T
    GO

    Thanks,
    Brijesh

  9. Dear Pinal, i find this tutorial is very useful but clearly the handle which query return is not the sql_handle. How can i get the sql_handle to join with sys.dm_exec_query_stats? Is that possible?

  10. Thanks a lot, I was really looking for something like this.
    Where you say ‘c:\LongRunningQuery*.xet’
    I suspect it should be ‘c:\LongRunningQuery*.xel’

  11. Hi Pinal
    We are facing problem with transaction log file of our ERP database. It’s in simple recovery model. We do daily backup. Log file grows very rapidly, we deattach , delete log and create new log to make space in server. Last night when we left office it was 500 MB, today morning we found it 160 GB. How can we get rid of this issue. Pls help
    Thanks

  12. Pingback: SQL SERVER – Weekly Series – Memory Lane – #022 | SQL Server Journey with SQL Authority

  13. Hi Pinal,

    I created the even and I tried to execute the following:
    ALTER EVENT SESSION LongRunningSP ON SERVER
    STATE=START
    GO

    I getting error :
    The target, “CE79811F-1A80-40E1-8F5D-7445A3F375E7.package0.asynchronous_file_target”, encountered a configuration error during initialization. Object cannot be added to the event session.

    Can u please help me with

    This is the Event I created to monitor the SP running more than 30 sec.
    CREATE EVENT SESSION LongRunningSP
    ON SERVER
    — Add event to capture event
    ADD EVENT sqlserver.sql_statement_completed
    (
    — Add action – event property
    ACTION (sqlserver.sql_text, sqlserver.tsql_stack)
    — Predicate – time 30000000milisecond
    WHERE sqlserver.sql_statement_completed.duration > 30000000–microseconds
    )
    ADD TARGET package0.asynchronous_file_target(
    SET filename =’F:\ExtendedEvent\LongRunningSP*.xet’, metadatafile=’F:\ExtendedEvent\LongRunningSP*.xem’)

  14. sir my database goes slow during the peak hours and after restarting the service it runs quite smoothly and then after takes a lot of time to respond how can i remove this problem by clearing the sessions of the database so that i will not restart the service of ms sql.

  15. Morning Pinal,
    I’m from Brazil and I follow your blog a few times, and it has strengthened me a lot in my knowledge, this article and this very Interesting Events Functionality extended SQL, here where I work have much problems with query problem, which take too long to run, on account of the queries are automatically constructed by a third party tool, now this feature can identify and show my supervisors that the problem is in badly constructed queries and not on behalf of the environment.

  16. Hi Padma,
    We can avoid that error “CE79811F-1A80-40E1-8F5D-7445A3F375E7.package0.asynchronous_file_target”, by changing the file path .

  17. hi pinal,
    after collecting all these events and finding the long running queries can we replay the events as in SQL profiler especially we can save the events to disk
    thanx in advance

  18. Pingback: SQL SERVER – Performance Dashboard: Historic Information | Journey to SQL Authority with Pinal Dave

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 )

Twitter picture

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

Facebook photo

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

Google+ photo

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

Connecting to %s