The Setup:
Our current deploy process runs a big script that adds columns, tables, indexes, constraints, etc. It performs DDL changes. It even migrates data to the new tables and columns. So it also performs DML changes. One issue we run into is that in our development environment we have a deploy everyday (an incremental build). In production, we only do it once – officially. We were working on our staging environment, going for the non-incremental deploy and it was taking a long time – what should take 10 minutes, we stopped at 3 hours.
The Statement:
Looking into the deploy issue I was querying the sys.dm_exec_query_stats DMV and only saw the DML statements. Digging into it, the DMV doesn’t collect stats for the DDL statements.
The Proof:
To prove this, here’s what I did – first – almost a reboot (cleared the cache, clean buffers, etc):
CHECKPOINT --writes dirty pages to disk
DBCC FREEPROCCACHE --clears entire plan cache
DBCC DROPCLEANBUFFERS --clears all clean data cache pages
--from MS page on sys.dm_exec_query_stats
SELECT TOP 5 query_stats.query_hash AS "Query Hash",
SUM(query_stats.total_worker_time) / SUM(query_stats.execution_count) AS "Avg CPU Time",
MIN(query_stats.statement_text) AS "Statement Text"
FROM
(SELECT QS.*,
SUBSTRING(ST.text, (QS.statement_start_offset/2) + 1,
((CASE statement_end_offset
WHEN -1 THEN DATALENGTH(ST.text)
ELSE QS.statement_end_offset END
- QS.statement_start_offset)/2) + 1) AS statement_text
FROM sys.dm_exec_query_stats AS QS
CROSS APPLY sys.dm_exec_sql_text(QS.sql_handle) as ST) as query_stats
GROUP BY query_stats.query_hash
ORDER BY 2 DESC;
Here are the results:
Then I created a test table and reran the query on sys.dm_exec_query_stats:
Create table test (iid int)
Go
SELECT TOP 5 query_stats.query_hash AS "Query Hash",
SUM(query_stats.total_worker_time) / SUM(query_stats.execution_count) AS "Avg CPU Time",
MIN(query_stats.statement_text) AS "Statement Text"
FROM
(SELECT QS.*,
SUBSTRING(ST.text, (QS.statement_start_offset/2) + 1,
((CASE statement_end_offset
WHEN -1 THEN DATALENGTH(ST.text)
ELSE QS.statement_end_offset END
- QS.statement_start_offset)/2) + 1) AS statement_text
FROM sys.dm_exec_query_stats AS QS
CROSS APPLY sys.dm_exec_sql_text(QS.sql_handle) as ST) as query_stats
GROUP BY query_stats.query_hash
ORDER BY 2 DESC;
Here are the results:
To Prove this is legit, I ran a select statement on the new table and then reran the query on sys.dm_exec_query_stats:
Select * from test
Go
SELECT TOP 5 query_stats.query_hash AS "Query Hash",
SUM(query_stats.total_worker_time) / SUM(query_stats.execution_count) AS "Avg CPU Time",
MIN(query_stats.statement_text) AS "Statement Text"
FROM
(SELECT QS.*,
SUBSTRING(ST.text, (QS.statement_start_offset/2) + 1,
((CASE statement_end_offset
WHEN -1 THEN DATALENGTH(ST.text)
ELSE QS.statement_end_offset END
- QS.statement_start_offset)/2) + 1) AS statement_text
FROM sys.dm_exec_query_stats AS QS
CROSS APPLY sys.dm_exec_sql_text(QS.sql_handle) as ST) as query_stats
GROUP BY query_stats.query_hash
ORDER BY 2 DESC;
The Select statement on the table and the DMV showes up, but not the create table statement.
The same thing happened with adding an index, here’s the script (first almost reboot, then prove there is nothing in the results of the query to dm_exec_query_stats, add the index and rerun the query to dm_exec_query_stats):
CHECKPOINT --writes dirty pages to disk
DBCC FREEPROCCACHE --clears entire plan cache
DBCC DROPCLEANBUFFERS --clears all clean data cache pages
SELECT TOP 5 query_stats.query_hash AS "Query Hash",
SUM(query_stats.total_worker_time) / SUM(query_stats.execution_count) AS "Avg CPU Time",
MIN(query_stats.statement_text) AS "Statement Text"
FROM
(SELECT QS.*,
SUBSTRING(ST.text, (QS.statement_start_offset/2) + 1,
((CASE statement_end_offset
WHEN -1 THEN DATALENGTH(ST.text)
ELSE QS.statement_end_offset END
- QS.statement_start_offset)/2) + 1) AS statement_text
FROM sys.dm_exec_query_stats AS QS
CROSS APPLY sys.dm_exec_sql_text(QS.sql_handle) as ST) as query_stats
GROUP BY query_stats.query_hash
ORDER BY 2 DESC;
Go
CREATE UNIQUE CLUSTERED INDEX [UC_Test_iID] ON [dbo].[test]
([iid] ASC) WITH (STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
GO
SELECT TOP 5 query_stats.query_hash AS "Query Hash",
SUM(query_stats.total_worker_time) / SUM(query_stats.execution_count) AS "Avg CPU Time",
MIN(query_stats.statement_text) AS "Statement Text"
FROM
(SELECT QS.*,
SUBSTRING(ST.text, (QS.statement_start_offset/2) + 1,
((CASE statement_end_offset
WHEN -1 THEN DATALENGTH(ST.text)
ELSE QS.statement_end_offset END
- QS.statement_start_offset)/2) + 1) AS statement_text
FROM sys.dm_exec_query_stats AS QS
CROSS APPLY sys.dm_exec_sql_text(QS.sql_handle) as ST) as query_stats
GROUP BY query_stats.query_hash
ORDER BY 2 DESC;
Here’s the results:
In conclusion, remember the fact that sys.dm_exec_query_stats DMV only shows DML statements, not DDL statements!
