SQL Server has two very useful dynamic management views, sys.dm_exec_query_stats and sys.dm_exec_procedure_stats DMVs, which let us DBA to find out which queries and stored procs are expensive in terms of processing time, I/O, duration, etc. Every time a query or a stored procedure is executed, that execution's performance figures will be added into the performance statistics. But what if the execution was cancelled by the client application, such as due to being blocked and then the client timeout? Will the cancelled execution still be counted in the performance statistics? This month blog post I will do an experiment to check it out.
1. Let's create a simple testing table and stored proc:
USE TestingDB;
GO
DROP TABLE IF EXISTS dbo.Table1;
CREATE TABLE Table1 (
pk int IDENTITY(1,1) NOT NULL PRIMARY KEY,
col [varchar](50) NULL
);
GO
CREATE OR ALTER PROC TestSP
@p varchar(50)
AS
BEGIN
SET NOCOUNT ON;
BEGIN TRAN
SELECT 'Before', * FROM Table1;
INSERT Table1 (col) VALUES (@p);
SELECT 'After', * FROM Table1;
COMMIT
END
GO
2. Execute the stored proc 3 times in order to populate the performance statistics:
EXEC TestSP 'X';
EXEC TestSP 'X';
EXEC TestSP 'X';
3. Check the performance statistics of the queries inside the stored proc, and the whole stored proc:
SELECT DB_NAME(qt.[dbid]) as DB, OBJECT_NAME(qt.objectid, qt.[dbid]) AS Obj,
SUBSTRING(qt.[text], qs.statement_start_offset/2+1,
(CASE WHEN qs.statement_end_offset = -1
THEN LEN(CONVERT(nvarchar(max), qt.[text]))*2 ELSE qs.statement_end_offset END - qs.statement_start_offset)/2
) AS query_text, qs.statement_end_offset,
qs.execution_count, qs.creation_time, qs.last_execution_time, qs.last_elapsed_time, qs.max_elapsed_time
FROM sys.dm_exec_query_stats AS qs CROSS APPLY sys.dm_exec_sql_text(qs.[sql_handle]) AS qt
WHERE qt.[dbid]=DB_ID('TestingDB') AND qt.objectid=OBJECT_ID('TestingDB.dbo.TestSP')
ORDER BY qs.statement_start_offset;
SELECT DB_NAME(database_id) AS DB, OBJECT_NAME([object_id], database_id) AS Obj,
execution_count, cached_time, last_execution_time, last_elapsed_time, max_elapsed_time
FROM sys.dm_exec_procedure_stats
WHERE database_id=DB_ID('TestingDB') AND [object_id]=OBJECT_ID('TestingDB.dbo.TestSP');
As you can see, both the queries and the stored proc are executed 3 times.
4. Open another query window, execute below query to lock the whole table:
SET TRANSACTION ISOLATION LEVEL SERIALIZABLE;
BEGIN TRAN
SELECT * FROM Table1;
5. In the previous window, execute the TestSP stored proc again, now it's being blocked. You can check it on the Activity - All Blocking Transaction server report:
You can see that the query being blocked is the INSERT Table1 statement inside the stored proc.
6. Now press the red square button to CANCEL the TestSP execution. Then check the performance statistics again:
It shows the first SELECT statement in the stored proc is executed (execution_count = 4), the last SELECT is skipped (exec_count = 3), which can be imagined. The most interesting point is, SQL Server was really tried hard to execute the INSERT statement, unfortunately being blocked, and then the whole stored proc was cancelled by the client application (yes, you, haha), and sadly its query_stats does NOT count in this hardworking try (exec_count = 3). But the procedure_stats surprisingly counts in that cancelled execution.
Conclusion:
Cancelled QUERY execution will NOT count in sys.dm_exec_query_stats.
But cancelled STORED PROC will count in sys.dm_exec_procedure_stats.
The moral:
* That's why DBA likes stored procs rather than ORM/query generated from application code!
* To monitor blocking, we should enable blocked process report session.
w
