New Cache-Related Counters in the Query Subcube Verbose Event

Reposted from Chris Webb's blog with the author's permission.

I was studying a Profiler trace run on a SSAS 2012 Multidimensional instance today, and I noticed some new information was being returned in the Query Subcube Verbose event relating to caching. The Query Subcube Verbose event is fired every time the Formula Engine requests data from the Storage Engine, specifically when the Formula Engine requests a subcube of data from a single measure group, and one of these requests may or may not be answered using the cache associated with that measure group. If the request is answered from cache then performance is likely to be very good; however in some (but by no means all) cases, if the Storage Engine has to go to disk to answer the request then performance could be poor.

It has always been possible to tell whether the subcube request associated with a Query Subcube Verbose event is answered from cache or not. Let’s take as an example a query that returns a single cell of data from a super-simple cube. Here’s what I see in Profiler when I run my query on a cold cache:

Out of the three red boxes in this screenshot, in the top box you can see the Progress Report Begin/End events associated with the Query Subcube Verbose event that’s in the middle red box – these show the Storage Engine is reading data from disk. The Event Subclass column for the Query Subcube Verbose event shows that it is requesting non-cache data, and the Resource Usage event shows the number of rows scanned and returned. If I run the query a second time without clearing the cache – ie on a warm cache – then I see the following:

The Event Subclass column for the Query Subcube Verbose event shows the data it is requesting is being retrieved from cache, there are no Progress Report Begin/End events (as you would expect) and the Resource Usage event shows no rows read.

Looking at the Query Subcube Verbose event itself, there are now two groups of information returned:

The top red box shows information on the granularity of the request, as has been the case since SSAS 2005. The bottom red box contains the new stuff. These four values are reported at the point in time after the Query Subcube Verbose event has executed and are:

• CacheEntries: the number of entries in the measure group cache after the subcube request has been executed. This value will continue to increment and only be reset back to zero after the measure group cache has been cleared (either as a result of an XMLA clear cache or some other event, like processing, that clears the cache). The execution of the subcube request will itself usually result in an entry being made into the cache, so it’s unlikely you’ll see this value showing as zero. If you don’t see this value incrementing you might be running into this issue.
• CacheHits: the number of times that a subcube request has been answered from this particular measure group cache since the last time this measure group was processed (note, not the last time the cache was cleared).
• CacheSearches: the number of times that the measure group cache has been searched since the last time this measure group was processed. This value may increment by more than one for each subcube request.
• CacheEvictions: the number of times that an entry has been evicted from the measure group cache since the last time the measure group was processed. You’ll see this value go up, for instance, if you run an XMLA clear cache; if you see it go up at other times then Bad Things are likely to be happening – you may be running out of memory on the server for example, and SSAS might be evicting data from the cache as a result.

Together these values give us a much more detailed view of what’s going on in the individual storage engine caches than we’ve ever had before, and will prove to be very useful for performance tuning and also when building cache warmers. That said it’s not going to be easy to use this information when you’ve got complex queries that generate a lot of subcube requests, but it’s better than not having the information at all.

[Thanks once again to Akshai Mirchandani for answering my questions on this!]

Chris has been working with Microsoft BI tools since he started using beta 3 of OLAP Services back in the late 90s. Since then he has worked with Analysis Services in a number of roles (including three years spent with Microsoft Consulting Services) and he is now an independent consultant specialising in complex MDX, Analysis Services cube design and Analysis Services query performance problems. His company website can be found at http://www.crossjoin.co.uk and his blog can be found at http://cwebbbi.wordpress.com .