It’s been some time since I started with my first SQL-G Hack, and I think those are precisely the kind of posts you might want to find when searching for a specific problem you have right now.

It’s true that most of the time your answer is posted already in StackOverflow, but that’s another story.

This time I wanted to post this stored procedure that might help people start using more Extended Events, because, to be honest, I still find easier jump onto SQL Profiler when it’s something about checking some sort of activity or what happens in the database when I click that button (and I don’t have any developer handy) in the application.

But the output is not very friendly and once you have a target, you cannot change it, and persisting the information in a file happens to be binary, and using T-SQL you can only see it as XML and everyone hates XML, specially when you have to query it 🙂

So the other day I had to do exactly this and I ended up writing a query that reads from the file, parses the XML and PIVOT the results to get meaningful data to look at. Then I said to myself… never again, so I kept writing to have a more flexible one, so I don’t have to do it again for good.

 
First things first

So I’m going to show you how I did create my Extended Events session to track «What I do» on my SQL Server instance. You may want to customize the output file path and [server_principal_name]

[tsql]
CREATE EVENT SESSION [What I do] ON SERVER

ADD EVENT sqlserver.rpc_completed(SET collect_statement=(1)
ACTION(package0.collect_system_time,sqlserver.client_hostname,sqlserver.database_name,sqlserver.query_plan_hash
,sqlserver.server_principal_name,sqlserver.session_id)),

ADD EVENT sqlserver.sql_statement_completed(SET collect_parameterized_plan_handle=(0),collect_statement=(1)
ACTION(package0.collect_system_time,sqlserver.client_hostname,sqlserver.database_name,sqlserver.query_plan_hash
,sqlserver.server_principal_name,sqlserver.session_id)
WHERE ([sqlserver].[server_principal_name]=N’SQLDoubleG’))

ADD TARGET package0.event_file(SET filename=N’C:\Program Files\Microsoft SQL Server\MSSQL12.MSSQL2014\MSSQL\Log\WhatIdo.xel’)

WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB
,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=ON,STARTUP_STATE=OFF)
GO
[/tsql]

There are a couple of events I’m interested on, [rpc_completed] and [sql_statement_completed], that’s enough for my purpose, but you can choose whatever you feel like, it shouldn’t be any problem if you want to go for something different.

 
The tools

Thankfully SQL Server is full of tools, so good news is there is a function we can call to read the target file, sys.fn_xe_file_target_read_file bad news though is that all the meat inside a XML column.

Once I’ve started my session, I run a few commands.

[tsql]
USE AdventureWorks2014

SELECT TOP 100 * FROM Person.Address

SELECT TOP 100 * FROM Person.Person

SELECT TOP 100 * FROM Production.Product
[/tsql]

I stopped it and find the file in location specified, please note that there is a suffix in addition to the given name.

So if we see the file using the function, it looks like

[tsql]
SELECT *
FROM sys.fn_xe_file_target_read_file(N’C:\Program Files\Microsoft SQL Server\MSSQL12.MSSQL2014\MSSQL\Log\WhatIdo_0_131086770842200000.xel’, null, null, null);
[/tsql]

Not very useful I guess, the information we are looking for is contained in XML

 
The XML

The XML that contains the information we want to analyse might look like the one below.

[xml]
<event name="rpc_completed" package="sqlserver" timestamp="2016-05-25T19:11:24.230Z">
<data name="cpu_time">
<value>0</value>
</data>
<data name="duration">
<value>3633</value>
</data>
<data name="physical_reads">
<value>0</value>
</data>
<data name="logical_reads">
<value>24</value>
</data>
<data name="writes">
<value>0</value>
</data>
<data name="result">
<value>0</value>
<text>OK</text>
</data>
<data name="row_count">
<value>1</value>
</data>
<data name="connection_reset_option">
<value>0</value>
<text>None</text>
</data>
<data name="object_name">
<value>sp_executesql</value>
</data>
<data name="statement">
<value>exec sp_executesql N’SELECT
session.name AS [Name],
»XEStore[@Name=» + quotename(CAST(SERVERPROPERTY(N»ServerName») AS sysname),»»»») + »]» + »/Session[@Name=» + quotename(session.name,»»»») + »]» AS [Urn],
session.startup_state AS [AutoStart],
running.create_time AS [StartTime],
(CASE WHEN (running.create_time IS NULL) THEN 0 ELSE 1 END) AS [IsRunning]
FROM
sys.server_event_sessions AS session
LEFT OUTER JOIN sys.dm_xe_sessions AS running ON running.name = session.name
WHERE
(session.name=@_msparam_0)and((CAST(SERVERPROPERTY(N»ServerName») AS sysname)=@_msparam_1))
ORDER BY
[Name] ASC’,N’@_msparam_0 nvarchar(4000),@_msparam_1 nvarchar(4000)’,@_msparam_0=N’What I do’,@_msparam_1=N’DESKTOP-P6AOTMB\MSSQL2014′</value>
</data>
<data name="data_stream">
<value />
</data>
<data name="output_parameters">
<value />
</data>
<action name="session_id" package="sqlserver">
<value>51</value>
</action>
<action name="server_principal_name" package="sqlserver">
<value>SQLDoubleG</value>
</action>
<action name="query_plan_hash" package="sqlserver">
<value>0</value>
</action>
<action name="database_name" package="sqlserver">
<value>master</value>
</action>
<action name="client_hostname" package="sqlserver">
<value>DESKTOP-P6AOTMB</value>
</action>
<action name="collect_system_time" package="package0">
<value>2016-05-25T19:11:24.229Z</value>
</action>
<action name="attach_activity_id_xfer" package="package0">
<value>B05B6BEA-DA76-4283-94EC-4EEAAF43EA87-0</value>
</action>
<action name="attach_activity_id" package="package0">
<value>33E553E3-FF64-4A8D-BD2F-1C061195AB96-1</value>
</action>
</event>
[/xml]

Using SQL Server, we can query our XML column to get all the juice, but first we have to convert it to XML because it comes as plain text. So we can use a temporary table to do the trick.

[tsql]
IF OBJECT_ID(‘tempdb..#ExEvent’) IS NOT NULL DROP TABLE #ExEvent

SELECT IDENTITY(INT,1,1) AS RowId, object_name AS event_name, CONVERT(XML,event_data) AS event_data
INTO #ExEvent
FROM sys.fn_xe_file_target_read_file(N’C:\Program Files\Microsoft SQL Server\MSSQL12.MSSQL2014\MSSQL\Log\WhatIdo_0_131086770842200000.xel’, null, null, null);
[/tsql]

 
Parsing the XML

Once we have the table, we can start querying the XML to extract all that info
[tsql]
SELECT RowId
, event_name
, T2.Loc.query(‘.’).value(‘(/action/@name)[1]’, ‘varchar(max)’)AS att_name
, T2.Loc.query(‘.’).value(‘(/action/value)[1]’, ‘varchar(max)’)AS att_value
FROM #ExEvent
CROSS APPLY event_data.nodes(‘/event/action’) as T2(Loc)
WHERE T2.Loc.query(‘.’).value(‘(/action/@name)[1]’, ‘varchar(max)’)
IN (‘client_hostname’, ‘collect_system_time’, ‘database_name’, ‘query_plan_hash’
, ‘server_principal_name’, ‘session_id’)

[/tsql]

I just picked up a few columns I am interested on, but there are some others you can check.

The thing is that as you’ve seen above there are 2 different elements in the XML, the <data> and <action>, so I’ll have to do more magic to get all of them.

[tsql]
SELECT RowId
, event_name
, T3.Loc.query(‘.’).value(‘(/data/@name)[1]’, ‘varchar(max)’) AS att_name
, T3.Loc.query(‘.’).value(‘(/data/value)[1]’, ‘varchar(max)’) AS att_value
FROM #ExEvent
CROSS APPLY event_data.nodes(‘/event/data’) as T3(Loc)
WHERE T3.Loc.query(‘.’).value(‘(/data/@name)[1]’, ‘varchar(max)’)
IN (‘collect_statement’, ‘connection_reset_option’, ‘cpu_time’, ‘data_stream’, ‘duration’
, ‘last_row_count’, ‘line_number’, ‘logical_reads’, ‘object_name’, ‘offset’
, ‘offset_end’, ‘output_parameters’, ‘parameterized_plan_handle’, ‘physical_reads’
, ‘result’, ‘row_count’, ‘statement’, ‘writes’)
[/tsql]

Each of those queries above will return a list of actions and events respectively along the current value for each time the event was triggered during the session.

Still not very useful, I’d rather see this like one event one line, so another top favourite for each DBA, PIVOT!!! there we go

[tsql]
SELECT RowId, event_name, [client_hostname], [collect_system_time], [database_name], [query_plan_hash], [server_principal_name], [session_id]
FROM (
SELECT RowId
, event_name
, T2.Loc.query(‘.’).value(‘(/action/@name)[1]’, ‘varchar(max)’)AS att_name
, T2.Loc.query(‘.’).value(‘(/action/value)[1]’, ‘varchar(max)’)AS att_value
FROM #ExEvent
CROSS APPLY event_data.nodes(‘/event/action’) as T2(Loc)
WHERE T2.Loc.query(‘.’).value(‘(/action/@name)[1]’, ‘varchar(max)’)
IN (‘client_hostname’, ‘collect_system_time’, ‘database_name’, ‘query_plan_hash’, ‘server_principal_name’, ‘session_id’)
) AS SourceTable
PIVOT(
MAX(att_value)
FOR att_name IN ([client_hostname], [collect_system_time], [database_name], [query_plan_hash], [server_principal_name], [session_id])
) AS PivotTable
[/tsql]

That looks much better, thanks!

 
Final output

But to get all information I have used 2 different queries, so now if you were wondering why I generated an IDENTITY column, this is why, so I can join both, <data> and <action> and generate a unique row per event in the file.

Let’s go for it!

[tsql]
SELECT ISNULL(t_action.RowId, t_data.RowId) AS RowId
, ISNULL(t_action.event_name, t_data.event_name) AS event_name
, t_action.[client_hostname], t_action.[collect_system_time], t_action.[database_name], t_action.[query_plan_hash], t_action.[server_principal_name], t_action.[session_id]
, t_data.[collect_statement], t_data.[connection_reset_option], t_data.[cpu_time], t_data.[data_stream], t_data.[duration], t_data.[last_row_count], t_data.[line_number], t_data.[logical_reads], t_data.[object_name], t_data.[offset], t_data.[offset_end], t_data.[output_parameters], t_data.[parameterized_plan_handle], t_data.[physical_reads], t_data.[result], t_data.[row_count], t_data.[statement], t_data.[writes]
FROM (
SELECT RowId, event_name, [client_hostname], [collect_system_time], [database_name], [query_plan_hash], [server_principal_name], [session_id]
FROM (
SELECT RowId
, event_name
, T2.Loc.query(‘.’).value(‘(/action/@name)[1]’, ‘varchar(max)’)AS att_name
, T2.Loc.query(‘.’).value(‘(/action/value)[1]’, ‘varchar(max)’)AS att_value
FROM #ExEvent
CROSS APPLY event_data.nodes(‘/event/action’) as T2(Loc)
WHERE T2.Loc.query(‘.’).value(‘(/action/@name)[1]’, ‘varchar(max)’)
IN (‘client_hostname’, ‘collect_system_time’, ‘database_name’, ‘query_plan_hash’, ‘server_principal_name’, ‘session_id’)
) AS SourceTable
PIVOT(
MAX(att_value)
FOR att_name IN ([client_hostname], [collect_system_time], [database_name], [query_plan_hash], [server_principal_name], [session_id])
) AS PivotTable
) AS t_action

— Full outer because it might be no events selected only the payload
FULL OUTER JOIN (
SELECT RowId, event_name, [collect_statement], [connection_reset_option], [cpu_time], [data_stream], [duration], [last_row_count], [line_number], [logical_reads], [object_name], [offset], [offset_end], [output_parameters], [parameterized_plan_handle], [physical_reads], [result], [row_count], [statement], [writes]
FROM (
SELECT RowId
, event_name
, T3.Loc.query(‘.’).value(‘(/data/@name)[1]’, ‘varchar(max)’) AS att_name
, T3.Loc.query(‘.’).value(‘(/data/value)[1]’, ‘varchar(max)’) AS att_value

FROM #ExEvent
CROSS APPLY event_data.nodes(‘/event/data’) as T3(Loc)
WHERE T3.Loc.query(‘.’).value(‘(/data/@name)[1]’, ‘varchar(max)’)
IN (‘collect_statement’, ‘connection_reset_option’, ‘cpu_time’, ‘data_stream’, ‘duration’, ‘last_row_count’, ‘line_number’, ‘logical_reads’, ‘object_name’, ‘offset’, ‘offset_end’, ‘output_parameters’, ‘parameterized_plan_handle’, ‘physical_reads’, ‘result’, ‘row_count’, ‘statement’, ‘writes’)
) AS SourceTable
PIVOT (
MAX(att_value)
FOR att_name IN ([collect_statement], [connection_reset_option], [cpu_time], [data_stream], [duration], [last_row_count], [line_number], [logical_reads], [object_name], [offset], [offset_end], [output_parameters], [parameterized_plan_handle], [physical_reads], [result], [row_count], [statement], [writes])
) AS PivotTable

) AS t_data
ON t_data.RowId = t_action.RowId
[/tsql]

And finally we can get some meaningful info, just one line per event and all the columns where had defined for the session.

Yes! that works!

 
The SQL-G Hack!

Hopefully you have read all the process through and you have now a better understanding of how painful it was. But that’s what this post is for, to relieve the pain 🙂

Using DMV’s we can see how any session is defined hence dynamically we can do all the hard work and leave for us just analysing the results. Cool, innit?

[tsql]
USE [DBA]
GO
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
IF OBJECT_ID(‘dbo.sqlg_ExtendedEventFileReader’) IS NULL EXECUTE sp_executesql N’CREATE PROCEDURE dbo.sqlg_ExtendedEventFileReader AS RETURN’
GO
— =============================================
— Author: Raul Gonzalez @SQLDoubleG
— Create date: 25/05/2016
— Description: Returns the content of a Extended Event target file in a table format according to the current definition of the session
—
— Remarks:
— – The session must exist in the server and so must the file in a place we can access
— – Depending on the amount of data this process may take very long, it is recommended not to use in production systems
— – You can offload this task by generating the query using the parameter @debugging = 1 and copying the file to another server.
—
— Parameters:
— – @sessionName -> name of the extended event session
— – @filePath -> full path (including name) of the target file
— – @debugging -> will print the statement or execute it
—
— Log History:
— 25/05/2016 RAG – Created
— 31/03/2017 RAG – Allow ‘xml_deadlock_report’ events to be returned in a way you can copy/paste and save as (.xdl) file
— for further analysis.
— 07/06/2017 RAG – Added event_timestamp column
— 08/06/2017 RAG – Return all events that return XML in XML format
—
— Copyright: (C) 2016 Raul Gonzalez (@SQLDoubleG https://www.sqldoubleg.com)
—
— THIS CODE AND INFORMATION ARE PROVIDED "AS IS" WITHOUT WARRANTY OF
— ANY KIND, EITHER EXPRESSED OR IMPLIED, INCLUDING BUT NOT LIMITED
— TO THE IMPLIED WARRANTIES OF MERCHANTABILITY AND/OR FITNESS FOR A
— PARTICULAR PURPOSE.
—
— THE AUTHOR SHALL NOT BE LIABLE TO YOU OR ANY THIRD PARTY FOR ANY INDIRECT,
— SPECIAL, INCIDENTAL, PUNITIVE, COVER, OR CONSEQUENTIAL DAMAGES OF ANY KIND
—
— YOU MAY ALTER THIS CODE FOR YOUR OWN *NON-COMMERCIAL* PURPOSES. YOU MAY
— REPUBLISH ALTERED CODE AS LONG AS YOU INCLUDE THIS COPYRIGHT AND GIVE DUE CREDIT.
—
— =============================================
ALTER PROCEDURE dbo.sqlg_ExtendedEventFileReader
@sessionName SYSNAME
, @filePath NVARCHAR(512)
, @debugging BIT = 0 — Set to 0 to run the query, otherwise PRINT the statement
AS

DECLARE @sql NVARCHAR(MAX)

DECLARE @actionsList NVARCHAR(MAX)
DECLARE @actionsListFilter NVARCHAR(MAX)
DECLARE @actionsListColumns NVARCHAR(MAX)

DECLARE @eventsList NVARCHAR(MAX)
DECLARE @eventsListFilter NVARCHAR(MAX)
DECLARE @eventsListColumns NVARCHAR(MAX)

— Get actions from the Session
SET @actionsList = (SELECT STUFF((SELECT DISTINCT ‘, ‘ + QUOTENAME(a.name)
FROM sys.server_event_sessions AS s
LEFT JOIN sys.server_event_session_events AS e
ON e.event_session_id = s.event_session_id
INNER JOIN sys.server_event_session_actions AS a
ON a.event_id = e.event_id
AND e.event_session_id = a.event_session_id
WHERE s.name = @sessionName
FOR XML PATH(»)), 1, 2, »))

SET @actionsListFilter = REPLACE(REPLACE(@actionsList, ‘[‘, »»), ‘]’, »»)
SET @actionsListColumns = REPLACE(@actionsList, ‘[‘, ‘t_action.[‘)

— Get Payload
— This to return events that return XML in XML format, just for the final query
SET @eventsListColumns = (SELECT STUFF(
(SELECT DISTINCT ‘, ‘ +
CASE WHEN c.type_name = ‘XML’ THEN ‘CONVERT(XML, ‘ + QUOTENAME(c.name) + ‘) AS ‘ + QUOTENAME(c.name)
ELSE ‘t_data.’ + QUOTENAME(c.name)
END
FROM sys.server_event_sessions AS s
LEFT JOIN sys.server_event_session_events AS e
ON e.event_session_id = s.event_session_id
LEFT JOIN sys.dm_xe_objects AS o
ON o.name = e.name
LEFT JOIN sys.dm_xe_object_columns AS c
ON c.object_name = o.name
WHERE s.name = @sessionName
AND c.column_type <> ‘readonly’
AND ISNULL(column_value, ‘true’) = ‘true’
FOR XML PATH(»)), 1, 2, »))

SET @eventsList = (SELECT STUFF(
(SELECT DISTINCT ‘, ‘ + QUOTENAME(c.name)
FROM sys.server_event_sessions AS s
LEFT JOIN sys.server_event_session_events AS e
ON e.event_session_id = s.event_session_id
LEFT JOIN sys.dm_xe_objects AS o
ON o.name = e.name
LEFT JOIN sys.dm_xe_object_columns AS c
ON c.object_name = o.name
WHERE s.name = @sessionName
AND c.column_type <> ‘readonly’
AND ISNULL(column_value, ‘true’) = ‘true’
FOR XML PATH(»)), 1, 2, »))

SET @eventsListFilter = REPLACE(REPLACE(@eventsList, ‘[‘, »»), ‘]’, »»)

SET @sql = N’

IF OBJECT_ID(»tempdb..#ExEvent») IS NOT NULL DROP TABLE #ExEvent

SELECT IDENTITY(INT,1,1) AS RowId, object_name AS event_name, CONVERT(XML,event_data) AS event_data
INTO #ExEvent
FROM sys.fn_xe_file_target_read_file(N»’ + @filePath + »’, null, null, null);

–=======================================================================================================
— Usually here I would remove events I am not interested on, because the next query can take very long
—
–SELECT TOP 100 * FROM #ExEvent ORDER BY event_name
—
— DELETE #ExEvent
–WHERE event_name [NOT] IN (N»rpc_completed»)
–=======================================================================================================

SELECT ISNULL(t_action.RowId, t_data.RowId) AS RowId
, ISNULL(t_action.event_name, t_data.event_name) AS event_name
, ISNULL(t_action.event_timestamp, t_data.event_timestamp) AS event_timestamp
, ‘ + @actionsListColumns + N’
, ‘ + @eventsListColumns + N’
FROM (
SELECT RowId, event_name, event_timestamp, ‘ + @actionsList + N’
FROM (
SELECT RowId
, event_name
, T1.Loc.query(».»).value(»(/event/@timestamp)[1]», »varchar(max)») AS event_timestamp
, T2.Loc.query(».»).value(»(/action/@name)[1]», »varchar(max)»)AS att_name
, T2.Loc.query(».»).value(»(/action/value)[1]», »varchar(max)»)AS att_value
FROM #ExEvent
CROSS APPLY event_data.nodes(»/event») as T1(Loc)
CROSS APPLY event_data.nodes(»/event/action») as T2(Loc)
WHERE T2.Loc.query(».»).value(»(/action/@name)[1]», »varchar(max)»)
IN (‘ + @actionsListFilter + N’)
) AS SourceTable
PIVOT(
MAX(att_value)
FOR att_name IN (‘ + @actionsList + N’)
) AS PivotTable
) AS t_action

— Full outer because it might be no events selected only the payload
FULL OUTER JOIN (
SELECT RowId, event_name, event_timestamp, ‘ + @eventsList + N’
FROM (
SELECT RowId
, event_name
, T1.Loc.query(».»).value(»(/event/@timestamp)[1]», »varchar(max)») AS event_timestamp
, T3.Loc.query(».»).value(»(/data/@name)[1]», »varchar(max)») AS att_name
, CASE
— deadlock report in xml to allow it to be saved as xdl
WHEN event_name = »xml_deadlock_report»
THEN CONVERT(NVARCHAR(MAX), event_data.query(»/event/data/value/deadlock»))
— rest of events that return xml
WHEN event_name IN (SELECT object_name FROM sys.dm_xe_object_columns
WHERE type_name = »xml» AND name NOT IN (»xml_deadlock_report»))
THEN CONVERT(NVARCHAR(MAX), event_data.query(»/event»))
— rest of events
ELSE T3.Loc.query(».»).value(»(/data/value)[1]», »varchar(max)»)
END AS att_value
FROM #ExEvent
CROSS APPLY event_data.nodes(»/event») as T1(Loc)
CROSS APPLY event_data.nodes(»/event/data») as T3(Loc)
WHERE T3.Loc.query(».»).value(»(/data/@name)[1]», »varchar(max)»)
IN (‘ + @eventsListFilter + N’)
) AS SourceTable
PIVOT (
MAX(att_value)
FOR att_name IN (‘ + @eventsList + N’)
) AS PivotTable
) AS t_data
ON t_data.RowId = t_action.RowId
‘

IF @debugging = 1
SELECT CONVERT(XML, @sql)
ELSE
EXECUTE sp_executesql @sql
GO
[/tsql]

And that was all folks! Hope you find it useful and any feedback is always welcome.

Facebook

Google

Twitter

Linkedin

Reddit