Sql-server – How to find statement executed by sp_executesql in [sys].[dm_exec_query_stats]

dmvsql serversql-server-2012t-sql

I have a function which is generating dynamic T-SQL statement. The generated code is executed then in a stored procedure.

I want to log some statistics about how long the execution of the generated code is and some IO statistics (logical/physical reads and stuff).

In order to do that, in the function which is building the dynamic T-SQL statement I append the following line to the final statement:

SET @A = @A + '--' + REPLACE('F2B287FD-1419-48DB-9881-4AA77B99450E', '-', '');

Then I am searching for statistics using the following query:

SELECT *
FROM [sys].[dm_exec_query_stats] QS
CROSS APPLY [sys].[dm_exec_sql_text] (QS.[sql_handle]) ST
WHERE ST.[dbid] = DB_ID()
    AND ST.[text] LIKE '%F2B287FD141948DB98814AA77B99450E%';

but it finds nothing.

The code is executed via sp_executesql procedure. Could anyone tell what's wrong with my query or alternative way of detecting IO for specific query.

Best Answer

Your problem is caused by the ST.[dbid] = DB_ID() in your WHERE clause.

I've taken a basic example of what I believe you are trying to do from AdventureWorks:

USE AdventureWorks;
GO

DECLARE @sql NVARCHAR(2000);

SET @SQL = 'SELECT TOP 10 * FROM Person.Person';

SET @SQL = @SQL + '--' + REPLACE('F2B287FD-1419-48DB-9881-4AA77B99450E', '-', '');

EXEC sys.sp_executesql @sql;

When you try and get the dbid value from the dm_exec_sql_text() DMV, it's actually NULL for this query, so you are immediately filtering it out.

Database ID is NULL

However, by using the dm_exec_plan_attributes() DMV, WHERE attribute = 'dbid' you can get the correct DBID() value for your current database.

This is my current go-to query to retrieve this information.

  SELECT
    deqs.plan_handle AS PlanHandle
  ,deqs.query_hash AS QueryHash
  ,dest.dbid
  ,DB_NAME(CAST(depa.value AS SMALLINT)) AS DatabaseName
  ,OBJECT_SCHEMA_NAME(dest.objectid, CAST(depa.value AS INT)) AS SchemaName
  ,OBJECT_NAME(dest.objectid, CAST(depa.value AS INT)) AS ObjectName
  ,MAX(last_execution_time) AS LastExecuted
  ,deqs.creation_time AS PlanCreationTime
  ,SUM(deqs.execution_count) AS Executions
  ,SUM(total_elapsed_time) AS SumDuration
  ,CAST(100.0 * SUM(total_elapsed_time)
              / SUM(SUM(total_elapsed_time)) OVER() AS NUMERIC(5,2)) AS PctDuration
  ,SUM(total_worker_time) AS SumCPU
  ,CAST(100.0 * SUM(total_worker_time)
              / SUM(SUM(total_worker_time)) OVER() AS NUMERIC(5,2)) AS PctCPU
  ,SUM(total_logical_reads + total_logical_writes + total_physical_reads) AS [SumIO]
  ,CAST(100.0 * SUM(total_logical_reads + total_logical_writes + total_physical_reads)
              / SUM(SUM(total_logical_reads + total_logical_writes + total_physical_reads)) OVER() AS NUMERIC(5,2)) AS PctIO
  ,Q.statementtext
  ,deqs.query_plan_hash AS QueryPlanHash    
  ,SUM(total_rows) AS RowsAffected
  ,MAX(statement_start_offset) statement_start_offset
  ,MAX(statement_end_offset) statement_end_offset                              
FROM sys.dm_exec_query_stats AS deqs 
CROSS APPLY sys.dm_exec_sql_text(deqs.sql_handle) AS dest
CROSS APPLY sys.dm_exec_plan_attributes(plan_handle) AS depa
CROSS APPLY (VALUES (SUBSTRING(dest.text, (deqs.statement_start_offset/2)+1,
                          ((CASE deqs.statement_end_offset WHEN -1 THEN DATALENGTH(dest.text)
                                ELSE deqs.statement_end_offset
                              END - deqs.statement_start_offset)/2)+1))) AS Q(statementtext)     
WHERE deqs.last_execution_time > DATEADD(dd, -1, GETDATE()) 
      AND depa.attribute = 'dbid'
      AND Q.statementtext LIKE '%F2B287FD141948DB98814AA77B99450E%'
GROUP BY 
      dest.text, Q.statementtext, deqs.plan_handle, deqs.creation_time, 
        dest.objectid, deqs.query_hash, deqs.query_plan_hash, depa.value, dest.dbid;
Related Question