Cache tab sliding expiration side effects

[MikeSQ]

I love the functionality of the cache tab displaying the contents of the cache, but it appears to be causing a side effect with sliding expirations. When viewing a page with Glimpse activated, it is accessing the values and refreshing their timeouts.

Environment:

• Glimpse (1.8.6)
  • .AspNet (1.8.0)
  • .Ado (1.7.3)
  • .Elmah (1.1.1)
  • .Mvc4 (1.5.3)
• IIS Express on my dev box
• .NET 4
• MVC 4

Sample Code:

{
    System.Diagnostics.Trace.TraceInformation("Asking for cache entry [" + cacheKey + "]");
    var result = HttpRuntime.Cache[cacheKey];

    if (result == null)
    {
        System.Diagnostics.Trace.TraceInformation("Adding new entry for [" + cacheKey + "]");
         System.Web.Caching.CacheItemRemovedCallback CacheItemDel = new System.Web.Caching.CacheItemRemovedCallback(CacheItemUpdateCallbackMethod);
        HttpRuntime.Cache.Add(cacheKey, cacheObject, null, System.Web.Caching.Cache.NoAbsoluteExpiration, new TimeSpan(0, 1, 0), System.Web.Caching.CacheItemPriority.Normal, CacheItemDel);
    }
    // Stuff
}

private void CacheItemUpdateCallbackMethod(string key, Object value, System.Web.Caching.CacheItemRemovedReason reason)
{
    System.Diagnostics.Trace.TraceWarning("Removed [" + key + "] due to [" + reason.ToString() + "]");
}

Test Results:

When running the above with Glimpse turned on, it produces output similar to this (Notice that all the entries expire at same time):

iisexpress.exe Information: 0 : [10:29 AM] Asking for cache entry [WeatherData595_W_8_635411897400000000]
iisexpress.exe Information: 0 : [10:29 AM] Not found, adding new entry for [WeatherData595_W_8_635411897400000000]
iisexpress.exe Information: 0 : [10:29 AM] Asking for cache entry [WeatherData595_W_8_635411897400000000]

iisexpress.exe Information: 0 : [10:30 AM] Asking for cache entry [WeatherData595_W_8_635411898000000000]
iisexpress.exe Information: 0 : [10:30 AM] Not found, adding new entry for [WeatherData595_W_8_635411898000000000]
iisexpress.exe Information: 0 : [10:30 AM] Asking for cache entry [WeatherData595_W_8_635411898000000000]

iisexpress.exe Information: 0 : [10:31 AM] Asking for cache entry [WeatherData595_W_8_635411898600000000]
iisexpress.exe Information: 0 : [10:31 AM] Not found, adding new entry for [WeatherData595_W_8_635411898600000000]

iisexpress.exe Warning: 0 : [10:32 AM] Removing entry [WeatherData595_W_8_635411898600000000] due to [Expired]
iisexpress.exe Warning: 0 : [10:32 AM] Removing entry [WeatherData595_W_8_635411898000000000] due to [Expired]
iisexpress.exe Warning: 0 : [10:32 AM] Removing entry [WeatherData595_W_8_635411897400000000] due to [Expired]

With it turned off, it produces output similar to this (notice entries expire in-line)

iisexpress.exe Information: 0 : [10:21 AM] Asking for cache entry [WeatherData595_W_8_635411892600000000]
iisexpress.exe Information: 0 : [10:21 AM] Not found, adding new entry for [WeatherData595_W_8_635411892600000000]

iisexpress.exe Information: 0 : [10:22 AM] Asking for cache entry [WeatherData595_W_8_635411893200000000]
iisexpress.exe Information: 0 : [10:22 AM] Not found, adding new entry for [WeatherData595_W_8_635411893200000000]
iisexpress.exe Information: 0 : [10:22 AM] Asking for cache entry [WeatherData595_W_8_635411893200000000]
iisexpress.exe Information: 0 : [10:22 AM] Asking for cache entry [WeatherData595_W_8_635411893200000000]

iisexpress.exe Warning: 0 : [10:22 AM] Removing entry [WeatherData595_W_8_635411892600000000] due to [Expired]

iisexpress.exe Information: 0 : [10:22 AM] Asking for cache entry [WeatherData595_W_8_635411893200000000]
iisexpress.exe Information: 0 : [10:22 AM] Asking for cache entry [WeatherData595_W_8_635411893200000000]

iisexpress.exe Information: 0 : [10:23 AM] Asking for cache entry [WeatherData595_W_8_635411893800000000]
iisexpress.exe Information: 0 : [10:23 AM] Not found, adding new entry for [WeatherData595_W_8_635411893800000000]
iisexpress.exe Information: 0 : [10:23 AM] Asking for cache entry [WeatherData595_W_8_635411893800000000]
iisexpress.exe Information: 0 : [10:23 AM] Asking for cache entry [WeatherData595_W_8_635411893800000000]

iisexpress.exe Warning: 0 : [10:24 AM] Removing entry [WeatherData595_W_8_635411893200000000] due to [Expired]

iisexpress.exe Warning: 0 : [10:25 AM] Removing entry [WeatherData595_W_8_635411893800000000] due to [Expired]

I'm not sure if this is a known side-effect or an unintentional one. It did confuse me for a while when trying to use Glimpse to debug our caching and seeing all the entries build up rather than drop off as I expected them to. Is there a way to see the values without affecting the cache, or should I just keep that tab off in production environments to avoid the behavior?

[CGijbels]

@MikeSQ thanks for the feedback. regarding your question

if this is a known side-effect or an unintentional one

I think the correct answer would be unintentional and an unknown side effect so far as well (as far as I am aware of it).
We've had other users mentioning issues with the Cache tab, especially if there is a lot of data being cached and most of the time disabling that specific tab solves the issue, but of course that means they loose the functionality.

The issue you are talking about is a new one and I'm not sure if we can bypass the cache logic when accessing the cached value, I more thorough investigation is needed then.

We are thinking about having a more per user logic of deciding which tab should be active or not per request and this globally or per user, which basically means that a tab can be disabled by default, but that you could enable it for your specific request (if you have the necessary rights for instance) without needing to adapt the configuration. That way the application does not recycle and you could read the state of the cache at that moment, of course influencing the sliding expiration of everything being accessed at that moment, but then it is by choice and not a continuous process...

Either way that doesn't solve your issue today, so the only option for now is to disable the tab in production, or create your own tab that uses the caching tab for instance and have it run conditionally based on a cookie or other value that you can send in your request.

Hope this helps