{"id":1254,"date":"2011-08-16T16:30:00","date_gmt":"2011-08-16T14:30:00","guid":{"rendered":"https:\/\/www.sqlinthewild.co.za\/?p=1254"},"modified":"2011-08-11T23:30:47","modified_gmt":"2011-08-11T21:30:47","slug":"compiles-and-recompiles","status":"publish","type":"post","link":"https:\/\/www.sqlinthewild.co.za\/index.php\/2011\/08\/16\/compiles-and-recompiles\/","title":{"rendered":"Compiles and recompiles"},"content":{"rendered":"

I want to spend some time over the next few months looking at query compilation and the plan cache, and there’s a couple concepts that I want to get cleared up beforehand. The first of those is around two terms that are often used interchangeably, compile and recompile.<\/p>\n

Compile<\/h3>\n

A compile occurs when a query is given to the query optimiser and, when it does a lookup into the plan cache, no matching plan is found. The optimism must then compile the query, generating an execution plan, must add that plan to the plan cache (in most cases) and then must pass that plan onto the query execution engine so that the query can be executed. (http:\/\/technet.microsoft.com\/en-us\/library\/Cc966425<\/a>)<\/p>\n

Recompile<\/h3>\n

A recompile is something slightly different. For a recompile, the optimiser must find a matching plan when it queries the plan cache, must hand that cached plan over to the query execution engine and then while doing validation checks the execution engine must determine that then query plan is no longer valid and request the optimiser to partially or completely recompile the query. (http:\/\/technet.microsoft.com\/en-us\/library\/Cc966425<\/a>)<\/p>\n

Subtle difference. Both cases result in the optimiser generating an execution plan, but the reasons can be different. Also worth noting is that a compile results in a new plan in the cache, a recompile simply replaces an existing plan.<\/p>\n

Another difference since SQL 2005 – a compile is for the entire batch, but a recompile can be for just a single statement within the batch.<\/p>\n

\n

Now the theory’s dealt with, let’s look at some examples and see how we can track these two events and try and get a better understanding of which occurs when and how they look.<\/p>\n

The tools I’m going to use to track these are performance monitor with the compiles\/sec and recompiles\/sec counters and SQL Profiler with the event SP:StmtRecompile event (there’s no profiler event for compilation). I’ll also check what’s in the plan cache after each test.<\/p>\n

The first one\u2019s going to be very simplistic, a query run against an empty plan cache.<\/p>\n

DBCC FREEPROCCACHE\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO<\/pre>\n
What we get from that is a non-zero value for SQL Compilations\/sec (perfmon) and the following from profiler (The SQL Recompiles\/sec remains 0)<\/p>\n
\"Compiles1\"<\/a><\/p>\n
and the plan cache now contains one plan with one use. (for more info on how the CacheMiss and CacheInsert events work, see https:\/\/www.sqlinthewild.co.za\/index.php\/2010\/07\/27\/hit-and-miss\/<\/a> and https:\/\/www.sqlinthewild.co.za\/index.php\/2010\/08\/31\/come-and-gone\/<\/a>)<\/p>\n
\"Compiles2\"<\/a><\/p>\n
In this case, I hope it was clear, we had a compile occur (empty plan cache before, new plan added to cache).<\/p>\n
Now what happens if, with no clearing of the cache nor anything else being done, I mark that procedure for recompile and run it again?<\/p>\n
<\/p>\n
EXEC sp_recompile OutStandingTotalByStatus\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO<\/pre>\n
This is interesting. We don\u2019t see a non-zero value for SQLRecompiles\/sec (as might have been expected), instead, as with the previous case we get a spike for SQLCompiles\/sec. The profiler output shows why<\/p>\n
\"Compiles3\"<\/a><\/p>\n
Note the SP:CacheRemove being run for the stored procedure\u2019s plan. So sp_recompile does not mark a plan as invalid and needing recompilation. It removes it from the cache entirely. The next time that procedure runs SQL does a cache lookup, doesn\u2019t find a matching plan and compiles a new one (compile, not recompile)<\/p>\n
Onwards\u2026 What about if I alter the procedure?<\/p>\n
I\u2019m not going to clear the cache first, the procedure has a plan in there from the last test, we can use that to see the effects.<\/p>\n
ALTER PROCEDURE OutStandingTotalByStatus\r\nAS\r\n-- This has changed!\r\nSELECT 1;\r\n\r\nSELECT o.OrderStatus, SUM(UnitPrice*Quantity) AS TotalOutstanding\r\nFROM dbo.Orders o\r\nINNER JOIN dbo.OrderDetails od ON o.OrderID = od.OrderID\r\nWHERE ShippingDate IS NULL\r\nGROUP BY OrderStatus;\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO<\/pre>\n
Again perfmon shows a bump in Compiles\/sec and the recompiles\/sec is still at 0. Again, profiler shows why.<\/p>\n
\"Compiles4\"<\/a><\/p>\n
Same as when I ran the sp_recompile, the ALTER PROCEDURE triggered a SP:CacheRemove. The plan was gone from cache at the point the stored procedure ran again, so this was considered a compile, not a recompile.<\/p>\n
btw, for those curious, if I query the plan cache between altering the procedure and running it again, the procedure\u2019s plan really has gone.<\/p>\n
Let\u2019s try something more complex, an alteration of one of the base tables. I\u2019m going to clear the cache first, for reasons that will later be clear<\/p>\n
DBCC FREEPROCCACHE\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO\r\n\r\nALTER TABLE dbo.OrderDetails ADD Filler CHAR(10)\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO<\/pre>\n
Ha! This time perfmon shows a non-zero value for SQLRecompiles\/sec. The profiler trace has a different form too<\/p>\n
\"Compiles5\"<\/a><\/p>\n
There\u2019s no SP:CacheRemove. No SP:CacheInsert either.<\/p>\n
The alteration of the table did not result in SQL going through the plan cache and removing plans for dependant objects. That makes sense if you think about it. There could be millions of plans in cache, for SQL to check each and every one to see if it has a dependency on the table just changed would be terribly time consuming, so it\u2019s not done. What happens instead is that the next time the procedure runs SQL looks in the cache, finds the procedure\u2019s plan (the SP:CacheHit), does the pre-execution validations and finds that one of the base objects has changed since that plan was compiled. The plan is then sent to the optimiser to recompile that plan (the SP:Recompile event)<\/p>\n
Here\u2019s the other interesting thing, from a query of the plan cache<\/p>\n
\"Compiles6\"<\/a><\/p>\n
The usecounts is 2, not 1. I ran that procedure once before altering the table, once after. The alter of the table forced SQL to recompile the plan on the second execution, but the usecount for the plan reflects both executions, the one from before the recompile and the one from after.<\/p>\n
In all the previous cases, when the plan was actually removed from cache and then compiled and inserted the usecount was only 1 because when the plan was removed all related information was removed with it. With a recompile it\u2019s not removed, so the usecounts aren\u2019t reset to 0.<\/p>\n
This is important to note. There are lots of articles (and books even) that say to check plan usecounts as a low usecount is a sign of frequent recompiles. As we can now see, it\u2019s not. It\u2019s a sign of frequent compiles, of the plans being removed from cache and later re-added, recompiles don\u2019t affect the usecount (well, at least not in this case, there may be cases where it does)<\/p>\n
Now try a couple more common cases, see what they show, starting with rebuilding an index.<\/p>\n
DBCC FREEPROCCACHE\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO\r\n\r\nALTER INDEX PK_OrderDetails ON dbo.OrderDetails REBUILD\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO<\/pre>\n
Any guesses?<\/p>\n
\"Compiles7\"<\/a><\/p>\n
It\u2019s a recompile (and the perfmon counters confirm that). As with the previous case, the usecount shown in sys.dm_exec_cached_plans is 2 for the procedure\u2019s plan, not 1<\/p>\n
Lastly, a statistics update. Can anyone guess what\u2019s going to happen here? Anyone?<\/p>\n
DBCC FREEPROCCACHE\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO\r\n\r\n-- Insert a few more rows into OrderDetails at this point\r\n\r\nUPDATE STATISTICS dbo.OrderDetails WITH FULLSCAN\r\nGO\r\n\r\nEXEC dbo.OutStandingTotalByStatus\r\nGO<\/pre>\n
\"Compiles9\"<\/a><\/p>\n
Yup, it\u2019s a recompile.<\/p>\n
It is worth nothing that (in my tests anyway), if at least one row isn\u2019t changed, the stats update has no effect. Perhaps an optimisation that checks whether there have been modifications or not before updating? I\u2019m not sure what\u2019s causing that.<\/p>\n
There is a lot more I could test, SET option changes, memory pressure, configuration changes, etc, but I think I\u2019ve done enough that anyone interested can play themselves for further info.<\/p>\n
Ok, but what\u2019s the use? Was this just a dive into internals with no practical usage? I don\u2019t think so.<\/p>\n
One thing that\u2019s important when investigating SQL problems is to understand what the various counters, events and columns are saying and what they mean. If one is faced with a server with very high SQLCompiles\/sec, it\u2019s a waste of time to go looking at whether automatic or manual stats updates are happening too often. Similarly if the SQLRecompiles\/sec is high, investigating the usage of WITH RECOMPILE and OPTION(RECOMPILE) is completely off track and is going to waste time and not help with solving the problem.<\/p>\n
That\u2019s why I believe it\u2019s important to understand what the various counters, events and columns actually means and what occurrences within SQL affects them. None of us have time to spend a couple days busy investigating something that\u2019s not related to what\u2019s actually wrong with the server based on an incorrect understanding of what SQL is showing us.<\/p>\n","protected":false},"excerpt":{"rendered":"
I want to spend some time over the next few months looking at query compilation and the plan cache, and there’s a couple concepts that I want to get cleared up beforehand. The first of those is around two terms… (Read more)<\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"jetpack_post_was_ever_published":false,"_jetpack_newsletter_access":"","_jetpack_dont_email_post_to_subs":false,"_jetpack_newsletter_tier_id":0,"_jetpack_memberships_contains_paywalled_content":false,"_jetpack_memberships_contains_paid_content":false,"footnotes":"","jetpack_publicize_message":"","jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":false,"jetpack_social_options":{"image_generator_settings":{"template":"highway","default_image_id":0,"font":"","enabled":false},"version":2}},"categories":[23,15,16],"tags":[],"class_list":["post-1254","post","type-post","status-publish","format-standard","hentry","category-execution-plans","category-sql-server","category-syndication"],"jetpack_publicize_connections":[],"jetpack_featured_media_url":"","jetpack_shortlink":"https:\/\/wp.me\/p7h6n-ke","jetpack_sharing_enabled":true,"_links":{"self":[{"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/posts\/1254","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/comments?post=1254"}],"version-history":[{"count":0,"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/posts\/1254\/revisions"}],"wp:attachment":[{"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/media?parent=1254"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/categories?post=1254"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.sqlinthewild.co.za\/index.php\/wp-json\/wp\/v2\/tags?post=1254"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}