Mi rendo conto che questo problema è già stato risolto, ma ero interessato a come risolverlo utilizzando gli eventi estesi di SQL Server 2008. Questo è il mio primo gioco con XEvents, quindi sono sicuro che c'è molto da migliorare!
Script per configurare il database di prova
CREATE TABLE [dbo].[TableWithMysteryUpdate](
[Period] [int] NOT NULL,
[ColumnThatWillBeUpdated] [int] NOT NULL
) ON [PRIMARY]
GO
INSERT [dbo].[TableWithMysteryUpdate] ([Period], [ColumnThatWillBeUpdated]) VALUES (1, 20)
INSERT [dbo].[TableWithMysteryUpdate] ([Period], [ColumnThatWillBeUpdated]) VALUES (2, 23)
GO
CREATE TABLE [dbo].[TestTable](
[foo] [int] IDENTITY(1,1) NOT NULL,
[bar] [nchar](10) NOT NULL,
CONSTRAINT [PK_TestTable] PRIMARY KEY CLUSTERED
(
[foo] ASC
)
)
GO
CREATE TRIGGER [dbo].[triggerCausingMysteryUpdate]
ON [dbo].[TestTable]
AFTER INSERT
AS
BEGIN
SET NOCOUNT ON;
UPDATE [dbo].[TableWithMysteryUpdate]
SET [Period] = [Period]+1
END
GO
CREATE PROCEDURE [dbo].[Proc4]
AS
BEGIN
INSERT INTO [dbo].[TestTable]
(
[bar])
VALUES
('Test')
END
GO
CREATE PROCEDURE [dbo].[Proc3]
AS
BEGIN
EXEC dbo.Proc4
END
GO
CREATE PROCEDURE [dbo].[Proc2]
AS
BEGIN
EXEC dbo.Proc3
END
GO
CREATE PROCEDURE [dbo].[Proc1]
AS
BEGIN
EXEC dbo.Proc2
END
Quindi lo scenario è che TableWithMysteryUpdate è in fase di aggiornamento ma non sono sicuro di cosa. Aggiungerò un trigger di aggiornamento che non fa nulla per poter filtrare su questo oggetto.
CREATE TRIGGER [dbo].[triggerAfterUpdate]
ON [dbo].[TableWithMysteryUpdate]
AFTER UPDATE
AS
BEGIN
SET NOCOUNT ON;
END
Quindi esegui lo script per creare la sessione XEvents, avvia la procedura che alla fine ridurrà lo stack di chiamate provocando l'aggiornamento e quindi interromperà la sessione.
USE TestDB
DECLARE @DynSql nvarchar(max)
SET @DynSql = '
IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name=''test_trace'')
DROP EVENT SESSION [test_trace] ON SERVER;
CREATE EVENT SESSION [test_trace]
ON SERVER
ADD EVENT sqlserver.sql_statement_completed(
ACTION (package0.callstack, sqlserver.session_id, sqlserver.sql_text, sqlserver.tsql_stack)
WHERE (object_id = ' + cast(object_id('[dbo].[triggerAfterUpdate]') as varchar(10)) + ')
)
,
ADD EVENT sqlserver.sp_statement_completed(
ACTION (package0.callstack, sqlserver.session_id, sqlserver.sql_text, sqlserver.tsql_stack)
WHERE (object_id = ' + cast(object_id('[dbo].[triggerAfterUpdate]') as varchar(10)) + ')
)
ADD TARGET package0.asynchronous_file_target
(set filename = ''c:\temp\test_trace.xel'' , metadatafile = ''c:\temp\test_trace.xem'')
ALTER EVENT SESSION [test_trace] ON SERVER STATE = START
'
EXEC sp_executesql @DynSql
GO
EXEC dbo.Proc1
GO
ALTER EVENT SESSION [test_trace] ON SERVER STATE = STOP
I dati di traccia possono essere letti con
SELECT CONVERT (XML, event_data) AS data
FROM sys.fn_xe_file_target_read_file ('C:\Temp\test_trace*.xel', 'C:\Temp\test_trace*.xem', NULL, NULL)
La parte dello stack di chiamate è
<action name="tsql_stack" package="sqlserver">
<value><frame level='1' handle='0x03000800E8EA0D0612E4EB00A59D00000000000000000000' line='6' offsetStart='228' offsetEnd='264'/>
<frame level='2' handle='0x03000800921155002C81E700A59D00000000000000000000' line='8' offsetStart='258' offsetEnd='398'/>
<frame level='3' handle='0x03000800CB3549012F81E700A59D00000100000000000000' line='5' offsetStart='90' offsetEnd='284'/>
<frame level='4' handle='0x03000800045A3D022F81E700A59D00000100000000000000' line='5' offsetStart='90' offsetEnd='120'/>
<frame level='5' handle='0x030008003D7E31033081E700A59D00000100000000000000' line='5' offsetStart='90' offsetEnd='120'/>
<frame level='6' handle='0x0300080076A225043081E700A59D00000100000000000000' line='5' offsetStart='90' offsetEnd='120'/>
<frame level='7' handle='0x010008002E775203603D9A0D000000000000000000000000' line='2' offsetStart='4' offsetEnd='-1'/></value>
<text />
</action>
Unirsi ai DMV
WITH CapturedResults AS
( SELECT data.value ( '(/event/@timestamp)[1]', 'DATETIME') AS [TIME],
data.value ( '(/event/data[@name=''cpu'']/value)[1]', 'INT') AS [CPU (ms)],
CONVERT (FLOAT, data.value ('(/event/data[@name=''duration'']/value)[1]', 'BIGINT')) / 1000000 AS [Duration (s)],
data.value ( '(/event/action[@name=''sql_text'']/value)[1]', 'VARCHAR(MAX)') AS [SQL STATEMENT],
CAST(data.value('(/event/action[@name="tsql_stack"]/value)[1]','varchar(MAX)') AS XML) AS [stack_xml]
FROM (SELECT CONVERT (XML, event_data) AS data
FROM sys.fn_xe_file_target_read_file ('C:\Temp\test_trace*.xel', 'C:\Temp\test_trace*.xem', NULL, NULL)
)
entries
)
,
StackData AS
( SELECT frame_xml.value('(./@level)', 'int') AS [frame_level],
frame_xml.value('(./@handle)', 'varchar(MAX)') AS [sql_handle],
frame_xml.value('(./@offsetStart)', 'int') AS [offset_start],
frame_xml.value('(./@offsetEnd)', 'int') AS [offset_end]
FROM CapturedResults CROSS APPLY stack_xml.nodes('//frame') N (frame_xml)
)
SELECT sd.frame_level,
object_name(st.objectid, st.dbid) AS ObjectName,
SUBSTRING(st.text, (sd.offset_start/2)+1, ((
CASE sd.offset_end
WHEN -1
THEN DATALENGTH(st.text)
ELSE sd.offset_end
END - sd.offset_start)/2) + 1) AS statement_text,
qp.query_plan,
qs2.creation_time,
qs2.last_execution_time,
qs2.execution_count
FROM StackData AS sd CROSS APPLY sys.dm_exec_sql_text(CONVERT(VARBINARY(MAX),sd.sql_handle,1)) AS st
LEFT OUTER JOIN sys.dm_exec_query_stats qs2
ON qs2.sql_handle = CONVERT(VARBINARY(MAX),sd.sql_handle,1) OUTER APPLY sys.dm_exec_query_plan(CONVERT(VARBINARY(MAX),qs2.plan_handle,1)) AS qp
fornisce risultati (mostrando l'intero stack di chiamate tsql)
