From 69139b5023b39d15f8ebf028c216634ac70c6969 Mon Sep 17 00:00:00 2001 From: Justin Kotalik Date: Fri, 31 May 2019 08:59:42 -0700 Subject: [PATCH] Log StartupTimeoutLimit failure to response (#10661) --- .../InProcessRequestHandler/dllmain.cpp | 21 +++++++++++-------- .../inprocessapplication.cpp | 13 +++++++++--- .../inprocessapplication.h | 5 +++-- .../Inprocess/StartupTests.cs | 9 ++++++-- 4 files changed, 32 insertions(+), 16 deletions(-) diff --git a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp index 664d8130d2..fe7f9d10a0 100644 --- a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp +++ b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp @@ -122,10 +122,13 @@ CreateApplication( std::unique_ptr inProcessApplication; - // TODO not sure how easy it will be to untangle errors here - // ErrorContext errorContext; + ErrorContext errorContext; + errorContext.statusCode = 500; + errorContext.subStatusCode = 30; + errorContext.generalErrorType = "ANCM In-Process Start Failure"; + errorContext.errorReason = ""; - if (!FAILED_LOG(hr = IN_PROCESS_APPLICATION::Start(*pServer, pSite, *pHttpApplication, pParameters, nParameters, inProcessApplication))) + if (!FAILED_LOG(hr = IN_PROCESS_APPLICATION::Start(*pServer, pSite, *pHttpApplication, pParameters, nParameters, inProcessApplication, errorContext))) { *ppApplication = inProcessApplication.release(); } @@ -138,10 +141,10 @@ CreateApplication( g_errorPageContent : FILE_UTILITY::GetHtml(g_hServerModule, IN_PROCESS_RH_STATIC_HTML, - 500i16, - 30i16, - "ANCM In-Process Start Failure", - "", + errorContext.statusCode, + errorContext.subStatusCode, + errorContext.generalErrorType, + errorContext.errorReason, ""); auto pErrorApplication = std::make_unique(*pServer, @@ -149,8 +152,8 @@ CreateApplication( options->QueryDisableStartUpErrorPage(), hr, content, - 500i16, - 30i16, + errorContext.statusCode, + errorContext.subStatusCode, "Internal Server Error"); RETURN_IF_FAILED(pErrorApplication->StartMonitoringAppOffline()); diff --git a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp index aa90367734..f261436690 100644 --- a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp +++ b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp @@ -130,7 +130,7 @@ IN_PROCESS_APPLICATION::SetCallbackHandles( } HRESULT -IN_PROCESS_APPLICATION::LoadManagedApplication() +IN_PROCESS_APPLICATION::LoadManagedApplication(ErrorContext& errorContext) { THROW_LAST_ERROR_IF_NULL(m_pInitializeEvent = CreateEvent( nullptr, // default security attributes @@ -157,11 +157,17 @@ IN_PROCESS_APPLICATION::LoadManagedApplication() // Wait for shutdown request const auto waitResult = WaitForMultipleObjects(2, waitHandles, FALSE, m_pConfig->QueryStartupTimeLimitInMS()); + THROW_LAST_ERROR_IF(waitResult == WAIT_FAILED); if (waitResult == WAIT_TIMEOUT) { // If server wasn't initialized in time shut application down without waiting for CLR thread to exit + errorContext.statusCode = 500; + errorContext.subStatusCode = 37; + errorContext.generalErrorType = "ANCM Failed to Start Within Startup Time Limit"; + errorContext.errorReason = format("ANCM failed to start after %d milliseconds", m_pConfig->QueryStartupTimeLimitInMS()); + m_waitForShutdown = false; StopClr(); throw InvalidOperationException(format(L"Managed server didn't initialize after %u ms.", m_pConfig->QueryStartupTimeLimitInMS())); @@ -380,7 +386,8 @@ HRESULT IN_PROCESS_APPLICATION::Start( IHttpApplication& pHttpApplication, APPLICATION_PARAMETER* pParameters, DWORD nParameters, - std::unique_ptr& application) + std::unique_ptr& application, + ErrorContext& errorContext) { try { @@ -388,7 +395,7 @@ HRESULT IN_PROCESS_APPLICATION::Start( THROW_IF_FAILED(InProcessOptions::Create(pServer, pSite, pHttpApplication, options)); application = std::unique_ptr( new IN_PROCESS_APPLICATION(pServer, pHttpApplication, std::move(options), pParameters, nParameters)); - THROW_IF_FAILED(application->LoadManagedApplication()); + THROW_IF_FAILED(application->LoadManagedApplication(errorContext)); return S_OK; } catch (InvalidOperationException& ex) diff --git a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h index 9f28db3889..0f3ae289b9 100644 --- a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h +++ b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h @@ -58,7 +58,7 @@ public: ExecuteApplication(); HRESULT - LoadManagedApplication(); + LoadManagedApplication(ErrorContext& errorContext); void QueueStop(); @@ -115,7 +115,8 @@ public: IHttpApplication& pHttpApplication, APPLICATION_PARAMETER* pParameters, DWORD nParameters, - std::unique_ptr& application); + std::unique_ptr& application, + ErrorContext& errorContext); private: struct ExecuteClrContext: std::enable_shared_from_this diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs index 572b85d823..c1be28d0d6 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs @@ -416,7 +416,6 @@ namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests.InProcess } [ConditionalFact] - [Flaky("https://github.com/aspnet/AspNetCore-Internal/issues/1772", FlakyOn.All)] public async Task StartupTimeoutIsApplied() { // From what I can tell, this failure is due to ungraceful shutdown. @@ -434,11 +433,17 @@ namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests.InProcess var response = await deploymentResult.HttpClient.GetAsync("/"); Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode); - StopServer(); + StopServer(gracefulShutdown: false); EventLogHelpers.VerifyEventLogEvents(deploymentResult, EventLogHelpers.InProcessFailedToStart(deploymentResult, "Managed server didn't initialize after 1000 ms.") ); + + if (DeployerSelector.HasNewHandler) + { + var responseContent = await response.Content.ReadAsStringAsync(); + Assert.Contains("ANCM Failed to Start Within Startup Time Limit", responseContent); + } } }