Or “Monitoring plan cache usage”

For people interested in the details of how SQL is using and reusing execution plans, there are some useful events in profiler for watching this in detail, under the Stored procedure group:

• SP:CacheMiss
• SP:CacheInsert
• SP:CacheHit
• SP:CacheRemove
• SP:Recompile
• SP:StmtRecompile

Additionally there’s the SQL:StmtRecompile event under the TSQL group.

For now, I just want to look briefly at the CacheMiss and CacheHit events.

One word of caution early on, these are frequently occurring events and it may not be a good idea to trace these on busy production servers. If you do need to, keep the duration of the trace short and the columns to a minimum.

CacheMiss

The cache miss event fires any time SQL looks for the execution plans for an object or ad-hoc batch and does not find it in the plan cache.

For an object (scalar function, multi-statement table-valued function, stored procedure or trigger) the match is done on the object ID (along with some of the connection’s SET options and possibly the database user and c couple other factors¹). For an ad-hoc batch, the match is done on a hash of the text of the batch (along with some of the connection’s SET options and possibly the database user)

When testing stored procedures from Management Studio (or another SQL querying tool), two CacheMiss events will appear in the trace.

What’s going on here?

Let’s start from the bottom and work up. The last event there, the SP:Completed records the completion of the stored procedure and lists both the ObjectID and ObjectName and, if I check in the database, ObjectID 1301579675 does indeed belong to the stored procedure FireCacheEvents.

The second event (the second cache miss) has the same ObjectID and ObjectName. So this is the failed cache lookup for the stored procedure (failed because this is the first time I ran it and the plan was, as a result, not in cache).

The first entry is the one that’s curious. The ObjectName is not populated and the ObjectID doesn’t match anything in the database. So what is the cache lookup trying to find?

The TextData column give a hint. What it’s trying to find is a cached plan for the ad-hoc batch containing the whole of the text submitted to SQL (In this case just ‘EXEC FireCacheEvents’). This too could contain queries (though it doesn’t in this case) and needs a plan lookup. With just an EXEC in the batch, it won’t have a plan and hence won’t be found in cache, but there’s still a lookup for it.

If there was any SELECT, INSERT, UPDATE or DELETE (or MERGE on SQL 2008) statement within that ad-hoc batch, the batch would also be cached and future cache lookups would succeed but, since it’s just an EXEC, there’s no plan to cache.

This additional cache lookup won’t occur if the execution is via RPC (e.g. A .Net call with the SQLCommand.CommandType = CommandType.StoredProcedure) but it will any time there is an ad-hoc SQL batch submitted (e.g. from Management Studio or .Net if the SQLCommand.CommandType is set to CommandType.Text)

That’s ad-hoc batches and stored procs. Let’s try the third possibility – a parameterised query.

This looks semi-familiar. The first CacheMiss is again for the entire of the ad-hoc batch (consisting of the DECLARE and the EXEC in this case). The second looks similar, something in TextData and no ObjectName. This is the parameterised query, identifiable as parameterised by the (@Status Char(1)) parameter definition right at the beginning. Again here the ObjectID is a hash of the text and doesn’t match to a real object in the database.

It is worth noting that, if both the CacheMiss and CacheInsert events are traced, the CacheMiss events will only appear if there is no subsequent CacheInsert for the same ObjectID. If I ran the exact same script as above, but had the SP:Completed, SP:CacheMiss and SP:CacheInsert events in the trace, there would still be only three events recorded, the cache miss for the ad-hoc batch (as that’s not cached there’s no matching CacheInsert event), the CacheInsert for the stored proc and then the SP:Completed. The CacheMiss for the procedure wouldn’t appear, though it’s presence can be intuited from the presence of the CacheInsert.

That should about cover it for the CacheMiss. If the failed cache lookup is for is an ad-hoc batch or parameterised query, the TextData column will be populated with the contents of the batch or query and the ObjectID will be a hash of the text (and shouldn’t match any object in the database). If the failed cache lookup is for a procedure (or function or trigger), the object name column is usually populated (not always) with the name of the object, TextData is blank and the ObjectID matches the ObjectID of the object in the database

CacheHit

Onto the CacheHit event. This, as its name implies, is the opposite to the CacheMiss. The CacheMiss indicates that a lookup to the plan cache failed to find a matching plan. The CacheHit indicates that a lookup to the plan cache succeeded in finding a matching plan (based on object id, set options, maybe user, and various other conditions).

It’s not certain, even if the cache lookup succeeds, that the plan will indeed be used for the execution of the query/batch/procedure as there are a number of stability and optimality related checks that will be done before the plan is used.

So let’s see how this event looks.

EXEC FireCacheEvents
GO
SELECT ID, SomeDate, Status
FROM dbo.TestingCacheEvents
WHERE Status = 'B'
GO 

Two ad-hoc batches, first with just a stored procedure call, second with just an ad-hoc SQL statement.

No big surprises here, not after looking at the CacheMiss events. The first is the CacheMiss for the first of the ad-hoc batches, the one with just the EXEC in it. Since that is not cached, there will be a CacheMiss every time that executes.

The first of the CacheHit events is for the stored procedure. As with the CacheMiss, this CacheHit for the stored procedure has an ObjectID that matches the ObjectID for that procedure in the database, and the ObjectName column is populated with (surprise) the object name while the TextData is blank.

The second CacheHit is for the ad-hoc batch with the SELECT statement. As is probably expected by this point, the ObjectID there is just a hash of the text, the ObjectName is blank and the TextData is populated with the full text of the batch.

In Conclusion

If you’re monitoring cache usage with the CacheMiss and CacheHit events, there are two different ways to identify what the lookup was looking for.

If the lookup was for the plan of a stored procedure, trigger or function, the ObjectID column contains a value that matches the ObjectID for that object in the database. The TextData column is blank and the ObjectName column is (usually) populated with the name of the object. I did encounter a couple of cases where the ObjectName was blank for a CacheMiss event for a stored procedure, not quite sure why. More investigation is necessary.

If the lookup was for the plan of an ad-hoc batch or parameterised query, the ObjectID contains a meaningless value, the ObjectName column is blank and the TextData contains the entire of the batch/query.

It may also be worth mentioning that the DatabaseID column is populated for all CacheMiss and CacheHit events, regardless of what the lookup is looking for. Additionally the DatabaseName column is populated for all CacheHit events (but is not an available column for the CacheMiss)

(1) For anyone who wants more information, there are two excellent resources available from Microsoft:

• Batch Compilation, Recompilation, and Plan Caching Issues in SQL Server 2005
• Plan Caching in SQL Server 2008

Both go extremely deep into caching, what influences matching of plans, plan reuse, recompilations and the plan cache itself.

Reproduction code:

CREATE TABLE TestingCacheEvents (
 ID INT IDENTITY PRIMARY KEY,
 SomeDate DATETIME,
 Status CHAR(1),
 Filler CHAR(300) DEFAULT ' '
);
GO
INSERT INTO TestingCacheEvents (SomeDate, Status)
SELECT TOP (10000)
 DATEADD(dd,FLOOR(RAND(a.object_id+b.column_id*5000)*500),'2000/01/01'),
 CHAR(65+FLOOR(RAND(b.object_id+a.column_id*5000)*10))
 FROM master.sys.columns a CROSS JOIN master.sys.columns b;
GO
CREATE PROCEDURE FireCacheEvents
AS
 SELECT ID, SomeDate, Status
 FROM TestingCacheEvents
 WHERE Status = 'G'
GO