SQLServerCentral Article

Performance Tuning Using Extended Events: Part 2

,

Performance tuning is the process of analyzing query plans, execution plans, indexes, partitioning, etc. and finding ways to reduce the time a query takes or reduce resource usage by that query. There are four events that I found can help you to identify queries that can be performance tuned. They are deadlocks, application aborts, blocking, and long running queries.

In Part 1 of this series we looked at building these 4 Extended Event sessions. In this article, Part 2, we look at shredding the XML from the Extended Event (XE) sessions.

The event_GetEventData Stored Procedure

I have created a stored procedure that shreds the XML for these XE sessions and displays the data as record sets and attached it to this article. The stored procedure “event_GetEventData” has parameters that allow you to define the XE session data you want to look at and the time range for that data. It also allows you to filter out lists of error numbers, error messages, and application names. Below I break down the stored procedure and explain its parts. It is best to review the stored procedure while reading this article.

Getting the File Path

The first section in the stored procedure is focused on getting the path to the saved data. To retrieve data from an Extended Events session we first need to get the path to the file(s) where it’s stored. The statements below use the dm_xe_sessions and dm_xe_session_targets to collect and shred the XML column value that contains the base path to the file and then creating a “wildcard” path that will be used to get the data.

Looking at the subquery we can see that we are filtering dm_xe_sessions down to the event name that was passed in, i.e. “Deadlocks”, and shred the XML returned in the target_data column. (see example XML below). We then replace the end of the file name with “_*xel”. This tells the Extended Event file reader, explained below, that we are looking for all files that match this pattern. For example, if the base path or first file for our XE session is “F:logDeadlocks_0_131318679767020000.xel” then our wildcard path will be “F:logDeadlocks_0_*xel”. So all files that start with “Deadlocks_0_” and end with “xel” will be included. This will allow us to read all 3 of the rollover files defined in the XE session (see Part 1).

--GET PATH TO EVENT FILE -----------------------------
DECLARE @filePath sysname
SELECT @filePath = n.value('(@name)[1]','varchar(255)')
FROM (SELECT CAST(t.target_data AS XML) target_data
       FROM sys.dm_xe_sessions s
              INNER JOIN sys.dm_xe_session_targets t ON t.event_session_address = s.address
       WHERE s.name = CASE WHEN @eventName = 'BlockingReport' THEN 'Blocking' ELSE @eventName END
              AND t.target_name = N'event_file') AS tab
              CROSS APPLY [target_data].[nodes]('EventFileTarget/File') AS 
([n]); SET @filePath = LEFT(@filePath,LEN(@filePath) - CHARINDEX('_',REVERSE(@filePath))) + '_*xel' ------------------------------------------------------

target_data XML example:

<EventFileTarget truncated="0">
  <Buffers logged="5" dropped="0" />
  <File name="f:fakepathMSSQL10_50.fakeMSSQLLogDeadlocks_0_131318679767020000.xel" />
</EventFileTarget>

Deadlocks

The Deadlocks portion of the stored procedure collects information about the deadlocks including processes involved, victims, lock types, and locks held & requested by each process. It then joins all these sections together to display a record set of the deadlocks.

We start by declaring a series of temporary tables to hold the data for each section of the deadlock XML. These temporary tables are then joined at the bottom of the section to display the final results. The temporary tables are:

#VICTIM

Contains the process id for each deadlock victim defined.

#KEY_LOCK

Used specifically for deadlocks on key indexes deadlocks. Contains information about the key lock including the linking HObtId (Heap or B-Tree ID), database name, object name, index name, and the lock type of the owner process.

#PAGE_LOCK

Used specifically for deadlocks on pages. Contains information about the page lock including the file id, page id, database name, object name, associated object id, and the lock type of the owner process.

#PARTITION_LOCK

Used specifically for deadlocks on partitions. Contains information about the partition lock including the locked partition, database name, object name, associated object id, and the lock type of the owner process.

#OWNER

This table is populated for all deadlock types except “Exchange Event” (explained below). It contains information about the lock owners and lock waiters and includes the linking HObtId (Heap or B-Tree ID), request type (wait, convert, etc.), lock type requested, and process id used for linking to the #PROCESS table.

#OWNER2

This table is specifically used for the “Exchange Event” (explained below) type of deadlock. It contains information about the wait type and owner and has linking information as well.

#PROCESS

This table is populated for all deadlock types. It contains information about the process being executed and includes the wait resource, transaction name, lock mode, status, transaction count, client application, host name, login name, isolation level, database name, procedure name, and buffers that include the text being executed.

The Cursor

Below the declaration of the temporary tables a cursor is defined to loop through each of the files in the EE Deadlock session. The XE function fn_xe_file_target_read_file returns a row for each file it finds matching the file path populated above. Each row contains a column called event_data. The event_data column contains an XML document with all the session data, which is then stored in the @XML variable. This same procedure is used in all subsequent sections to get the XE session data, except on some no cursor is used.

DECLARE curXML CURSOR FAST_FORWARD LOCAL FOR
 SELECT CAST(event_data AS XML) FROM sys.fn_xe_file_target_read_file(@filePath,NULL,NULL,NULL)
OPEN curXML
FETCH NEXT FROM curXML INTO @XML

Inside the cursor data is collected from each of the sections in the XML. These include the Process List, Victim List, Owner/Waiter List, and Lock List. There are several different type of locks that can be defined in the lock list. The ones I have included are the Key Lock, Page Lock, Partition Lock, and Exchange Event Lock.

The Process List

The process list section of the XML contains information about each process that was involved in the deadlock and is inserted into the #PROCESS temporary table. The path to this data is located at “event/data/value/deadlock/process-list/process”.

The Victim List

The victim list is the process or processes that SQL declared as the victim of the deadlock and killed. The victim list is simply a list of process ids and will be joined at the end with the process list. The victim list is located at “event/data/value/deadlock/victim-list/victimProcess”.

Lock Types

Depending on the lock type only one of the follow 4 sections (Exchange Event, Key Lock, Page Lock, or Partition Lock) will be populated. However, for each of these sections the Owner/Waiter temporary table will be populated and for the Exchange Event this is the only one.

The Exchange Event List

The Exchange Event deadlock is unique in that no process is listed as being the victim. These deadlocks can be caused by parallelism. Read Bart Duncan’s article about this here: https://blogs.msdn.microsoft.com/bartd/2008/09/24/todays-annoyingly-unwieldy-term-intra-query-parallel-thread-deadlocks/ .The Exchange Event list is inserted into the #OWNER2 table and is located in the XML at “event/data/value/deadlock/resource-list/exchangeEvent”.

The Key Lock List

The Key Lock section of the XML contains information about the primary/foreign key locks being held/requested including process id, owner mode and database, object, & index names. The Key Lock list is inserted into the #KEY_LOCK temporary table and is located in the XML at “event/data/value/deadlock/resource-list/keylock”. Also populated in this section is owner/waiter information. This information is inserted into the #OWNER temporary table and includes the process id, lock type, and lock requested. This data is located in the XML within the Key Lock path at “owner-list/owner” and “waiter-list/waiter”.

The Page Lock List

The Page Lock section of the XML contains information about the locks being held/requested on data file pages. The information includes process id, file id, page id, database name, object name and associated object id. The Page Lock information is inserted into the #PAGE_LOCK temporary tables and is located in the XML at “event/data/value/deadlock/resource-list/pagelock”. Also populated in this section is owner/waiter information. This information is inserted into the #OWNER temporary table and includes the process id, lock type, and lock requested. This data is located in the XML within the Page Lock path at “owner-list/owner” and “waiter-list/waiter”.

The Partition Lock List

The Partition Lock section of the XML contains information about the schema locks being held/requested. The information includes process id, object id, database name, object name, and associated object name. The Partition Lock information is inserted into the #PARTITION_LOCK temporary tables and is located in the XML at “event/data/value/deadlock/resource-list/objectlock”. Also populated in this section is owner/waiter information. This information is inserted into the #OWNER temporary table and includes the process id, lock type, and lock requested. This data is located in the XML within the Partition Lock path at “owner-list/owner” and “waiter-list/waiter”.

Displaying the Results

The results that display are determined by the lock type. The first column “TimeStamp_...” indicates the lock type, i.e. NoVictim, Keylock, PageLock, PartitionLock. For all lock types, except Exchange Event, the lock table is joined with the #OWNER, #PROCESS, & #VICTIM tables. For the Exchange Event lock type only the #OWNER2 & #PROCESS tables are joined together. The resulting displayed record set contains information about the lock type, SQL being run, deadlock victims, transaction count, isolation level, wait resource and more.

Application Aborts (A.K.A. Time outs)

The “Time Out” section of the stored procedure collects information about the application aborts that have occurred. It includes CPU, duration, read/write information, database/client/user name, and SQL statement. Unlike the deadlock portion the Time Out portion collects data from all the XE files in a set instead of a cursor. This section also allows filtering by client application name and time stamp. The parsed XML is inserted into the #TO_EVENTS temporary tables and then displayed filtering for the selected time range. All information for the Time Outs is stored in the “data” and “action” nodes of the XML.

Blocking

For the Blocking section a cursor is used to loop through the XE files. This is done because blocking information has to be grouped into individual record sets that contain blocked & blocking data. The script below unions together the information for related blocked and blocking sessions and displays information including which process was blocked, what resource is being blocked, the wait type, and isolation level for each process. The data is pulled from 'event/data[@name="blocked_process"]/value/blocked-process-report/blocking-process/process' and 'event/data[@name="blocked_process"]/value/blocked-process-report/blocked-process/process' and inserted into the #BLOCKING temporary table. Another cursor is used to display the data. Once again this is to group the data together by blocking session. The query used for the cursor (SELECT DISTINCT [TimeStamp] FROM #BLOCKING ORDER BY [TimeStamp]) allows for grouping the data together by time stamp.

Long Running Queries

The Long Running Queries XE session is designed to capture all query calls that exceed a specific duration. In this case it has been set to 25 seconds and is called “DurationGT25Seconds”. The DurationGT25Seconds section collects information like cpu time, duration, reads/writes, database name, client application name, NT user name and SQL statement. All information for the DurationGT25Seconds is stored in the “data” and “action” nodes of the XML. This section also allows filtering by client application name and time stamp.

Errors

Also found in this stored procedure is a section for collecting data about errors. Although not listed above as one of the four important extended event sessions it is useful for confirming issues found in the other section and in general is useful to review on occasion or during an issue. The Errors record set that is returned contains sufficient information to allow for the identification of the error and its source. It also allows for easy synchronizing of events with the other XE sessions above.

Using this stored procedure we can see how to gather important information about what performance issues may be occurring with our queries. In the next part we'll look at building an aggregate report and analyzing the results.

Resources

Rate

4.64 (11)

You rated this post out of 5. Change rating

Share

Share

Rate

4.64 (11)

You rated this post out of 5. Change rating