What is causing my httpcontext.cache to be removed

We have a web application that retrieves a lot of data from a SOAP webservice and takes about 4 to 5 minutes to do so. To make sure users are not bothered by this, the data is cached like so:

//using Nlog to log caching behaviour
private Logger log = LogManager.GetCurrentClassLogger();
//a public actionresult to get the summaries with an ajax call or site24x7 service
public ActionResult GetSummariesAsync()
{
  log.Info(String.Format("GetSummariesAsync called"));
  List<ProjectDataSummary> summaries = GetAllSummaries();
  log.Info(String.Format("{0} summaries found", summaries.Count));
  List<ProjectDataSummary> cache = HttpContext.Cache["SummariesCache"] as List<ProjectDataSummary>;
  log.Info(String.Format("{0} in cache", cache.Count));

  return Json(summaries, JsonRequestBehavior.AllowGet);
}
private List<ProjectDataSummary> GetAllSummaries()
{
  List<ProjectDataSummary> summaries = new List<ProjectDataSummary>();
  //use setting in web.config if we want to force no cache, but set to false in released version
  if (ConfigurationManager.AppSettings["NoCache"] == "true")
  {
    summaries = _service.GetAllSummaries();
  }
  else
  {
    //get summaries from cache if available
    summaries = HttpContext.Cache["SummariesCache"] as List<ProjectDataSummary>;
    if (summaries == null)
    {
      //cache empty, retrieve values
      summaries = _service.GetAllSummaries();
      //cache it
      HttpContext.Cache.Add("SummariesCache", summaries, null, new DateTime(DateTime.Now.Year, DateTime.Now.Month, DateTime.Now.Day, 23, 59, 59), Cache.NoSlidingExpiration, CacheItemPriority.NotRemovable, new CacheItemRemovedCallback(this.cacheCallback));
    }
  }
  return summaries;
}
private void cacheCallback(String K, Object v, CacheItemRemovedReason r)
{
  CacheItemRemovedReason reason = r;
  log.Info("Cache expired, reason: {0}", r.ToString());
}

I have a service from www.site24x7.com hit the cache creation every hour so in theory it should hit it a bit past 0:00 am and make it create another cache. But for some reason the cache gets removed and the site creates a new one several times a day, also bothering users with extremely long loading times.

Here is a part from my Nlog log:

2015-09-22 18:31:07.8746 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 18:31:07.8901 GetSummariesAsync Info 263 summaries 
2015-09-22 18:31:07.8901 GetSummariesAsync Info 263 in cache 
2015-09-22 18:52:15.9684 cacheCallback Info Cache expired, reason: Removed 
2015-09-22 19:02:06.9839 cacheCallback Info Cache expired, reason: Removed 
2015-09-22 19:23:08.3590 cacheCallback Info Cache expired, reason: Removed 
2015-09-22 19:31:42.7182 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:32:15.0776 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:32:46.2495 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:33:01.8276 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:33:18.3746 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:33:34.8589 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:34:10.7182 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:34:15.4215 GetSummariesAsync Info 263 summaries 
2015-09-22 19:34:15.4215 GetSummariesAsync Info 263 in cache 
2015-09-22 19:35:07.3121 GetSummariesAsync Info 263 summaries 
2015-09-22 19:35:07.3121 GetSummariesAsync Info 263 in cache 
2015-09-22 19:36:07.9213 GetSummariesAsync Info 263 summaries 
2015-09-22 19:36:07.9213 GetSummariesAsync Info 263 in cache 
2015-09-22 19:36:19.5309 GetSummariesAsync Info 263 summaries 
2015-09-22 19:36:19.5309 GetSummariesAsync Info 263 in cache 
2015-09-22 19:36:36.3588 GetSummariesAsync Info 263 summaries 
2015-09-22 19:36:36.3588 GetSummariesAsync Info 263 in cache 
2015-09-22 19:37:07.9996 GetSummariesAsync Info 263 summaries 
2015-09-22 19:37:07.9996 GetSummariesAsync Info 263 in cache 
2015-09-22 19:37:33.7183 GetSummariesAsync Info 263 summaries 
2015-09-22 19:37:33.7183 GetSummariesAsync Info 263 in cache 
2015-09-22 19:37:59.8747 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 19:37:59.8747 GetSummariesAsync Info 263 summaries 
2015-09-22 19:37:59.8747 GetSummariesAsync Info 263 in cache 
2015-09-22 19:44:00.2496 cacheCallback Info Cache expired, reason: Removed 
2015-09-22 19:54:25.2183 cacheCallback Info Cache expired, reason: Removed 
2015-09-22 20:34:55.3589 GetSummariesAsync Info GetSummariesAsync called 
2015-09-22 20:34:55.3745 GetSummariesAsync Info 263 summaries 
2015-09-22 20:34:55.3745 GetSummariesAsync Info 263 in cache 
2015-09-22 20:44:32.5153 cacheCallback Info Cache expired, reason: Removed 
2015-09-22 20:56:38.8746 cacheCallback Info Cache expired, reason: Removed

Edit

I have Implemented the answer NightOwl888 has given, but to no avail, the cache keeps being removed.

Here is a section from my current Nlog file:

2015-09-27 20:05:29.9682 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 20:05:29.9682 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 20:23:51.5464 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:23:51.5464 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:23:51.5464 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:25:48.1714 Models.CachingBase`1.GetItemsCache Info Cache fileEntries created 
2015-09-27 20:25:48.1714 Models.CachingBase`1.GetItemsCache Info Cache idCertificaat created 
2015-09-27 20:26:46.3588 Controllers.HomeController.Index Info No cache found, Home/Index needs to create the cash Async 
2015-09-27 20:26:46.7963 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:40.0) Gecko/20100101 Firefox/40.0 vanuit Host: 88.159.95.251 
2015-09-27 20:27:26.9682 Models.CachingBase`1.GetItemsCache Info Cache GebouwProjectenSummaries created 
2015-09-27 20:27:26.9682 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 20:27:26.9682 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 20:33:48.7340 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:33:48.7340 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:33:48.7340 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:38:21.0151 Models.CachingBase`1.GetItemsCache Info Cache fileEntries created 
2015-09-27 20:38:21.0151 Models.CachingBase`1.GetItemsCache Info Cache idCertificaat created 
2015-09-27 20:38:21.0620 Controllers.HomeController.Index Info No cache found, Home/Index needs to create the cash Async 
2015-09-27 20:43:41.0620 Controllers.HomeController.Index Info No cache found, Home/Index needs to create the cash Async 
2015-09-27 20:46:29.0620 Models.CachingBase`1.GetItemsCache Info Cache GebouwProjectenSummaries created 
2015-09-27 20:57:21.5776 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:57:21.5776 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:57:21.5776 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 20:58:23.9553 Models.CachingBase`1.GetItemsCache Info Cache fileEntries created 
2015-09-27 20:58:23.9553 Models.CachingBase`1.GetItemsCache Info Cache idCertificaat created 
2015-09-27 20:58:23.9839 Controllers.HomeController.Index Info No cache found, Home/Index needs to create the cash Async 
2015-09-27 21:04:24.5151 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 21:04:24.5151 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 21:05:31.8277 Models.CachingBase`1.GetItemsCache Info Cache fileEntries created 
2015-09-27 21:05:31.8277 Models.CachingBase`1.GetItemsCache Info Cache idCertificaat created 
2015-09-27 21:05:31.8432 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Site24x7 vanuit Host: 72.5.230.111 
2015-09-27 21:06:03.5307 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Site24x7 vanuit Host: 72.5.230.111 
2015-09-27 21:06:36.3433 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Site24x7 vanuit Host: 120.138.27.125 
2015-09-27 21:06:40.2651 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Site24x7 vanuit Host: 119.81.237.98 
2015-09-27 21:07:08.6401 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Site24x7 vanuit Host: 120.138.27.125 
2015-09-27 21:07:11.4057 Models.CachingBase`1.GetItemsCache Info Cache GebouwProjectenSummaries created 
2015-09-27 21:07:11.4057 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 21:07:11.4057 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 21:07:11.4057 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 21:07:11.4057 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 21:07:11.4214 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 21:07:11.4214 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 21:07:11.4214 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 21:07:11.4214 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 21:07:11.4214 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 21:07:11.4214 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 21:07:12.5620 Controllers.HomeController.GetSummariesAsync Info GetSummariesAsync triggered by User-Agent: Site24x7 vanuit Host: 119.81.237.98 
2015-09-27 21:07:12.5620 Controllers.HomeController.GetSummariesAsync Info 263 summaries found 
2015-09-27 21:07:12.5620 Controllers.HomeController.GetSummariesAsync Info 263 in cache found 
2015-09-27 21:15:32.4370 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 21:15:32.4370 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed 
2015-09-27 21:15:32.4370 Controllers.HomeController.cacheCallback Info Cache expired, reason: Removed

What you can see is that Site24x7 sometimes calls the GetSummariesAsync function multiple times in a row.

And that users also (although very few times) experience problems.

The time between the creation of the cash and its removal can be as short as 8 minutes.

I have now disabled my site24x7 checks to see if that is the culprit.

标签： c# asp.net-mvc caching site24x7

3条回答

一夜七次

2楼-- · 2019-08-12 09:37

I don't know if this is the root of your problem, but I see that you have a race condition caused by multiple threads calling your GetAllSummaries method.

It's possible that you are getting false log entries when multiple threads are populating the cache (caused by the excess entries being removed because of collisions) and users are only experiencing problems because of multiple threads competing for system resources before the cache is populated.

First of all, take a look at the documentation of the Cache.Add method:

Calls to this method will fail if an item with the same key parameter is already stored in the Cache. To overwrite an existing Cache item using the same key parameter, use the Insert method.

And more importantly:

if you use the Add method and an item with the same name already exists in the cache, the method will not replace the item and will not raise an exception.

(emphasis added)

In addition, your cache checking code is not thread-safe. More than one thread can run the GetAllSummaries method because the cache will not have a value until the first call to it returns. And since the Add method doesn't throw an exception because of the duplicate, that effort is just wasted.

You can fix that by:

Making an object to wrap the cache with to make the multiple calls that you have to the cache thread-safe.
Using a double-checked locking pattern to ensure only one thread is let through to get the data.
Using a static instance of the cache wrapper, which ensures all threads use the same thread-locking code.

SummariesCache

public sealed class SummariesCache
{
    private ReaderWriterLockSlim synclock = 
        new ReaderWriterLockSlim(LockRecursionPolicy.NoRecursion);

    public List<ProjectSummaryData> GetSummaries(
        ISummariesService service, 
        ref CacheItemRemovedCallback onRemoveCallback)
    {
        List<ProjectDataSummary> summaries;
        string key = "SummariesCache";
        bool success;

        synclock.EnterReadLock();
        try
        {
            success = TryGetCacheValue(key, out summaries);
        }
        finally
        {
            synclock.ExitReadLock();
        }

        if (!success)
        {
            synclock.EnterWriteLock();
            try
            {
                if (!TryGetCacheValue(key, out summaries))
                {
                    //cache empty, retrieve values
                    summaries = service.GetAllSummaries();

                    // load the cache (using Insert)
                    HttpContext.Current.Cache.Insert(
                        key, 
                        summaries, 
                        null, 
                        new DateTime(DateTime.Now.Year, DateTime.Now.Month, DateTime.Now.Day, 23, 59, 59), 
                        Cache.NoSlidingExpiration, 
                        CacheItemPriority.NotRemovable, 
                        onRemoveCallback
                    );
                }
            }
            finally
            {
                synclock.ExitWriteLock();
            }
        }

        return summaries;
    }

    private bool TryGetCacheValue(string key, out List<ProjectSummaryData> value)
    {
        value = HttpContext.Current.Cache["key"] as List<ProjectDataSummary>;
        if (value != null)
        {
            return true;
        }
        return false;
    }
}

Usage

// Use a static instance of the cache to ensure all threads use it.
private static _summariesCache = new SummariesCache();

private List<ProjectDataSummary> GetAllSummaries()
{
    List<ProjectDataSummary> summaries = new List<ProjectDataSummary>();
    //use setting in web.config if we want to force no cache, but set to false in released version
    if (ConfigurationManager.AppSettings["NoCache"] == "true")
    {
        summaries = _service.GetAllSummaries();
    }
    else
    {
        summaries = _summariesCache.GetSummaries(_service, new CacheItemRemovedCallback(cacheCallback));
    }
    return summaries;
}

private void cacheCallback(String K, Object v, CacheItemRemovedReason r)
{
    CacheItemRemovedReason reason = r;
    log.Info("Cache expired, reason: {0}", r.ToString());
}

NOTE: Most of this code was borrowed from Micro-Caching in .NET. If you prefer, you can just use that solution.

0人赞添加讨论(0) 举报

够拽才男人

3楼-- · 2019-08-12 09:39

Apologies if this answer doesn't help but I've seen a similar issue before so I thought I'd post.

I've seen an issue before when the logger (in this case nlog) actually writes to the application directory in particular the bin folder. By doing this it actually triggers the website to reload its domain logic resulting in session and cache data being invalidated.

Again, sorry if this doesn't help you but I thought it was worth mentioning.

0人赞添加讨论(0) 举报

Anthone

4楼-- · 2019-08-12 09:47

HttpContext.Cache is only available during the lifetime of the application and that lifetime is tied to the IIS App Pool. When the App Pool recycles or terminates the cache is wiped out. Unfortunately you have no control over when IIS will do this. Off the top of my head I can see 2 options or (maybe a mix of both).

Store your cache in a local DB. Would still be slower than an in-memory cache but probably faster than the web service.
Re-load your cache on application start (inside the Application_Start() function of the Global.asax file) instead of or in addition to your periodic ping (depending on your requirements).

0人赞添加讨论(0) 举报