Fix AppOfflineDroppedWhileSiteStarting_SiteShutsDown_InProcess (#8419)

src/Servers/IIS/AspNetCoreModuleV2/AspNetCore/applicationinfo.cpp

@@ -155,8 +155,8 @@ APPLICATION_INFO::TryCreateApplication(IHttpContext& pHttpContext, const ShimOpt
             }
             LOG_LAST_ERROR_IF(WaitForSingleObject(eventHandle, INFINITE) != WAIT_OBJECT_0);
         }
-
     }
+
     RETURN_IF_FAILED(m_handlerResolver.GetApplicationFactory(*pHttpContext.GetApplication(), m_pApplicationFactory, options));
     LOG_INFO(L"Creating handler application");
 

src/Servers/IIS/AspNetCoreModuleV2/CommonLib/application.h

@@ -9,6 +9,7 @@
 #include "SRWExclusiveLock.h"
 #include "SRWSharedLock.h"
 #include "exceptions.h"
+#include "HandleWrapper.h"
 
 class APPLICATION : public IAPPLICATION
 {
@@ -24,8 +25,10 @@ public:
     {
         *pRequestHandler = nullptr;
 
-        SRWSharedLock stopLock(m_stateLock);
+        SRWSharedLock stopLock(m_stopLock);
 
+        // If we have acquired the stopLock, we don't need to acquire the data lock
+        // as m_fStoppedCalled is only set by Stop.
         if (m_fStopCalled)
         {
             return S_FALSE;
@@ -49,22 +52,25 @@ public:
           m_applicationConfigPath(pHttpApplication.GetAppConfigPath()),
           m_applicationId(pHttpApplication.GetApplicationId())
     {
-        InitializeSRWLock(&m_stateLock);
+        InitializeSRWLock(&m_stopLock);
+        InitializeSRWLock(&m_dataLock);
         m_applicationVirtualPath = ToVirtualPath(m_applicationConfigPath);
     }
 
-
     VOID
     Stop(bool fServerInitiated) override
     {
-        SRWExclusiveLock stopLock(m_stateLock);
+        SRWExclusiveLock stopLock(m_stopLock);
 
-        if (m_fStopCalled)
         {
-            return;
+            SRWExclusiveLock dataLock(m_dataLock);
-        }
+            if (m_fStopCalled)
+            {
+                return;
+            }
 
-        m_fStopCalled = true;
+            m_fStopCalled = true;
+        }
 
         StopInternal(fServerInitiated);
     }
@@ -120,7 +126,8 @@ public:
     }
 
 protected:
-    SRWLOCK m_stateLock {};
+    SRWLOCK m_stopLock{};
+    SRWLOCK m_dataLock {};
     bool m_fStopCalled;
 
 private:

src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp

@@ -20,7 +20,7 @@ IN_PROCESS_APPLICATION::IN_PROCESS_APPLICATION(
     IHttpServer& pHttpServer,
     IHttpApplication& pApplication,
     std::unique_ptr<InProcessOptions> pConfig,
-    APPLICATION_PARAMETER *pParameters,
+    APPLICATION_PARAMETER* pParameters,
     DWORD                  nParameters) :
     InProcessApplicationBase(pHttpServer, pApplication),
     m_Initialized(false),
@@ -55,6 +55,7 @@ IN_PROCESS_APPLICATION::StopInternal(bool fServerInitiated)
 VOID
 IN_PROCESS_APPLICATION::StopClr()
 {
+    // This has the state lock around it. 
     LOG_INFO(L"Stopping CLR");
 
     if (!m_blockManagedCallbacks)
@@ -69,11 +70,13 @@ IN_PROCESS_APPLICATION::StopClr()
             shutdownHandler(m_ShutdownHandlerContext);
         }
 
+        SRWSharedLock dataLock(m_dataLock);
+
         auto requestCount = m_requestCount.load();
+
         if (requestCount == 0)
         {
-            LOG_INFO(L"Drained all requests, notifying managed.");
+            CallRequestsDrained();
-            m_RequestsDrainedHandler(m_ShutdownHandlerContext);
         }
     }
 
@@ -141,12 +144,6 @@ IN_PROCESS_APPLICATION::LoadManagedApplication()
         FALSE,    // not set
         nullptr)); // name
 
-    THROW_LAST_ERROR_IF_NULL(m_pRequestDrainEvent = CreateEvent(
-        nullptr,  // default security attributes
-        TRUE,     // manual reset event
-        FALSE,    // not set
-        nullptr)); // name
-
     LOG_INFO(L"Waiting for initialization");
 
     m_workerThread = std::thread([](std::unique_ptr<IN_PROCESS_APPLICATION, IAPPLICATION_DELETER> application)
@@ -532,8 +529,13 @@ IN_PROCESS_APPLICATION::CreateHandler(
 {
     try
     {
+        SRWSharedLock dataLock(m_dataLock);
+
         DBG_ASSERT(!m_fStopCalled);
         m_requestCount++;
+
+        LOG_TRACEF(L"Adding request. Total Request Count %d", m_requestCount.load());
+
         *pRequestHandler = new IN_PROCESS_HANDLER(::ReferenceApplication(this), pHttpContext, m_RequestHandler, m_RequestHandlerContext, m_DisconnectHandler, m_AsyncCompletionHandler);
     }
     CATCH_RETURN();
@@ -544,11 +546,24 @@ IN_PROCESS_APPLICATION::CreateHandler(
 void
 IN_PROCESS_APPLICATION::HandleRequestCompletion()
 {
-    SRWSharedLock lock(m_stateLock);
+    SRWSharedLock dataLock(m_dataLock);
-    auto requestCount = m_requestCount--;
+
-    if (m_fStopCalled && requestCount == 0)
+    auto requestCount = --m_requestCount;
+
+    LOG_TRACEF(L"Removing Request %d", requestCount);
+
+    if (m_fStopCalled && requestCount == 0 && !m_blockManagedCallbacks)
+    {
+        CallRequestsDrained();
+    }
+}
+
+void IN_PROCESS_APPLICATION::CallRequestsDrained()
+{
+    if (m_RequestsDrainedHandler != nullptr)
     {
         LOG_INFO(L"Drained all requests, notifying managed.");
         m_RequestsDrainedHandler(m_ShutdownHandlerContext);
+        m_RequestsDrainedHandler = nullptr;
     }
 }

src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h

@@ -150,8 +150,6 @@ private:
     // The event that gets triggered when worker thread should exit
     HandleWrapper<NullHandleTraits> m_pShutdownEvent;
 
-    HandleWrapper<NullHandleTraits> m_pRequestDrainEvent;
-
     // The request handler callback from managed code
     PFN_REQUEST_HANDLER             m_RequestHandler;
     VOID*                           m_RequestHandlerContext;
@@ -169,6 +167,7 @@ private:
     std::atomic_bool                m_blockManagedCallbacks;
     bool                            m_Initialized;
     bool                            m_waitForShutdown;
+
     std::atomic<int>                m_requestCount;
 
     std::unique_ptr<InProcessOptions> m_pConfig;
@@ -188,6 +187,9 @@ private:
     void
     StopClr();
 
+    void
+    CallRequestsDrained();
+
     static
     void
     ClrThreadEntryPoint(const std::shared_ptr<ExecuteClrContext> &context);

src/Servers/IIS/AspNetCoreModuleV2/OutOfProcessRequestHandler/outprocessapplication.cpp

@@ -18,7 +18,7 @@ OUT_OF_PROCESS_APPLICATION::OUT_OF_PROCESS_APPLICATION(
 
 OUT_OF_PROCESS_APPLICATION::~OUT_OF_PROCESS_APPLICATION()
 {
-    SRWExclusiveLock lock(m_stateLock);
+    SRWExclusiveLock lock(m_stopLock);
     if (m_pProcessManager != NULL)
     {
         m_pProcessManager->Shutdown();

src/Servers/IIS/IIS/test/Common.FunctionalTests/AppOfflineTests.cs

@@ -14,6 +14,7 @@ using Microsoft.AspNetCore.Testing.xunit;
 using Microsoft.Extensions.Logging;
 using Xunit;
 using Microsoft.AspNetCore.Server.IntegrationTesting.IIS;
+using System.Collections.Generic;
 
 namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests
 {
@@ -98,8 +99,8 @@ namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests
             await deploymentResult.AssertRecycledAsync(() => AssertAppOffline(deploymentResult));
         }
 
-        [ConditionalFact(Skip = "https://github.com/aspnet/AspNetCore/issues/6555")]
+        [ConditionalFact]
-        [RequiresIIS(IISCapability.ShutdownToken)]
+        [RequiresNewHandler]
         public async Task AppOfflineDroppedWhileSiteStarting_SiteShutsDown_InProcess()
         {
             // This test often hits a race between debug logging and stdout redirection closing the handle
@@ -131,19 +132,100 @@ namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests
                         // if AssertAppOffline succeeded ANCM have picked up app_offline before starting the app
                         // try again
                         RemoveAppOffline(deploymentResult.ContentRoot);
+
+                        if (deploymentResult.DeploymentParameters.ServerType == ServerType.IIS)
+                        {
+                            deploymentResult.AssertWorkerProcessStop();
+                            return;
+                        }
                     }
                     catch
                     {
+                        // For IISExpress, we need to catch the exception because IISExpress will not restart a process if it crashed.
+                        // RemoveAppOffline will fail due to a bad request exception as the server is down.
+                        Assert.Contains(TestSink.Writes, context => context.Message.Contains("Drained all requests, notifying managed."));
                         deploymentResult.AssertWorkerProcessStop();
                         return;
                     }
                 }
 
                 Assert.True(false);
-
             }
         }
 
+        [ConditionalFact]
+        public async Task GracefulShutdownWorksWithMultipleRequestsInFlight_InProcess()
+        {
+            // The goal of this test is to have multiple requests currently in progress
+            // and for app offline to be dropped. We expect that all requests are eventually drained
+            // and graceful shutdown occurs. 
+            var deploymentParameters = _fixture.GetBaseDeploymentParameters(_fixture.InProcessTestSite);
+            deploymentParameters.TransformArguments((a, _) => $"{a} IncreaseShutdownLimit");
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            var result = await deploymentResult.HttpClient.GetAsync("/HelloWorld");
+
+            // Send two requests that will hang until data is sent from the client.
+            var connectionList = new List<TestConnection>();
+
+            for (var i = 0; i < 2; i++)
+            {
+                var connection = new TestConnection(deploymentResult.HttpClient.BaseAddress.Port);
+                await connection.Send(
+                    "POST /ReadAndCountRequestBody HTTP/1.1",
+                    "Content-Length: 1",
+                    "Host: localhost",
+                    "Connection: close",
+                    "",
+                    "");
+
+                await connection.Receive(
+                  "HTTP/1.1 200 OK", "");
+                await connection.ReceiveHeaders();
+                await connection.Receive("1", $"{i + 1}");
+                connectionList.Add(connection);
+            }
+
+            // Send a request that will end once app lifetime is triggered (ApplicationStopping cts).
+            var statusConnection = new TestConnection(deploymentResult.HttpClient.BaseAddress.Port);
+
+            await statusConnection.Send(
+                "GET /WaitForAppToStartShuttingDown HTTP/1.1",
+                "Host: localhost",
+                "Connection: close",
+                "",
+                "");
+
+            await statusConnection.Receive("HTTP/1.1 200 OK",
+                "");
+
+            await statusConnection.ReceiveHeaders();
+
+            // Receiving some data means we are currently waiting for IHostApplicationLifetime.
+            await statusConnection.Receive("5",
+                "test1",
+                "");
+
+            AddAppOffline(deploymentResult.ContentRoot);
+
+            // Receive the rest of all open connections.
+            await statusConnection.Receive("5", "test2", "");
+
+            for (var i = 0; i < 2; i++)
+            {
+                await connectionList[i].Send("a", "");
+                await connectionList[i].Receive("", "4", "done");
+                connectionList[i].Dispose();
+            }
+
+            deploymentResult.AssertWorkerProcessStop();
+
+            // Shutdown should be graceful here!
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult,
+                EventLogHelpers.InProcessShutdown());
+        }
+
         [ConditionalFact]
         public async Task AppOfflineDroppedWhileSiteRunning_SiteShutsDown_InProcess()
         {
@@ -282,6 +364,5 @@ namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests
                 File.Delete(file);
             }
         }
-
     }
 }

src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs

@@ -172,6 +172,11 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             }
         }
 
+        public static string InProcessShutdown()
+        {
+            return "Application 'MACHINE/WEBROOT/APPHOST/.*?' has shutdown.";
+        }
+
         public static string InProcessFailedToStop(IISDeploymentResult deploymentResult, string reason)
         {
             return "Failed to gracefully shutdown application 'MACHINE/WEBROOT/APPHOST/.*?'.";

src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/IISCapability.cs

@@ -12,11 +12,10 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         Websockets = 1,
         WindowsAuthentication = 2,
         PoolEnvironmentVariables = 4,
-        ShutdownToken = 8,
+        DynamicCompression = 8,
-        DynamicCompression = 16,
+        ApplicationInitialization = 16,
-        ApplicationInitialization = 32,
+        TracingModule = 32,
-        TracingModule = 64,
+        FailedRequestTracingModule = 64,
-        FailedRequestTracingModule = 128,
+        BasicAuthentication = 128
-        BasicAuthentication = 256
     }
 }

src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/RequiresIISAttribute.cs

@@ -124,12 +124,6 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 }
             }
 
-            if (capabilities.HasFlag(IISCapability.ShutdownToken))
-            {
-                IsMet = false;
-                SkipReason += "https://github.com/aspnet/IISIntegration/issues/1074";
-            }
-
             foreach (var module in Modules)
             {
                 if (capabilities.HasFlag(module.Capability))

src/Servers/IIS/IIS/test/testassets/InProcessWebSite/Program.cs

@@ -63,6 +63,18 @@ namespace TestSite
 
                         Thread.Sleep(Timeout.Infinite);
                     }
+                    break;
+                case "IncreaseShutdownLimit":
+                    {
+                        var host = new WebHostBuilder()
+                           .UseIIS()
+                           .UseShutdownTimeout(TimeSpan.FromSeconds(120))
+                           .UseStartup<Startup>()
+                           .Build();
+
+                        host.Run();
+                    }
+
                     break;
                 case "CheckConsoleFunctions":
                     // Call a bunch of console functions and make sure none return invalid handle.

src/Servers/IIS/IIS/test/testassets/InProcessWebSite/Startup.cs

@@ -284,6 +284,28 @@ namespace TestSite
             {
                 result = await ctx.Request.Body.ReadAsync(readBuffer, 0, 1);
             }
+
+        }
+
+        private int _requestsInFlight = 0;
+        private async Task ReadAndCountRequestBody(HttpContext ctx)
+        {
+            Interlocked.Increment(ref _requestsInFlight);
+            await ctx.Response.WriteAsync(_requestsInFlight.ToString());
+
+            var readBuffer = new byte[1];
+            await ctx.Request.Body.ReadAsync(readBuffer, 0, 1);
+
+            await ctx.Response.WriteAsync("done");
+            Interlocked.Decrement(ref _requestsInFlight);
+        }
+
+        private async Task WaitForAppToStartShuttingDown(HttpContext ctx)
+        {
+            await ctx.Response.WriteAsync("test1");
+            var lifetime = ctx.RequestServices.GetService<IHostApplicationLifetime>();
+            lifetime.ApplicationStopping.WaitHandle.WaitOne();
+            await ctx.Response.WriteAsync("test2");
         }
 
         private async Task ReadFullBody(HttpContext ctx)

src/Servers/IIS/IntegrationTesting.IIS/src/IISDeployer.cs

@@ -24,12 +24,13 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
         private const string DetailedErrorsEnvironmentVariable = "ASPNETCORE_DETAILEDERRORS";
 
         private static readonly TimeSpan _timeout = TimeSpan.FromSeconds(60);
-        private static readonly TimeSpan _retryDelay = TimeSpan.FromMilliseconds(200);
+        private static readonly TimeSpan _retryDelay = TimeSpan.FromMilliseconds(100);
 
         private CancellationTokenSource _hostShutdownToken = new CancellationTokenSource();
 
         private string _configPath;
         private string _debugLogFile;
+        private bool _disposed;
 
         public Process HostProcess { get; set; }
 
@@ -45,6 +46,12 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
 
         public override void Dispose()
         {
+            if (_disposed)
+            {
+                return;
+            }
+
+            _disposed = true;
             Dispose(gracefulShutdown: false);
         }
 
@@ -420,6 +427,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
             List<Exception> exceptions = null;
             var sw = Stopwatch.StartNew();
             int retryCount = 0;
+            var delay = _retryDelay;
 
             while (sw.Elapsed < _timeout)
             {
@@ -443,7 +451,8 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                 }
 
                 retryCount++;
-                Thread.Sleep(_retryDelay);
+                Thread.Sleep(delay);
+                delay *= 1.5;
             }
 
             throw new AggregateException($"Operation did not succeed after {retryCount} retries", exceptions.ToArray());