In a production Azure application, our Web roles were repeatedly running into an error in ELMAH that we found nearly impossible to reproduce. It never occurred running in local IIS, IIS Express or anything.
The exact error message was an ArgumentOutOfRangeException:
System.ArgumentOutOfRangeException: Specified argument was out of the range of valid values. Parameter name: utcDate at System.Web.HttpCachePolicy.UtcSetLastModified(DateTime utcDate) at System.Web.HttpCachePolicy.SetLastModified(DateTime date) at System.Web.UI.Page.InitOutputCache(OutputCacheParameters cacheSettings) at System.Web.UI.Page.ProcessRequest(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint) at System.Web.UI.Page.ProcessRequest() at System.Web.UI.Page.ProcessRequest(HttpContext context) at System.Web.Mvc.OutputCacheAttribute.OnResultExecuting(ResultExecutingContext filterContext) at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(IResultFilter filter, ResultExecutingContext preContext, Func`1 continuation) at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(IResultFilter filter, ResultExecutingContext preContext, Func`1 continuation) at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(IResultFilter filter, ResultExecutingContext preContext, Func`1 continuation) at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(ControllerContext controllerContext, IList`1 filters, ActionResult actionResult) at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass27.b__24(IAsyncResult asyncResult) at System.Web.Mvc.AsyncController.<>c__DisplayClass19.b__14(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.<>c__DisplayClass4.b__3(IAsyncResult ar) at System.Web.Mvc.AsyncController.EndExecuteCore(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.<>c__DisplayClass4.b__3(IAsyncResult ar) at System.Web.Mvc.MvcHandler.<>c__DisplayClass6.<>c__DisplayClassb.b__4(IAsyncResult asyncResult) at System.Web.Mvc.Async.AsyncResultWrapper.<>c__DisplayClass4.b__3(IAsyncResult ar) at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously
Notice anything missing?
Everything is in the “System.Web” namespace, meaning that all of this is framework code and not application code. This begs the question: Why is this happening?
Apparently, something in the framework (which was indirectly affected by our app) was causing this.
After many, many weeks of on again, off again debugging, I finally discovered the problem:
The key line in the stack trace was the one mentioning the “System.Web.Mvc.OutputCacheAttribute”. This attribute allows you to specify parameters for the ASP.NET framework to use when caching the output of your MVC Actions. Alternately, to allow you to vary these parameters outside of the code, you can use Output Cache Profiles to configure these parameters in your web.config. This is how we do it in our application.
So, I looked at our profiles in the web.config and the one I called “NoCache” stood out. This profile, you guessed it, doesn’t actually cache, it’s for things we don’t want to cache.
Here’s the web.config entry for that:
<system.web> ... <caching> <outputCacheSettings> <outputCacheProfiles> ... <add name="NoCache" noStore="true" duration="0" varyByParam="none" /> </outputCacheProfiles> </outputCacheSettings> </caching> ... </system.web>
The other profiles were rather simple. This one did something unusual, namely not caching. It was also doing this by relying on the ‘duration=”0”’ to accomplish this. Given that this problem seemed to be about values being out range, I theorized that the framework was attempting to add things to the cache with a duration of “0”, rather than not caching. So, after re-reading the MSDN reference on the Output Cache Profile, I noticed that it also had an “enabled” property. I’m not really sure how I missed this before.
So, I changed this profile to the following:
<add name="NoCache" enabled="false" noStore="true" varyByParam="none" />
Since we could never reproduce this failure outside of production, we decided to take the risk and deploy this change. We crossed our fingers, deployed the fix and waited.
After a few weeks, we have not seen the exception even once. Consider this bug squashed.
Hopefully, this can save someone else some serious debugging time in the future.