Tuning « SQL Feather and Quill

TSQL Looping Stats

Every once in a while, you need to loop through a bunch of records in TSQL. It’s not the fastest way to do things, but sometimes it’s necessary. I’ve been working on a process that requires this and I needed to know the progress of the loop, so I came up with this model. The output will give you a bunch of statistics including a predicted finishing time every 1000 rows (note you can adjust this). This should save me from getting some grey hairs when a looping process is necessary.

Declare @counter int,
		@currentRow int,
		@rowsFound int,
		@start datetime,
		@SecSoFar bigint,
		@PredictedTotalSec int,
		@PercentComplete varchar(10),
		@CompleteTime datetime

Set @rowsFound = 200000 -- or set this equal to the count of a table you are working with.

Set @currentRow = 1
Set @start = GETDATE()

while @currentRow <=  @rowsFound
Begin
		--<<DO YOUR WORK HERE>>--

			Set @currentRow = @currentRow + 1  ---Update the counter....
			If (@currentRow % 1000) = 0  --display every 1000 rows or adjust...
			Begin
				Set @SecSoFar = Datediff(s, @start, Getdate())
					Set @PercentComplete = Cast(ROUND(@currentRow/Cast(@rowsFound as float), 3)*100 as varchar(20)) + '%'
					Set @PredictedTotalSec = (@SecSoFar/Cast(@currentRow as float))*@rowsFound
					Set @CompleteTime = Dateadd(s, @PredictedTotalSec, @start)

				Select
					@currentRow as 'Current_Row',
					@rowsFound as 'Total_Rows',
					@start as 'Start_Time',
					GETDATE() as 'Current_Time',
					@SecSoFar as 'SecondsSoFar',
					@PercentComplete as 'Percent_Complete',
					@PredictedTotalSec as 'Predicted_Total_Seconds',
					@CompleteTime as 'Predicted_Complete_Time'

			End
End

Troubleshooting Troubleshooting – sys.dm_exec_query_stats

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!

Big Trys and Small Trans

The catch phrase around the office these days is “Big Trys and small Trans.” This came about as we were review stored procedure changes and I two suggestions. First, that the entire procedure has a try…catch around it and second that the transaction be as small as possible.

Big Try

We’ve got standards in place that procedures have a try…catch in them. One procedure had been copied, then modified with some logic to parse XML before the try. I said lets move the try to above the XML parsing in case there’s an error in the XML, we’ll catch that as well. So now we’ve got a bigger try.

Small Tran

The original code had the following steps:

Start the transaction
Look up some data
Insert some data into a table
Look up some other data
Update another table
Finally completed the transaction

In order to keep transactions small, I suggested the following:

Look up all the data
Start the transaction
Insert the row into the table
Update the row in the other table
Finish the transaction

This will help avoid deadlocks and contention and keep things running smoothly. There’s the smaller tran.

If you stick with the “Big Trys and Small Trans” methodology, it should help the following:

Help avoid contention
Help avoid deadlocks
Catch errors earlier

SQL Performance Trouble Shooting – the basics from Microsoft

Check Activity Monitor

Anything running?
Blocking/wait times
Goto Locks and check lock strategy

SQL Error Log

Any errors? If so investigate

Resource utilizations

DMVs

sys.dm_exec_query_stats

Look at: Total physical reads, logical reads, number to executions, total time, (divide those two to get average)
Join with sys.dm_exec_sql_text

Performance Monitors

Processor Time
Memory
SQL Server Statistics

Batch requests/sec
Compilations
Recompilations – high CPU time (use fully qualified name to avoid recompiatoins)

SQL Wait stats
SQLServer Memory Manager
Physical Disk – Average Disk Read and write – Less than 10 ms on SAN

Trace files – created default
Event Viewer

SQL Feather and Quill

Twitter

Subscribe

Search Site

Categories

My Other Sites

Archives

TSQL Looping Stats

Troubleshooting Troubleshooting – sys.dm_exec_query_stats

The Setup:

The Statement:

The Proof:

Big Trys and Small Trans

SQL Performance Trouble Shooting – the basics from Microsoft

SQLQuill Tweets

The SQLQuill Daily

Recent Posts

SQL Feather and Quill

Twitter

Subscribe

Search Site

Categories

My Other Sites

Tags

Archives

TSQL Looping Stats

Troubleshooting Troubleshooting – sys.dm_exec_query_stats

The Setup:

The Statement:

The Proof:

Big Trys and Small Trans

SQL Performance Trouble Shooting – the basics from Microsoft

SQLQuill Tweets

The SQLQuill Daily

Recent Posts