3

I use the Http.Current.Cache to store various values retrieved from my database because my app is to data-intensive. When running my website on my new laptop with VS2017 install (on another laptop with VS2015 I never see this problem), I'm seeing a very strange issue where cached values seem to be randomly cleared- almost in a way to defies logic.

For instance, I have an if clause whose condition is that the cache item in question is not null. My code is definitely following the path through this if statement, but a couple of statements later the debugger shows that the cache item is in fact null- causing my app to fail.

public static SportSeason GetCurrentSportSeason(string sportCode)
{
  SportSeason sportSeason = null;
  string key = "Sheets_SportSeason_" + sportCode;

  int i = 0;
  if (BaseSheet.Settings.EnableCaching && BizObject.Cache[key] != null)
  {
    i = 1;
    sportSeason = (SportSeason)BizObject.Cache[key];
  }
  else
  {
    i = 2;
    sportSeason = GetSportSeasonFromSportSeasonDetails(SiteProvider.Sheets.GetCurrentSportSeason(sportCode));
    BaseSheet.CacheData(key, sportSeason);
  }
  if(sportSeason == null)
  {
    int j = i;
  }
  return sportSeason;
}

I can set a breakpoint in the final if and the variable i is set to 1, but the sportSeason object is NULL (as is the cache entry). How can this be when the only way the code could have entered the first if clause is if the cache item was not null?

Here is a screenshot showing some watch variables with a breakpoint in the final if.enter image description here

This is tough to track down because it happens randomly throughout my business objects. Sometimes I have to refresh the page 3 or 4 times before I see this issues.

How can the cache be invalidated so quickly, and by what? The screenshot shows that there aren't many cached items, so I don't think I'm running out of memory. And no other processes are running which could be clobbering the cache.

EDIT: Through more debugging I've determined that only the cache key that is checked on Line 91 is cleared (set to null) when it is checked again at the breakpoint. All of the other cache records are still there.

EDIT2: I've isolated the problem down to this, although it still seems to defy logic:

    HttpContext.Current.Cache.Insert("ABC", "123", null, DateTime.Now.AddSeconds(600), TimeSpan.Zero);
    int i = 0;

I clear all my cache. When I step over the Cache.Insert statement, my cache count goes to 1. However, the cached item according to that key remains null (see watch window).

enter image description here

Also, if I execute one more statement (the int i = 0), the cache count goes back to zero.

enter image description here

Edit3: It's the AbsoluteExpiration parameter of the Insert() that is killing me. Somehow a clock is off.

If I set the AbsoluteExpiration to 5 hours into the future (300 minutes), it doesn't work. If I set it to 5 hours and one minute (301 minutes) into the future, everything works.

    HttpContext.Current.Cache.Insert("ABC", "123", null, DateTime.Now.AddMinutes(301), TimeSpan.Zero);

The clock on my laptop is 100% accurate and you can see the Intellisense shows the correct time as well. Can the cache be based off of some other clock that is 5 hours off?

enter image description here

Edit4: Looks like someone else is off by 5 hours.

bperniciaro
  • 901
  • 2
  • 12
  • 30
  • in the process you defined , did you tried to save the `web.config` by chance/ – Krsna Kishore Jul 04 '17 at 04:27
  • @Webruster no, nothing was being done except for the page load – bperniciaro Jul 04 '17 at 16:40
  • can you post your pageload code/ – Krsna Kishore Jul 04 '17 at 16:51
  • @Webruster it's happening on every page that accesses my Business layer classes. Is there some type of way to set a breakpoint on a cache value being cleared or determine where that is happening? – bperniciaro Jul 05 '17 at 13:02
  • I believe the problem may reside on the fact of you're going to I=2 and the return value of the function "GetSportSeasonFrom..." is a null - perhaps because you're forgetting to RETURN the value in some part of that function. – David BS Jul 06 '17 at 13:19
  • Are you sure this isnt just a bug in the debugger (new VS versions often have many debugging quirks)? Does it happen in your test/production environments? – Jonas Høgh Jul 06 '17 at 13:31
  • @DavidBS The code is going through #1, but that is contracted by the fact that BizObject.Cache[key] is null right after. – bperniciaro Jul 06 '17 at 14:32
  • @JonasH I am only seeing the problem when I port the code to my new laptop, although it's happening in both VS2015 and VS2017 on the new laptop. I do not see the problem on a different laptop or in my PROD environment. – bperniciaro Jul 06 '17 at 21:53
  • @bperniciaro, your last comment drive me to ask you what exactly is the laptop Windows version. I mean, some DELL and HP computers has a custom Windows version and the problem may reside in your OS environment, not the code or VS'es. See if your HyperThreading is enabled, see BIOS parameters and, if possible, try to run a virtual machine with a regular (and default distribution) Windows there. And if your laptop is a new Lenovo, the problem may be there. – David BS Jul 07 '17 at 01:38
  • @DavidBS It's a standard Windows 10 Pro. I think I may have isolated the problem pretty well now, check latest edit. – bperniciaro Jul 07 '17 at 01:58
  • Really, really weird @bperniciaro! But why this "bug" occurs only in the laptop? The problem must be due to the environment (hardware, Windows or Windows + hardware). – David BS Jul 07 '17 at 02:38
  • @DavidBS It has something to do with the internal clock and must be isolated to Windows 10 Pro. Check my latest edit someone else had to edit their AbsoluteExpiration for 5 hours into the future as well. Strange thing is the laptop that works is also running Windows 10, but the Home edition. Clocks are set identically. – bperniciaro Jul 07 '17 at 02:51

3 Answers3

7

The fix is to always use DateTime.UtcNow instead of DateTime.Now when specifying the AbsoluteExporation parameter.

Do this:

HttpContext.Current.Cache.Insert("ABC", "123", null, DateTime.UtcNow.AddMinutes(1), System.Web.Caching.Cache.NoSlidingExpiration);

Not this:

HttpContext.Current.Cache.Insert("ABC", "123", null, DateTime.Now.AddMinutes(1), System.Web.Caching.Cache.NoSlidingExpiration);

When I do this, it correctly recognizes that the cache is valid and I can retrieve the value. As to why this is required on my Windows 10 Pro laptop but not on my Windows 10 Home, I have no idea.

bperniciaro
  • 901
  • 2
  • 12
  • 30
  • 1
    If you're using a different format of datetime it may impact in some internal Windows function. I had same problem sometimes when user was using HH:MM format... – David BS Jul 08 '17 at 14:07
2

You can add a callback function that can tell you why an item was removed:

https://msdn.microsoft.com/en-us/library/7kxdx246.aspx

You specify the callback when adding an item, and it will be fired when the item is removed. Put a breakpoint or logging output in there to print out the CacheItemRemovedReason argument.

If that doesn't help you, you might try the debugging steps laid out in the top answer to ASP.NET HttpContext Cache removes right after insertion. This may catch if the app is terminating.

Chris Shain
  • 50,833
  • 6
  • 93
  • 125
  • It's an issue with the system time. I have to set my AbsoluteExpiration time at least 5 hours into the future or it gets immediately invalidated. – bperniciaro Jul 07 '17 at 02:48
0

Review your IIS application pool recycling options to rule out a recycle event. Because an application pool recycle, will clear your cache.

Per the App pool recycling settings docs:

You can specify that IIS recycle an application pool at set intervals (such as every 180 minutes), at a specific time each day, or after the application pool receives a certain number of requests. You can also configure the element to restart the application pool when the worker process virtual memory and physical memory usage reaches a specific threshold.

Even changing your config can recycle the app pool.

Ensure that no other apps are sharing your app pool and then turn on recycle logging and reproduce the issue. See if the cache disappearance is correlated with an app pool recycle in the log. If so, go from there to determine why the recycle is happening and then make a configuration change so app pool doesn't recycle during normal operating hours.

Taterhead
  • 5,763
  • 4
  • 31
  • 40
  • 1
    I think the problem with this theory is that the code followed through the (1) path, at which point the cache values must have been loaded. If the cache was cleared after that point, then all of the cache should be empty. However, if you look at the watch variables in my screenshot, you can see that many of my items are still in cache. – bperniciaro Jul 06 '17 at 23:34
  • 1
    I validated that there are no app pool recycle operations occurring. – bperniciaro Jul 06 '17 at 23:57