Or “Plan cache monitoring – insert and remove”

Previously I took a look at the CacheHit and CacheMiss events to see how they behave and how to identify what’s been searched for in the cache. in this follow up, I want to take a similar look at the CacheInsert and CacheRemove events, see when they fire and how to identify the objects that they relate to.

Again, a word of caution, these can be frequently occurring events on busy servers and so traces should be kept short and to a minimum of events and columns. That said, these should occur a lot less often than the CacheHit and CacheMiss events. If they are occurring very frequently it may indicate that the SQL Server is not reusing plans efficiently.

CacheInsert

The CacheInsert event fires after a CacheMiss. The search for a matching plan in the cache failed, firing a CacheMiss event. Since there’s no plan, the optimiser is invoked to generate one and then that plan is inserted into the plan cache before the Query Execution engine begins execution.

The event is fairly simple, though of course there are a few surprises (what in SQL doesn’t have?).

Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM TestingCacheEvents
WHERE Status =  'C'

Three CacheInsert events for two batches. The first is simple enough, it’s the insert of the plan for the stored procedure. The procedure name is in the TextData column and the procedure’s ID is in the ObjectID column. The ObjectName column is not populated for this event.

The second and third Cacheinsert events are the interesting ones. The second one shows a parameterised version of the ad-hoc SQL statement, while the third shows an unparameterised version of the same ad-hoc SQL statement. Clearly this query was simple enough to qualify for auto-parameterisation. So, are there two plans for this been inserted into cache? To answer that one, I need to switch over to SSMS and query the plan cache.

select usecounts, size_in_bytes, cacheobjtype, objtype, st.text,  qp.query_plan
 from sys.dm_exec_cached_plans cp
 cross apply  sys.dm_exec_sql_text(cp.plan_handle) st
 cross apply  sys.dm_exec_query_plan(cp.plan_handle) qp
 where st.text not like  '%sys.dm_exec%'

Well, there are three entries and the Cache Object Type is listed as compiled plan for all three, but there’s something different between them. Take a look at the size in bytes for the ad-hoc and prepared statements. The ad-hoc is less than half the size of the prepared. That’s not the only thing different. If I open up the execution plans, the exec plan for the prepared statement looks normal. There’s a clustered index scan (there are no nonclustered indexes on this table yet) and a select operator. The plan for the adhoc statement however…

There’s something missing here, like the rest of the plan. Ok, so the entry with the ad-hoc type is not a complete plan, so what is it?

There doesn’t seem to be anything on MSDN on this (at least nothing I could find), but two of Kalen’s books¹. (Inside Microsoft SQL Server 2005: Query Tuning and Optimisation, page 283; Microsoft SQL Server 2008 Internals, page 533) mention this. These ad-hoc entries are shell queries, cached just to make the parameterised form of the query easier to find. All the execution plan contains for these shell queries is a pointer to the plan for the parameterised version of the query.

For the ad-hoc query that gets inserted as a shell plan and the parameterised query, the objectID is, as with the CacheHit and CacheMiss events, a hash of the query text and does not match to any object in the database. The full text of the batch is then given in the TextData column.

I think that’s enough for CacheInsert. On to it’s opposite.

CacheRemove

The CacheRemove event fires, as one would expect, when a plan is removed from cache. The interesting question is, when does that occur?

Is it every event that could possibly result in an inefficient or invalid plan, or just memory pressure and explicit cache flushes that trigger the CacheRemove event?

Let’s see…

As an aside, I’m going to add a nonclustered index to the table that I’m using, so that the update of statistics will have an effect. Otherwise the only execution path possible is a table scan, and changing statistics won’t affect that.

CREATE NONCLUSTERED INDEX idx_TestingCacheEvents_Status
 ON  TestingCacheEvents (Status)
GO

Right, onto the testing.

Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM  TestingCacheEvents
WHERE Status = 'C'
GO
DBCC FREEPROCCACHE -- Gone.  All gone
WAITFOR DELAY '00:00:05'
GO
Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM  TestingCacheEvents
WHERE Status = 'C'
GO
DBCC  FREEPROCCACHE(0x0500060063A9355540614285000000000000000000000000) -- Just one removed, the proc
WAITFOR DELAY '00:00:05'
GO
Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM  TestingCacheEvents
WHERE Status = 'C'
GO
exec sp_recompile  'TestingCacheEvents' -- recompile on the table, both proc and ah-hoc plans  invalidated.
WAITFOR DELAY '00:00:05'
GO
Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM  TestingCacheEvents
WHERE Status = 'C'
GO
UPDATE TOP(1)  TestingCacheEvents
 SET Status = 'C'
 WHERE Status = 'B'
UPDATE STATISTICS TestingCacheEvents WITH FULLSCAN
WAITFOR DELAY  '00:00:05'
GO
Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM  TestingCacheEvents
WHERE Status = 'C'
GO
ALTER TABLE  TestingCacheEvents ALTER COLUMN FILLER CHAR(325)
WAITFOR DELAY '00:00:05'
GO
Exec FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM  TestingCacheEvents
WHERE Status = 'C'
GO

Well, this is interesting…

The only things that caused the CacheRemove event to fire were the two DBCC FreeProcCache, the first that, as can be seen from the EventSubClass, cleared the entire plan cache, and the second that cleared a single plan.

If I go back and look at the whitepaper Plan Caching in SQL Server 2008, it differentiates between removing a plan from cache (which memory pressure and cache flushes do) and invalidating the plan (which recompiles, schema changes, stats changes and the like do). Based on that whitepaper and these results, I would conclude that the CacheRemove event only fires when the plan is actually removed from cache, not when it’s just invalidated. The invalidation of a plan simply results in a recompile next time the plan is needed.

Now that the question of when it appears is answered, let’s finish with what it looks like.

There are two possible formats for this event, and it’s the EventSubClass that shows which of the two the particular event is.

The first possibility is when all of the plan cache has been flushed, identified by a EventSubClass of “2 – ProcCacheFlush”. This will be a result of a DBCC FREEPROCCACHE and some server reconfiguration events. In this case, there will be no ObjectID and the text data will simply state that the cache has been flushed.

The second possibility is more interesting, especially if monitoring plans being aged out of memory. An EventSubClass of “1 – Compplan Remove” identifies a single plan being removed from cache. These are fired when either a single plan or part of the plan cache is cleared. Examples here are DBCC FREEPROCCACHE with a plan or SQL handle passed to it, DBCC FLUSHPROCINDB, database reconfigurations (restore, detach, offline)

With the one, the ObjectID does have a value and it’s the ObjectID of the pbject whose plan is being thrown out of cache. As with all the other cache events, for ad-hoc queries the ObjectID is just a hash of the query text and only really useful for matching to CacheMiss, CacheHit and CacheInsert events and the object name or ad-hoc batch appears in the TextData

That’s more than I planned to write, but CacheRemove turned out to be a little more complex than I expected. Next up, the last part of this sort series – the recompile events.