Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

What do multiple parse and compile outputs in Statistics Time mean?

I'm performance tuning a query in Microsoft SQL server, and I have SET STATISTICS TIME ON.

For output, I'm receiving multiple SQL Server parse and compile time: messages:

SQL Server parse and compile time: 
   CPU time = 0 ms, elapsed time = 2 ms.
SQL Server parse and compile time: 
   CPU time = 5985 ms, elapsed time = 5985 ms.
SQL Server parse and compile time: 
   CPU time = 5953 ms, elapsed time = 5965 ms.
SQL Server parse and compile time: 
   CPU time = 6172 ms, elapsed time = 6173 ms.
SQL Server parse and compile time: 
   CPU time = 6031 ms, elapsed time = 6073 ms.
SQL Server parse and compile time: 
   CPU time = 6000 ms, elapsed time = 6008 ms.
SQL Server parse and compile time: 
   CPU time = 5978 ms, elapsed time = 5978 ms.
SQL Server parse and compile time: 
   CPU time = 5969 ms, elapsed time = 5970 ms.
SQL Server parse and compile time: 
   CPU time = 5953 ms, elapsed time = 5966 ms.

(1 row(s) affected)

(1 row(s) affected)

 SQL Server Execution Times:
   CPU time = 9516 ms,  elapsed time = 9544 ms.
SQL Server parse and compile time: 
   CPU time = 0 ms, elapsed time = 0 ms.

 SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 0 ms.

Someone suggested this was due to subqueries, but I can't find anything confirming this. And there are more messages then there are subqueries.

I'm also not certain why I'm getting 2 (1 row(s) affected) since only 1 recordset with one row is returned.

EDIT:

This query is one SELECT statement that uses multiple subqueries, a window function, and an offset fetch next.

like image 364
user3593990 Avatar asked Nov 10 '22 16:11

user3593990


1 Answers

I came across this post while I was researching a similar problem. Although it's old I thought I'd add my answer.

Pretty sure what you were seeing is simply a bug with STATISTICS TIME. I'm getting similar behaviour inserting into a table with a trigger. You may also find that the time (or some of it) apportioned to Parse and Compile is actually related to the query processing. I've verified this (in my case) by capturing the actual execution plan and checking the CompileTime and CompileCPU in the XML - these are reporting as 61 and 27 (ms) respectively. If I look at my STATISTICS TIME output I have:

SQL Server parse and compile time:  
  CPU time = 7906 ms, elapsed time = 8041 ms.  
SQL Server parse and compile time:   
  CPU time = 7906 ms, elapsed time = 8041 ms.  
SQL Server parse and compile time:   
  CPU time = 7906 ms, elapsed time = 8041 ms.  

A lot more than the figures captured in the plan.

You can see the repeated identical rows, they are clearly wrong in my case as the query took less time to execute that the total elapsed time from these alone. For my query, I expect that I should just have one row and it should be marked as SQL Server Execution Time (not parse and compile).

STATISTICS TIME and STATISTICS IO are great tools, but there are a few cases where they display incorrect figures, so it's important to also apply common sense checking to them also.

like image 73
Matthew McGiffen Avatar answered Nov 14 '22 22:11

Matthew McGiffen