From 7c238b9fefde341ffe6c64ff3683fc44b781d377 Mon Sep 17 00:00:00 2001 From: Jack Kanarish Date: Wed, 31 Jul 2019 16:22:05 -0400 Subject: [PATCH 1/3] fix: fix for logging deadlock, use mutexes, add logging for last message sent. --- ICD.Common.Utils/IcdErrorLog.cs | 132 +++++++++++++++++++++----------- 1 file changed, 88 insertions(+), 44 deletions(-) diff --git a/ICD.Common.Utils/IcdErrorLog.cs b/ICD.Common.Utils/IcdErrorLog.cs index 0e2d818..e49dff4 100644 --- a/ICD.Common.Utils/IcdErrorLog.cs +++ b/ICD.Common.Utils/IcdErrorLog.cs @@ -8,35 +8,44 @@ namespace ICD.Common.Utils { public static class IcdErrorLog { - private static readonly SafeCriticalSection s_LoggingSection; + private const int MUTEX_TIMEOUT = 30 * 1000; + private static readonly SafeMutex s_SafeMutex; + private static string s_LastMessage; /// /// Static constructor. /// static IcdErrorLog() { - s_LoggingSection = new SafeCriticalSection(); + s_SafeMutex = new SafeMutex(); } [PublicAPI] public static void Error(string message) { - s_LoggingSection.Enter(); - - try + if(s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) { + try + { + s_LastMessage = message; #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_RED); - ErrorLog.Error(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_RED); + ErrorLog.Error(message); #else System.Console.ForegroundColor = ConsoleColor.Red; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif + } + finally + { + s_SafeMutex.ReleaseMutex(); + } } - finally + else { - s_LoggingSection.Leave(); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); } } @@ -49,22 +58,29 @@ namespace ICD.Common.Utils [PublicAPI] public static void Warn(string message) { - s_LoggingSection.Enter(); - - try + if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) { + try + { + s_LastMessage = message; #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW); - ErrorLog.Warn(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW); + ErrorLog.Warn(message); #else System.Console.ForegroundColor = ConsoleColor.Yellow; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif + } + finally + { + s_SafeMutex.ReleaseMutex(); + } } - finally + else { - s_LoggingSection.Leave(); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); } } @@ -77,22 +93,29 @@ namespace ICD.Common.Utils [PublicAPI] public static void Notice(string message) { - s_LoggingSection.Enter(); - - try + if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) { + s_LastMessage = message; + try + { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_BLUE); - ErrorLog.Notice(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_BLUE); + ErrorLog.Notice(message); #else System.Console.ForegroundColor = ConsoleColor.Blue; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif + } + finally + { + s_SafeMutex.ReleaseMutex(); + } } - finally + else { - s_LoggingSection.Leave(); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); } } @@ -105,22 +128,29 @@ namespace ICD.Common.Utils [PublicAPI] public static void Ok(string message) { - s_LoggingSection.Enter(); - - try + if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) { + s_LastMessage = message; + try + { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_GREEN); - ErrorLog.Ok(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_GREEN); + ErrorLog.Ok(message); #else System.Console.ForegroundColor = ConsoleColor.Green; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif + } + finally + { + s_SafeMutex.ReleaseMutex(); + } } - finally + else { - s_LoggingSection.Leave(); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); } } @@ -133,13 +163,14 @@ namespace ICD.Common.Utils [PublicAPI] public static void Exception(Exception ex, string message) { - s_LoggingSection.Enter(); - - try + if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) { + s_LastMessage = message; + try + { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW_ON_RED_BACKGROUND); - ErrorLog.Exception(message, ex); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW_ON_RED_BACKGROUND); + ErrorLog.Exception(message, ex); #else System.Console.ForegroundColor = ConsoleColor.Yellow; System.Console.BackgroundColor = ConsoleColor.Red; @@ -147,10 +178,16 @@ namespace ICD.Common.Utils System.Console.ResetColor(); System.Console.Error.WriteLine(ex.StackTrace); #endif + } + finally + { + s_SafeMutex.ReleaseMutex(); + } } - finally + else { - s_LoggingSection.Leave(); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); } } @@ -164,22 +201,29 @@ namespace ICD.Common.Utils [PublicAPI] public static void Info(string message) { - s_LoggingSection.Enter(); - - try + if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) { + s_LastMessage = message; + try + { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_CYAN); - ErrorLog.Info(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_CYAN); + ErrorLog.Info(message); #else System.Console.ForegroundColor = ConsoleColor.Cyan; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif + } + finally + { + s_SafeMutex.ReleaseMutex(); + } } - finally + else { - s_LoggingSection.Leave(); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); + IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); } } From 89061b5cbff99c1537d54fc4b9c7e640579dee73 Mon Sep 17 00:00:00 2001 From: Jack Kanarish Date: Wed, 7 Aug 2019 20:47:54 -0400 Subject: [PATCH 2/3] feat: add unit test for timer --- .../Timers/IcdStopwatchTest.cs | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) create mode 100644 ICD.Common.Utils.Tests/Timers/IcdStopwatchTest.cs diff --git a/ICD.Common.Utils.Tests/Timers/IcdStopwatchTest.cs b/ICD.Common.Utils.Tests/Timers/IcdStopwatchTest.cs new file mode 100644 index 0000000..36a79a8 --- /dev/null +++ b/ICD.Common.Utils.Tests/Timers/IcdStopwatchTest.cs @@ -0,0 +1,17 @@ +using ICD.Common.Utils.Timers; +using NUnit.Framework; + +namespace ICD.Common.Utils.Tests.Timers +{ + [TestFixture] + public sealed class IcdStopwatchTest + { + [Test] + public void ConstructorTest() + { + var stopwatch = new IcdStopwatch(); + ThreadingUtils.Sleep(100); + Assert.AreEqual(0, stopwatch.ElapsedMilliseconds); + } + } +} From e388f35efb8e8dc0bad9af348994722d208a5b9e Mon Sep 17 00:00:00 2001 From: Chris Cameron Date: Thu, 15 Aug 2019 10:56:34 -0400 Subject: [PATCH 3/3] Revert "fix: fix for logging deadlock, use mutexes, add logging for last message sent." This reverts commit 7c238b9fefde341ffe6c64ff3683fc44b781d377. --- ICD.Common.Utils/IcdErrorLog.cs | 132 +++++++++++--------------------- 1 file changed, 44 insertions(+), 88 deletions(-) diff --git a/ICD.Common.Utils/IcdErrorLog.cs b/ICD.Common.Utils/IcdErrorLog.cs index e49dff4..0e2d818 100644 --- a/ICD.Common.Utils/IcdErrorLog.cs +++ b/ICD.Common.Utils/IcdErrorLog.cs @@ -8,44 +8,35 @@ namespace ICD.Common.Utils { public static class IcdErrorLog { - private const int MUTEX_TIMEOUT = 30 * 1000; - private static readonly SafeMutex s_SafeMutex; - private static string s_LastMessage; + private static readonly SafeCriticalSection s_LoggingSection; /// /// Static constructor. /// static IcdErrorLog() { - s_SafeMutex = new SafeMutex(); + s_LoggingSection = new SafeCriticalSection(); } [PublicAPI] public static void Error(string message) { - if(s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) + s_LoggingSection.Enter(); + + try { - try - { - s_LastMessage = message; #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_RED); - ErrorLog.Error(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_RED); + ErrorLog.Error(message); #else System.Console.ForegroundColor = ConsoleColor.Red; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif - } - finally - { - s_SafeMutex.ReleaseMutex(); - } } - else + finally { - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); + s_LoggingSection.Leave(); } } @@ -58,29 +49,22 @@ namespace ICD.Common.Utils [PublicAPI] public static void Warn(string message) { - if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) + s_LoggingSection.Enter(); + + try { - try - { - s_LastMessage = message; #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW); - ErrorLog.Warn(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW); + ErrorLog.Warn(message); #else System.Console.ForegroundColor = ConsoleColor.Yellow; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif - } - finally - { - s_SafeMutex.ReleaseMutex(); - } } - else + finally { - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); + s_LoggingSection.Leave(); } } @@ -93,29 +77,22 @@ namespace ICD.Common.Utils [PublicAPI] public static void Notice(string message) { - if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) + s_LoggingSection.Enter(); + + try { - s_LastMessage = message; - try - { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_BLUE); - ErrorLog.Notice(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_BLUE); + ErrorLog.Notice(message); #else System.Console.ForegroundColor = ConsoleColor.Blue; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif - } - finally - { - s_SafeMutex.ReleaseMutex(); - } } - else + finally { - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); + s_LoggingSection.Leave(); } } @@ -128,29 +105,22 @@ namespace ICD.Common.Utils [PublicAPI] public static void Ok(string message) { - if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) + s_LoggingSection.Enter(); + + try { - s_LastMessage = message; - try - { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_GREEN); - ErrorLog.Ok(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_GREEN); + ErrorLog.Ok(message); #else System.Console.ForegroundColor = ConsoleColor.Green; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif - } - finally - { - s_SafeMutex.ReleaseMutex(); - } } - else + finally { - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); + s_LoggingSection.Leave(); } } @@ -163,14 +133,13 @@ namespace ICD.Common.Utils [PublicAPI] public static void Exception(Exception ex, string message) { - if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) + s_LoggingSection.Enter(); + + try { - s_LastMessage = message; - try - { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW_ON_RED_BACKGROUND); - ErrorLog.Exception(message, ex); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_YELLOW_ON_RED_BACKGROUND); + ErrorLog.Exception(message, ex); #else System.Console.ForegroundColor = ConsoleColor.Yellow; System.Console.BackgroundColor = ConsoleColor.Red; @@ -178,16 +147,10 @@ namespace ICD.Common.Utils System.Console.ResetColor(); System.Console.Error.WriteLine(ex.StackTrace); #endif - } - finally - { - s_SafeMutex.ReleaseMutex(); - } } - else + finally { - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); + s_LoggingSection.Leave(); } } @@ -201,29 +164,22 @@ namespace ICD.Common.Utils [PublicAPI] public static void Info(string message) { - if (s_SafeMutex.WaitForMutex(MUTEX_TIMEOUT)) + s_LoggingSection.Enter(); + + try { - s_LastMessage = message; - try - { #if SIMPLSHARP - message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_CYAN); - ErrorLog.Info(message); + message = FormatConsoleColor(message, ConsoleColorExtensions.CONSOLE_CYAN); + ErrorLog.Info(message); #else System.Console.ForegroundColor = ConsoleColor.Cyan; System.Console.Error.WriteLine(message); System.Console.ResetColor(); #endif - } - finally - { - s_SafeMutex.ReleaseMutex(); - } } - else + finally { - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, "Deadlock in Error Logging, last logged message is:"); - IcdConsole.PrintLine(eConsoleColor.YellowOnRed, StringUtils.ToMixedReadableHexLiteral(s_LastMessage)); + s_LoggingSection.Leave(); } }