From cb964f1ae77f664ed11757c36f00267d7154404c Mon Sep 17 00:00:00 2001 From: Steve MacLean Date: Mon, 11 Mar 2019 12:33:38 -0400 Subject: [PATCH 1/2] Extend WindowsEventLog test Verify EntryPointFilter solves logging problem with native host swallowing exceptions WindowsEventLog only look at new entries WindowsEventLog remove time check Add mechanism to corhost to emulate host swallowing all exceptions --- src/inc/clrconfigvalues.h | 2 + src/vm/corhost.cpp | 19 +++++- src/vm/excep.cpp | 5 ++ .../WindowsEventLog/WindowsEventLog.cs | 59 +++++++++++++------ 4 files changed, 63 insertions(+), 22 deletions(-) diff --git a/src/inc/clrconfigvalues.h b/src/inc/clrconfigvalues.h index a8b4270d4d06..86a6166d1a9f 100644 --- a/src/inc/clrconfigvalues.h +++ b/src/inc/clrconfigvalues.h @@ -269,6 +269,8 @@ CONFIG_DWORD_INFO_DIRECT_ACCESS(INTERNAL_AssertOnFailFast, W("AssertOnFailFast") RETAIL_CONFIG_DWORD_INFO_EX(UNSUPPORTED_legacyCorruptedStateExceptionsPolicy, W("legacyCorruptedStateExceptionsPolicy"), 0, "Enabled Pre-V4 CSE behavior", CLRConfig::FavorConfigFile) CONFIG_DWORD_INFO_EX(INTERNAL_SuppressLostExceptionTypeAssert, W("SuppressLostExceptionTypeAssert"), 0, "", CLRConfig::REGUTIL_default) RETAIL_CONFIG_DWORD_INFO_EX(UNSUPPORTED_FailFastOnCorruptedStateException, W("FailFastOnCorruptedStateException"), 0, "Failfast if a CSE is encountered", CLRConfig::FavorConfigFile) +RETAIL_CONFIG_DWORD_INFO_EX(INTERNAL_UseEntryPointFilter, W("UseEntryPointFilter"), 0, "", CLRConfig::REGUTIL_default) +RETAIL_CONFIG_DWORD_INFO_EX(INTERNAL_Corhost_Swallow_Uncaught_Exceptions, W("Corhost_Swallow_Uncaught_Exceptions"), 0, "", CLRConfig::REGUTIL_default) /// /// Garbage collector diff --git a/src/vm/corhost.cpp b/src/vm/corhost.cpp index e02b514f5e30..40d8fff2dcbe 100644 --- a/src/vm/corhost.cpp +++ b/src/vm/corhost.cpp @@ -460,10 +460,23 @@ HRESULT CorHost2::ExecuteAssembly(DWORD dwAppDomainId, arguments->SetAt(i, argument); } - DWORD retval = pAssembly->ExecuteMainMethod(&arguments, TRUE /* waitForOtherThreads */); - if (pReturnValue) + if(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_Corhost_Swallow_Uncaught_Exceptions)) { - *pReturnValue = retval; + EX_TRY + DWORD retval = pAssembly->ExecuteMainMethod(&arguments, TRUE /* waitForOtherThreads */); + if (pReturnValue) + { + *pReturnValue = retval; + } + EX_CATCH_HRESULT (hr) + } + else + { + DWORD retval = pAssembly->ExecuteMainMethod(&arguments, TRUE /* waitForOtherThreads */); + if (pReturnValue) + { + *pReturnValue = retval; + } } GCPROTECT_END(); diff --git a/src/vm/excep.cpp b/src/vm/excep.cpp index 6d62f9c691ab..028e7e9c89cd 100644 --- a/src/vm/excep.cpp +++ b/src/vm/excep.cpp @@ -5139,7 +5139,12 @@ LONG InternalUnhandledExceptionFilter( } // LONG InternalUnhandledExceptionFilter() + +#ifdef PLATFORM_WINDOWS +static bool s_useEntryPointFilter = CLRConfig::GetConfigValue(CLRConfig::INTERNAL_UseEntryPointFilter) != 0; +#else static bool s_useEntryPointFilter = false; +#endif void ParseUseEntryPointFilter(LPCWSTR value) { diff --git a/tests/src/baseservices/exceptions/WindowsEventLog/WindowsEventLog.cs b/tests/src/baseservices/exceptions/WindowsEventLog/WindowsEventLog.cs index d4fd9292aa25..7d83bd4e4df6 100644 --- a/tests/src/baseservices/exceptions/WindowsEventLog/WindowsEventLog.cs +++ b/tests/src/baseservices/exceptions/WindowsEventLog/WindowsEventLog.cs @@ -50,13 +50,11 @@ private static string RandomCookie() .Select(s => s[random.Next(s.Length)]).ToArray()); } - private static bool LaunchTest(string testName, string[] logEntriesToCheck, string randomCookie) + private static bool LaunchTest(string testName, string[] logEntriesToCheck, string randomCookie, bool swallowExcep = false, bool useEntryPointFilter = false) { EventLog logBefore = new EventLog("Application"); int logBeforeCount = logBefore.Entries.Count; - DateTime dt = DateTime.Now; - Process testProcess = new Process(); string currentPath = Directory.GetCurrentDirectory(); string corerunPath = Environment.GetEnvironmentVariable("CORE_ROOT") + "\\corerun.exe"; @@ -64,6 +62,8 @@ private static bool LaunchTest(string testName, string[] logEntriesToCheck, stri testProcess.StartInfo.FileName = corerunPath; testProcess.StartInfo.Arguments = currentPath + "\\WindowsEventLog.exe " + testName + " " + randomCookie; testProcess.StartInfo.EnvironmentVariables["CORE_ROOT"] = Environment.GetEnvironmentVariable("CORE_ROOT"); + testProcess.StartInfo.EnvironmentVariables["COMPlus_Corhost_Swallow_Uncaught_Exceptions"] = swallowExcep ? "1" : "0"; + testProcess.StartInfo.EnvironmentVariables["COMPlus_UseEntryPointFilter"] = useEntryPointFilter ? "1" : "0"; testProcess.StartInfo.UseShellExecute = false; testProcess.Start(); @@ -75,32 +75,31 @@ private static bool LaunchTest(string testName, string[] logEntriesToCheck, stri Console.WriteLine("Found {0} entries in Event Log", logAfter.Entries.Count); - foreach (EventLogEntry entry in logAfter.Entries) + for (int i = logAfter.Entries.Count - 1; i >= logBeforeCount; --i) { + EventLogEntry entry = logAfter.Entries[i]; int checkCount = 0; - if (entry.TimeGenerated > dt.AddMinutes(-3)) // Grant some leeway in the time error was logged - { - String source = entry.Source; - String message = entry.Message; + String source = entry.Source; + String message = entry.Message; + + if (source.Contains(".NET Runtime")) + { + Console.WriteLine("*** Event Log ***"); + Console.WriteLine(message); foreach (string logEntry in logEntriesToCheck) { Console.WriteLine("Checking for existence of : " + logEntry); if (message.Contains(logEntry)) checkCount += 1; else - Console.WriteLine("Couldn't find it in: " + message); + Console.WriteLine("!!! Couldn't find it !!!"); } - if (source.Contains(".NET Runtime") && checkCount == logEntriesToCheck.Length && logBeforeCount < logAfter.Entries.Count) + if (checkCount == logEntriesToCheck.Length) { return true; } - else if (source.Contains(".NET Runtime")) - { - Console.WriteLine("*** Event Log ***"); - Console.WriteLine(message); - } } } return false; @@ -117,11 +116,11 @@ private static void DisableErrorDialog() } #endif - private static bool RunUnhandledExceptionTest() + private static bool RunUnhandledExceptionTest(bool swallowExcep = false, bool useEntryPointFilter = false) { string cookie = RandomCookie(); string[] logEntriesToCheck = { "unhandled exception", "ArgumentException", cookie }; - return LaunchTest("UnhandledException", logEntriesToCheck, cookie); + return LaunchTest("UnhandledException", logEntriesToCheck, cookie, swallowExcep, useEntryPointFilter); } private static bool RunFailFastTest() @@ -131,7 +130,6 @@ private static bool RunFailFastTest() return LaunchTest("FailFast", logEntriesToCheck, cookie); } - public static int Main(string[] args) { if (args.Length == 0) // When invoked with no args, launch itself with appropriate args to cause various exceptions @@ -144,7 +142,30 @@ public static int Main(string[] args) if (!RunUnhandledExceptionTest()) { - Console.WriteLine("WindowsEventLog Test: UnhandledExceptionTest failed."); + Console.WriteLine("WindowsEventLog Test: UnhandledExceptionTest() failed."); + return 1; + } + + if (RunUnhandledExceptionTest(swallowExcep:true)) + { + // Swallowing exceptions is reported to prevent logging to the Windows log. + // This is more of a test configuration sanity check than a requirement + Console.WriteLine("WindowsEventLog Test: UnhandledExceptionTest(swallowExcep:true) should have failed."); + return 1; + } + + if (!RunUnhandledExceptionTest(swallowExcep:true, useEntryPointFilter:true)) + { + // Logging should be the same with useEntryPointFilter + Console.WriteLine("WindowsEventLog Test: UnhandledExceptionTest(swallowExcep:true, useEntryPointFilter:true) failed."); + return 1; + } + + if (!RunUnhandledExceptionTest(swallowExcep:false, useEntryPointFilter:true)) + { + // Logging should be the same with useEntryPointFilter even without swallowing exception handler + // This is more of a test configuration sanity check than a requirement + Console.WriteLine("WindowsEventLog Test: UnhandledExceptionTest(swallowExcep:false, useEntryPointFilter:true) failed."); return 1; } From f809d0cb83a75bcb3680c01b61dd9b7f6fe8354d Mon Sep 17 00:00:00 2001 From: Steve MacLean Date: Mon, 11 Mar 2019 16:14:50 -0400 Subject: [PATCH 2/2] PR feedback --- src/vm/excep.cpp | 23 +++++++++++++++-------- 1 file changed, 15 insertions(+), 8 deletions(-) diff --git a/src/vm/excep.cpp b/src/vm/excep.cpp index 028e7e9c89cd..213e4b6b4cb7 100644 --- a/src/vm/excep.cpp +++ b/src/vm/excep.cpp @@ -5140,21 +5140,28 @@ LONG InternalUnhandledExceptionFilter( } // LONG InternalUnhandledExceptionFilter() -#ifdef PLATFORM_WINDOWS -static bool s_useEntryPointFilter = CLRConfig::GetConfigValue(CLRConfig::INTERNAL_UseEntryPointFilter) != 0; -#else -static bool s_useEntryPointFilter = false; -#endif +// Represent the value of USE_ENTRYPOINT_FILTER as passed in the property bag to the host during construction +static bool s_useEntryPointFilterCorhostProperty = false; void ParseUseEntryPointFilter(LPCWSTR value) { -#ifdef PLATFORM_WINDOWS // This feature has only been tested on Windows, keep it disabled on other platforms // set s_useEntryPointFilter true if value != "0" if (value && (_wcsicmp(value, W("0")) != 0)) { - s_useEntryPointFilter = true; + s_useEntryPointFilterCorhostProperty = true; } +} + +bool GetUseEntryPointFilter() +{ +#ifdef PLATFORM_WINDOWS // This feature has only been tested on Windows, keep it disabled on other platforms + static bool s_useEntryPointFilterEnv = CLRConfig::GetConfigValue(CLRConfig::INTERNAL_UseEntryPointFilter) != 0; + + return s_useEntryPointFilterCorhostProperty || s_useEntryPointFilterEnv; +#else + return false; #endif + } // This filter is used to trigger unhandled exception processing for the entrypoint thread @@ -5177,7 +5184,7 @@ LONG EntryPointFilter(PEXCEPTION_POINTERS pExceptionInfo, PVOID _pData) return ret; } - if (!s_useEntryPointFilter) + if (!GetUseEntryPointFilter()) { return EXCEPTION_CONTINUE_SEARCH; }