I am trying to test the time it takes to run certain queries in my project. I am testing the query in management studio.
Here is a snippet of my code:
SET STATISTICS TIME ON
SET STATISTICS IO ON
EXEC <my stored procedure>
SET STATISTICS IO OFF
SET STATISTICS TIME OFFI do not understand what I am getting as an output:
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.
SQL Server parse and compile time:
CPU time = 21 ms, elapsed time = 21 ms.
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'product_loadtable'. Scan count 1, logical reads 942, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'Workfile'. Scan count 0, logical reads 0, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'product_option'. Scan count 2, logical reads 26, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'product_description'. Scan count 157, logical reads 628, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'barsizes'. Scan count 0, logical reads 314, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'product_detail'. Scan count 1, logical reads 17, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'product'. Scan count 1588, logical reads 6299, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'inventory'. Scan count 1, logical reads 24, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'option_value'. Scan count 1, logical reads 3, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 41 ms.
SQL Server Execution Times:
CPU time = 31 ms, elapsed time = 62 ms.
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.
Completion time: 2023-04-21T09:49:57.7878903-04:00Why so many SQL Execution times - are they additive? Can I make all the times into one easy to read time? Am I doing something wrong here?
2条答案
按热度按时间7z5jn7bk1#
Assuming that
STATISTICS TIMEwasOFFat the start of the batch, you likely have:SET STATISTICS IO ON(CPU time = 0 ms, elapsed time = 0 ms.)SET STATISTICS IO OFF(CPU time = 0 ms, elapsed time = 0 ms.)You might want to use
SET STATISTICS IO, TIME <ON|OFF>instead, to remove 2 of those steps.j0pj023g2#
Each of the execution times reflects the time it takes to do a 'step' in the processing.
You sometimes need to ignore a lot of the 0ms ones - it depends on what else is happening. For example, I think the first set (SQL Server Execution Times 0ms/0ms) represents the time it takes to
SET STATISTICS IO ON.The next line - parse and compile time - is relevant, to a degree. It is how long it takes SQL Server to determine how it will construct the query. However, this is typically only a fraction of the time it takes to actually run the query.
The big table with the list of IO is the most useful for identifying potential processing issues.
The time record after the IO list is the time taken to do the actual query.
I believe the next one is actually then the sum of the parse/compile time, and the time taken to do the query.
Then the last is the time to turn the IO statistics off.
In general, the times taken are additive - except the 2nd one after the IO list (which is the total time, for that SQL command, to both parse it and run it).
For reading/reviewing these, remember that the time taken also depends on a few things (how good your server is, how busy it is, etc) therefore IO times can vary from run to run. Also, the times are not precise to 1ms - instead usually to a certain value that I think is specific to your server (in your case, 21ms probably). Therefore you have things that sometimes take 0ms, and other times takes 21ms.
If you have 2 hours, Brent Ozar's 'How to think like the SQL Server engine is REALLY useful for understanding these and how to do basic analysis of these. Even when I thought I knew a lot about this - the videos were fantastic in really getting me to the next level.