Extended events query plan

I need to cover few scenarios connected to SQL statements or procedures and their Execution plans and IO statistics:

  • To monitor stored procedures performance running on server
  • To get execution plan from procedures not easily accessible from management studio
    • Procedures called from service broker applications
    • Huge nested level of SQL statement
  • Compare batches in testing labs

I decided to use Extended Events as lightweight solution for such a scenarios.

I found following tree evens very usefull to get requested data.

  • sqlserver.query_post_execution_showplan
    • to get execution plan of running query
  • sqlserver.sql_statement_completed
    • to get IO informations regarding executed query
  • sqlserver.sp_statement_completed
    • to get IO informations regarding executed stored procedure¨

Bellow you can find simple script creating above mentioned events with resctriction to concreted session and database.

CREATE EVENT SESSION Test ON SERVER
ADD EVENT sqlserver.query_post_execution_showplan -- ,
                         (
                         ACTION (sqlserver.database_name,
                                 sqlserver.plan_handle,
                                 sqlserver.query_plan_hash,
                                 sqlserver.session_id,
                                 sqlserver.sql_text,
                                 sqlserver.username)
                            WHERE
                                         sqlserver.session_id=58
                                         AND sqlserver.database_id = 8
                          )
,
ADD EVENT sqlserver.sql_statement_completed -- ,
                         (
                         ACTION (sqlserver.database_name,
                                 sqlserver.plan_handle,
                                 sqlserver.query_plan_hash,
                                 sqlserver.session_id,
                                 sqlserver.sql_text,
                                 sqlserver.username)
                            WHERE
                                         sqlserver.session_id=58
                                         AND sqlserver.database_id = 8
                          ),
ADD EVENT sqlserver.sp_statement_completed -- ,
                    (
                    ACTION (sqlserver.database_name,
                            sqlserver.plan_handle,
                            sqlserver.query_plan_hash,
                            sqlserver.session_id,
                            sqlserver.sql_text,
                            sqlserver.username)
                    WHERE
                                     sqlserver.session_id=58
                                     AND sqlserver.database_id = 8
                     )
ADD TARGET package0.ring_buffer (SET max_memory = 4096  ) WITH (max_dispatch_latency = 1 seconds)

Let’s start the session.

ALTER EVENT SESSION Test ON SERVER STATE = START

Here is an example to get data from the session.

SELECT CAST(LocksAcquired.TargetXml AS XML) AS XMLData
  INTO #LogData
  FROM (SELECT CAST(t.target_data AS XML) AS TargetXml
          FROM sys.dm_xe_session_targets AS t
          JOIN sys.dm_xe_sessions AS s ON s.address= t.event_session_address
         WHERE s.name= 'Test'   ) AS LocksAcquired;
 SELECT T.XMLData.value('(action[@name="sql_text"])[1]','varchar(1000)' ) AS [SqlText],
        T.XMLData.value('(@timestamp)[1]',    'datetime' )                AS [OccurredDtTm],
        T.XMLData.value('(data[@name="message"])[1]','varchar(60)')       AS [Message]
        ,T.XMLData.value('(action[@name="username"])[1]','SYSNAME')       AS [UserName]
        ,T.XMLData.value('(action[@name="session_id"])[1]','INT')         AS [SessionID]
        ,T.XMLData.value('(action[@name="query_plan_hash"])[1]','DECIMAL(38,0)') AS [QueryPLanHash]
        ,T.XMLData.value('(action[@name="plan_handle"])[1]','VARBINARY(MAX)') AS [QueryPLanHandle]
        ,T.XMLData.value('(data[@name="cpu_time"])[1]','INT') AS [CPUTime] 
        ,T.XMLData.value('(data[@name="duration"])[1]','BIGINT')  AS [Duration]
        ,NULL [PhysicalReads]
        ,NULL                                 [LogicalReads]
        ,NULL                                 [Writes]
        ,NULL                                 [RowCount]
       ,T.XMLData.value('(data[@name="object_type"])[1]','SYSNAME') AS [ObjectType]
       ,T.XMLData.value('(data[@name="object_id"])[1]','INT') AS [ObjectID]
       ,U.XMLData.query('.')                                                    AS [XML]
       ,T.XMLData.value('(data[@name="estimated_rows"])[1]','BIGINT') AS [EstimatedRow]
      ,T.XMLData.value('(data[@name="estimated_cost"])[1]','BIGINT')  AS [EstimatedCost]
       , 'QueryPlan' AS [type]
         INTO #finalset
         FROM #LogData x 
  CROSS APPLY x.XMLData.nodes('/RingBufferTarget/event[@name="query_post_execution_showplan"]') AS T(XMLData)
  CROSS APPLY t.XMLData.nodes('data[@name="showplan_xml"]/value/*') AS U(XMLData);
    SELECT  T.XMLData.value('(action[@name="sql_text"])[1]','varchar(1000)') AS [SqlText],
            T.XMLData.value('(@timestamp)[1]',    'datetime')                AS [OccurredDtTm],
            T.XMLData.value('(data[@name="message"])[1]','varchar(60)')      AS [Message]
           ,T.XMLData.value('(action[@name="username"])[1]','SYSNAME')       AS [UserName]
           ,T.XMLData.value('(action[@name="session_id"])[1]','INT') AS [SessionID]
           ,T.XMLData.value('(action[@name="query_plan_hash"])[1]', 'DECIMAL(38,0)' ) AS [QueryPLanHash]
           ,T.XMLData.value('(action[@name="plan_handle"])[1]', 'VARBINARY(MAX)' )    AS [QueryPLanHandle]
           ,T.XMLData.value('(data[@name="cpu_time"])[1]', 'INT')                     AS [CPUTime]
           ,T.XMLData.value('(data[@name="duration"])[1]','BIGINT')                   AS [Duration]
           ,T.XMLData.value('(data[@name="physical_reads"])[1]','BIGINT')                [PhysicalReads]
           ,T.XMLData.value('(data[@name="logical_reads"])[1]','BIGINT')                 [LogicalReads]
           ,T.XMLData.value('(data[@name="writes"])[1]', 'BIGINT' )                      [Writes]
           ,T.XMLData.value('(data[@name="row_count"])[1]','BIGINT')                     [RowCount]
           ,T.XMLData.value('(data[@name="object_type"])[1]', 'SYSNAME' )              AS [ObjectType]
           ,T.XMLData.value('(data[@name="object_id"])[1]',  'INT' )                   AS [ObjectID]
                -- ,U.XMLData.query('.')                                                AS [XML]
            ,CAST (NULL AS XML) AS [XML]
            ,T.XMLData.value('(data[@name="estimated_rows"])[1]','BIGINT')              AS [EstimatedRow]
           ,T.XMLData.value('(data[@name="estimated_cost"])[1]','BIGINT')               AS [EstimatedCost]
           , 'IOSql' AS [type]
         INTO #finalsetII
         FROM #LogData x
        CROSS APPLY x.XMLData.nodes('/RingBufferTarget/event[@name="sql_statement_completed"]') AS T(XMLData)

SELECT  T.XMLData.value('(action[@name="sql_text"])[1]','varchar(1000)') AS [SqlText],
        T.XMLData.value('(@timestamp)[1]',    'datetime' )               AS [OccurredDtTm],
        T.XMLData.value('(data[@name="message"])[1]','varchar(60)' )     AS [Message]
        ,T.XMLData.value('(action[@name="username"])[1]', 'SYSNAME')     AS [UserName]
        ,T.XMLData.value('(action[@name="session_id"])[1]','INT' )       AS [SessionID]
        ,T.XMLData.value('(action[@name="query_plan_hash"])[1]','DECIMAL(38,0)') AS [QueryPLanHash]
        ,T.XMLData.value('(action[@name="plan_handle"])[1]','VARBINARY(MAX)' ) AS [QueryPLanHandle]
        ,T.XMLData.value('(data[@name="cpu_time"])[1]','INT') AS [CPUTime]
        ,T.XMLData.value('(data[@name="duration"])[1]','BIGINT') AS [Duration]
        ,T.XMLData.value('(data[@name="physical_reads"])[1]', 'BIGINT' ) [PhysicalReads]
        ,T.XMLData.value('(data[@name="logical_reads"])[1]', 'BIGINT' )  [LogicalReads]
       ,T.XMLData.value('(data[@name="writes"])[1]', 'BIGINT' )          [Writes]
       ,T.XMLData.value('(data[@name="row_count"])[1]', 'BIGINT' )       [RowCount]
         ,T.XMLData.value('(data[@name="object_type"])[1]','SYSNAME') AS [ObjectType]
       ,T.XMLData.value('(data[@name="object_id"])[1]', 'INT' ) AS [ObjectID]
            -- ,U.XMLData.query('.')                                                    AS [XML]
            , CAST(NULL AS XML) AS [XML]
        ,T.XMLData.value('(data[@name="estimated_rows"])[1]','BIGINT')AS [EstimatedRow]
         ,T.XMLData.value('(data[@name="estimated_cost"])[1]', 'BIGINT' ) AS [EstimatedCost]
       , 'IOProcedure' AS [type]
         INTO #finalsetIII
            FROM  #LogData x
            CROSS APPLY x.XMLData.nodes('/RingBufferTarget/event[@name="sp_statement_completed"]') AS T(XMLData)
            --CROSS APPLY t.XMLData.nodes('data[@name="showplan_xml"]/value/*') AS U(XMLData)
            ;
SELECT * FROM #finalset UNION ALL SELECT * FROM #finalsetII UNION ALL SELECT * FROM #finalsetIII

Do not forget to clear your session

IF EXISTS (SELECT * FROM sys.server_event_sessions WHERE name = 'Test')
BEGIN
DROP EVENT SESSION Test ON SERVER;
END

In next post I will publish SQL routines in which above mentioned script will be encapsulated.

Leave a Reply

Your email address will not be published. Required fields are marked *