Uploaded image for project: 'Spring.NET'
  1. Spring.NET
  2. SPRNET-1555

Web context doesn't fail fast on first request

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 2.0 M2
    • Fix Version/s: FUTURES
    • Component/s: Spring-NET-WEB
    • Labels:
    • Environment:
      IIS8 Express, .NET 4.5

      Description

      This problem has lead to multiple issues in trying to debug spring components that have some sort of error when they are first created, or are misconfigured. In effect, Spring is unable to detect when the "first request" fails to create the root context, and will then subsequently request the root context, causing it to attempt to initialize a second time. The failure to create the context the first time can leave the app domain in an inconsistent state and attempting to create it a second time can mask the original error.

      In my particular example, I had a (IDisposable) singleton that opened a file handle when initialized. A singleton initialized later on failed, preventing the context from being created. The first singleton is not properly disposed and the file was left opened. Not realizing that the first attempt to initialize the web application context has failed, spring attempts to initialize it a second time the next time GetRootContext() is called. This second time, a second, new instance of the first singleton (the one that WASN'T failing) attempts to open the same file, but this time can't. The error that's now reported is a file lock timeout exception, masking the initial problem! If you were ever puzzled why you had singletons being initialized more than once, or very puzzling logs corresponding to errors, this is why!

      Please read the following stack trace and I'll explain why this happens:

      2013-09-27 13:41:43.9842|ERROR|Spring.Context.Support.WebApplicationContext|failed creating context 'spring.root', Stacktrace:
         at Spring.Context.Support.WebApplicationContext.GetContextInternal(String virtualPath)
         at Spring.Context.Support.WebApplicationContext.GetRootContext()
         at Spring.Context.Support.WebSupportModule.Init(HttpApplication app)
         at System.Web.HttpApplication.InitModulesCommon()
         at System.Web.HttpApplication.InitIntegratedModules()
         at System.Web.HttpApplication.InitInternal(HttpContext context, HttpApplicationState state, MethodInfo[] handlers)
         at System.Web.HttpApplicationFactory.GetNormalApplicationInstance(HttpContext context)
         at System.Web.HttpApplicationFactory.GetApplicationInstance(HttpContext context)
         at System.Web.HttpRuntime.ProcessRequestInternal(HttpWorkerRequest wr)
         at System.Web.HttpRuntime.ProcessRequestNow(HttpWorkerRequest wr)
         at _dynamic_System.Web.HttpRuntime.ProcessRequestNow(Object , Object[] )
         at Spring.Reflection.Dynamic.SafeMethod.Invoke(Object target, Object[] arguments)
         at Spring.Context.Support.WebApplicationContext..cctor()
         at Spring.Context.Support.WebApplicationContext.GetRootContext()
         at Spring.Context.Support.WebSupportModule.Init(HttpApplication app)
         at System.Web.HttpApplication.RegisterEventSubscriptionsWithIIS(IntPtr appContext, HttpContext context, MethodInfo[] handlers)
         at System.Web.HttpApplication.InitSpecial(HttpApplicationState state, MethodInfo[] handlers, IntPtr appContext, HttpContext context)
         at System.Web.HttpApplicationFactory.GetSpecialApplicationInstance(IntPtr appContext, HttpContext context)
         at System.Web.HttpApplicationFactory.GetPipelineApplicationInstance(IntPtr appContext, HttpContext context)
         at System.Web.Hosting.PipelineRuntime.InitializeApplication(IntPtr appContext)
      

      System.Web.HttpRuntime.ProcessRequestInternal() SWALLOWS the exception thrown from the spring context initialization, causing WebApplicationContext's constructor from realizing that it's failed:

      WebApplicationContext.cs
                      if (beforeFirstRequest)
                      {
                          try
                          {
                              string firstRequestPath = HttpRuntime.AppDomainAppVirtualPath.TrimEnd('/') + "/dummy.context";
                              s_weblog.Info("Forcing first request " + firstRequestPath);
                              SafeMethod fnProcessRequestNow = new SafeMethod(typeof(HttpRuntime).GetMethod("ProcessRequestNow", BindingFlags.Static | BindingFlags.NonPublic));
                              SimpleWorkerRequest wr = new SimpleWorkerRequest(firstRequestPath, string.Empty, new StringWriter());
                              fnProcessRequestNow.Invoke(null, new object[] { wr });
                              //                        HttpRuntime.ProcessRequest(
                              //                            wr);
                              s_weblog.Info("Successfully processed first request!");
                          }
                          catch (Exception ex)
                          {
                              s_weblog.Error("Failed processing first request", ex);
                              throw;
                          }
                      }
      

      This code fails because "Successfully processed first request!" is output in the logs even when this is not the case. "Failed processing first request" is NEVER output.

      This is not straightforward to fix since HttpRuntime can't be altered and there is no direct code path that involves anything passed to HttpRuntime.ProcessRequestNow that can record an exception being thrown. The most direct fix I can think of would be to have WebApplicationContext or WebSupportModule catch the exception and stash it in a static field to later retrieve on the other 'side' of the HttpRuntime.ProceessRequest.

      Brutal.

        Attachments

          Activity

            People

            Assignee:
            sbohlen Steve Bohlen
            Reporter:
            cherrydev Cherry Development
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated: