A question that came up recently was how to track the query compile time. It’s actually a pretty interesting question because, there aren’t that many ways to tell how long it took to compile the query, and they don’t necessarily agree. For most of us, most of the time, compile time for a given query doesn’t matter. However, I love telling the story of the query I had on an old system that could run in 90ms, but took 5 minutes to compile. In short, sometimes compile time matters.
How To See Query Compile Time
If you want to see how long it takes a query to compile, you have, to my knowledge, three options. The first, and possibly easiest, is to look at the plan properties on an execution plan. Take this plan from a SELECT…INTO query:
That first operator that is highlighted has all the meta-data about the plan. Right click on it and select “Properties” from the context menu. There, you’ll see all the info like this:
I’ve highlighted the CompileTime property. You can also see the CompileCPU and CompileMemory. From this, you can answer the question about the compile time (milliseconds on this measure by the way) for the query. Easy.
Now, capturing an execution plan isn’t always desirable, or, sometimes, possible. How else can you get compile information?
SET STATISTICS TIME ON
Enabling this in a query results in this kind of information:
You can see the CPU time, if any, and the total compile time for the query. You can see that this measure is accurate when compared to the compile time in the plan. Yeah, they’re not identical. This is two different compile operations for this test. If I go and look at the plan for the second run, it’s also 3ms this time.
If you have Query Store enabled for a database, the system view sys.query_store_plan will give you the compile time, but not CPU time or memory.
How about another way to monitor query compile time. Extended Events anyone?
Well, there we get a funny story. If you look at events like rpc_completed or sql_batch_completed, we don’t have any compile metrics captured. If you look at sql_statement_recompile, while we get info about the recompile, such as the reason, we don’t get any measurement metrics for how long that recompile took. So we’re a little stuck. If you capture the plan using Extended Events, a crazy heavy impact option by the way, you can see the compile time. You could do a combination of events, rpc_starting along with rpc_completed and sql_statement_recompile using Causality Tracking to put them all in order. Then, just get the time values for the event, subtract the execution time from the total time and you should arrive at the number… BLECHH!
What else have you got?
Debug?
Debug Extended Events
If you look at the New Session window for the Extended Events GUI, you’ll see a drop-down for Channel (I tried to get a screen capture of the drop down, but it just fought me long enough, I gave up):
In the drop down, you’ll see a list. By default, everything on that list will be selected, except Debug. This is on purpose. The Debug Events are subject to change, and not necessarily well documented. Some of them could even be dangerous. I recommend caution when using them.
HOWEVER
With SQL Server 2017 CU13, we get a new event in the debug category: sql_statement_post_compile. This is a handy little event. Check out the information it supplies:
Not only do we get the duration & cpu_time, but we also get the recompile_cause and more. There’s not much documentation on this event. It works great in my tests. If I wanted this info, I’d recommend using this event.
Conclusion
It’s funny how something simple, compile time, can actually be somewhat complicated. However, there it is. Between the plan itself, statistics_time, Query Store, and, if you’re running greater than 2017 CU13 or Azure, you can (easily) use Extended Events, you can get the query compile time.