Merge pull request #173 from PepperDash/feature-2/update-logging

Update Debug Logging

src/Pepperdash Core/Device.cs

@@ -1,9 +1,6 @@
 using System;
 using System.Collections.Generic;
-using System.Linq;
+using Serilog.Events;
-using Serilog;
-using Serilog.Core;
-using Serilog.Sinks.SystemConsole;
 
 namespace PepperDash.Core
 {
@@ -53,7 +50,7 @@ namespace PepperDash.Core
 		public Device(string key)
 		{
 			Key = key;
-			if (key.Contains('.')) Debug.Console(0, this, "WARNING: Device name's should not include '.'");
+			if (key.Contains(".")) Debug.LogMessage(LogEventLevel.Information, "WARNING: Device key should not include '.'", this);
 			Name = "";
 		}
 

src/Pepperdash Core/Logging/Debug.cs

@@ -1,19 +1,19 @@
-using System;
+using Crestron.SimplSharp;
-using System.Collections.Generic;
+using Crestron.SimplSharp.CrestronDataStore;
-using System.Text.RegularExpressions;
-using Crestron.SimplSharp;
-using System.Reflection;
-using Crestron.SimplSharp.CrestronLogger;
 using Crestron.SimplSharp.CrestronIO;
+using Crestron.SimplSharp.CrestronLogger;
 using Newtonsoft.Json;
-using PepperDash.Core.DebugThings;
+using PepperDash.Core.Logging;
 using Serilog;
+using Serilog.Context;
 using Serilog.Core;
 using Serilog.Events;
-using Serilog.Formatting.Json;
-using Crestron.SimplSharp.CrestronDataStore;
-using PepperDash.Core.Logging;
 using Serilog.Formatting.Compact;
+using Serilog.Formatting.Json;
+using System;
+using System.Collections.Generic;
+using System.Reflection;
+using System.Text.RegularExpressions;
 
 namespace PepperDash.Core
 {
@@ -24,6 +24,8 @@ namespace PepperDash.Core
     {
         private static readonly string LevelStoreKey = "ConsoleDebugLevel";
         private static readonly string WebSocketLevelStoreKey = "WebsocketDebugLevel";
+        private static readonly string ErrorLogLevelStoreKey = "ErrorLogDebugLevel";
+        private static readonly string FileLevelStoreKey = "FileDebugLevel";
 
         private static readonly Dictionary<uint, LogEventLevel> _logLevels = new Dictionary<uint, LogEventLevel>()
         {
@@ -35,12 +37,16 @@ namespace PepperDash.Core
             {2, LogEventLevel.Verbose },
         };
 
-        private static Logger _logger;
+        private static ILogger _logger;
 
         private static readonly LoggingLevelSwitch _consoleLoggingLevelSwitch;
 
         private static readonly LoggingLevelSwitch _websocketLoggingLevelSwitch;
 
+        private static readonly LoggingLevelSwitch _errorLogLevelSwitch;
+
+        private static readonly LoggingLevelSwitch _fileLevelSwitch;
+
         public static LogEventLevel WebsocketMinimumLogLevel
         {
             get { return _websocketLoggingLevelSwitch.MinimumLevel; }
@@ -117,10 +123,18 @@ namespace PepperDash.Core
 
             var defaultWebsocketLevel = GetStoredLogEventLevel(WebSocketLevelStoreKey);
 
+            var defaultErrorLogLevel = GetStoredLogEventLevel(ErrorLogLevelStoreKey);
+
+            var defaultFileLogLevel = GetStoredLogEventLevel(FileLevelStoreKey);
+
             _consoleLoggingLevelSwitch = new LoggingLevelSwitch(initialMinimumLevel: defaultConsoleLevel);            
 
             _websocketLoggingLevelSwitch = new LoggingLevelSwitch(initialMinimumLevel: defaultWebsocketLevel);
 
+            _errorLogLevelSwitch = new LoggingLevelSwitch(initialMinimumLevel: defaultErrorLogLevel);
+
+            _fileLevelSwitch = new LoggingLevelSwitch(initialMinimumLevel: defaultFileLogLevel);
+
             _websocketSink = new DebugWebsocketSink(new JsonFormatter(renderMessage: true));
 
             var logFilePath = CrestronEnvironment.DevicePlatform == eDevicePlatform.Appliance ?
@@ -131,13 +145,15 @@ namespace PepperDash.Core
 
             _defaultLoggerConfiguration = new LoggerConfiguration()
                 .MinimumLevel.Verbose()
+                .Enrich.FromLogContext()
                 .WriteTo.Sink(new DebugConsoleSink(new JsonFormatter(renderMessage: true)), levelSwitch: _consoleLoggingLevelSwitch)
                 .WriteTo.Sink(_websocketSink, levelSwitch: _websocketLoggingLevelSwitch)
-                .WriteTo.Sink(new DebugErrorLogSink(), LogEventLevel.Information)
+                .WriteTo.Sink(new DebugErrorLogSink(), levelSwitch: _errorLogLevelSwitch)
                 .WriteTo.File(new RenderedCompactJsonFormatter(), logFilePath,                                    
                     rollingInterval: RollingInterval.Day,
                     restrictedToMinimumLevel: LogEventLevel.Debug,
-                    retainedFileCountLimit: CrestronEnvironment.DevicePlatform == eDevicePlatform.Appliance ? 30 : 60
+                    retainedFileCountLimit: CrestronEnvironment.DevicePlatform == eDevicePlatform.Appliance ? 30 : 60,
+                    levelSwitch: _fileLevelSwitch
                 );
 
             try
@@ -387,9 +403,33 @@ namespace PepperDash.Core
             var err = CrestronDataStoreStatic.SetLocalUintValue(WebSocketLevelStoreKey, (uint) level);
 
             if (err != CrestronDataStore.CDS_ERROR.CDS_SUCCESS)
-                Console(0, "Error saving websocket debug level setting: {0}", err);
+                LogMessage(LogEventLevel.Information, "Error saving websocket debug level setting: {erro}", err);
 
-            Console(0, "Websocket debug level set to {0}", _websocketLoggingLevelSwitch.MinimumLevel);
+            LogMessage(LogEventLevel.Information, "Websocket debug level set to {0}", _websocketLoggingLevelSwitch.MinimumLevel);
+        }
+
+        public static void SetErrorLogMinimumDebugLevel(LogEventLevel level)
+        {
+            _errorLogLevelSwitch.MinimumLevel = level;
+
+            var err = CrestronDataStoreStatic.SetLocalUintValue(ErrorLogLevelStoreKey, (uint)level);
+
+            if (err != CrestronDataStore.CDS_ERROR.CDS_SUCCESS)
+                LogMessage(LogEventLevel.Information, "Error saving Error Log debug level setting: {error}", err);
+
+            LogMessage(LogEventLevel.Information, "Error log debug level set to {0}", _websocketLoggingLevelSwitch.MinimumLevel);
+        }
+
+        public static void SetFileMinimumDebugLevel(LogEventLevel level)
+        {
+            _errorLogLevelSwitch.MinimumLevel = level;
+
+            var err = CrestronDataStoreStatic.SetLocalUintValue(ErrorLogLevelStoreKey, (uint)level);
+
+            if (err != CrestronDataStore.CDS_ERROR.CDS_SUCCESS)
+                LogMessage(LogEventLevel.Information, "Error saving File debug level setting: {error}", err);
+
+            LogMessage(LogEventLevel.Information, "File debug level set to {0}", _websocketLoggingLevelSwitch.MinimumLevel);
         }
 
         /// <summary>
@@ -542,16 +582,44 @@ namespace PepperDash.Core
                 CrestronConsole.ConsoleCommandResponse(l + CrestronEnvironment.NewLine);
         }
 
+        /// <summary>
+        /// Log an Exception using Serilog's default Exception logging mechanism
+        /// </summary>
+        /// <param name="ex">Exception to log</param>
+        /// <param name="message">Message template</param>
+        /// <param name="device">Optional IKeyed device. If provided, the Key of the device will be added to the log message</param>
+        /// <param name="args">Args to put into message template</param>
+        public static void LogMessage(Exception ex, string message, IKeyed device = null, params object[] args)
+        {
+            using (LogContext.PushProperty("Key", device?.Key ?? string.Empty))
+            {
+                _logger.Error(ex, message, args);
+            }
+        }
+
+        /// <summary>
+        /// Log a message
+        /// </summary>
+        /// <param name="level">Level to log at</param>
+        /// <param name="message">Message template</param>
+        /// <param name="device">Optional IKeyed device. If provided, the Key of the device will be added to the log message</param>
+        /// <param name="args">Args to put into message template</param>
+        public static void LogMessage(LogEventLevel level, string message, IKeyed device=null, params object[] args)
+        {
+            using (LogContext.PushProperty("Key", device?.Key ?? string.Empty))
+            {
+                _logger.Write(level, message, args);
+            }
+        }
+
         public static void LogMessage(LogEventLevel level, string message, params object[] args)
         {
-            _logger.Write(level, message, args);
+            LogMessage(level, message, null, args);
         }
 
         public static void LogMessage(LogEventLevel level, IKeyed keyed, string message, params object[] args)
         {
-            var log = _logger.ForContext("Key", keyed.Key);
+            LogMessage(level, message, keyed, args);
-
-            log.Write(level, message, args);
         }
 
 
@@ -561,7 +629,7 @@ namespace PepperDash.Core
 
             var logLevel = _logLevels[level];
             
-            LogMessage(logLevel, format, items );
+            LogMessage(logLevel, format, items);
         }
 
         private static void LogMessage(uint level, IKeyed keyed, string format, params object[] items)

src/Pepperdash Core/Logging/DebugConsoleSink.cs

@@ -5,12 +5,7 @@ using Serilog.Core;
 using Serilog.Events;
 using Serilog.Formatting;
 using Serilog.Formatting.Json;
-using System;
+
-using System.Collections.Generic;
-using System.Linq;
-using System.Reflection.Emit;
-using System.Text;
-using System.Threading.Tasks;
 
 namespace PepperDash.Core
 {
@@ -26,7 +21,7 @@ namespace PepperDash.Core
 
             if(logEvent.Properties.TryGetValue("Key",out var value) && value is ScalarValue sv && sv.Value is string rawValue)
             {
-                message = $"[{logEvent.Timestamp}][{logEvent.Level}][App {InitialParametersClass.ApplicationNumber}][{rawValue}]: {logEvent.RenderMessage()}";
+                message = $"[{logEvent.Timestamp}][{logEvent.Level}][App {InitialParametersClass.ApplicationNumber}][{rawValue,3}]: {logEvent.RenderMessage()}";
             }
 
             CrestronConsole.PrintLine(message);

src/Pepperdash Core/Logging/DebugMemory.cs

@@ -2,7 +2,7 @@
 using Crestron.SimplSharp;
 using Newtonsoft.Json;
 
-namespace PepperDash.Core.DebugThings
+namespace PepperDash.Core.Logging
 {
     /// <summary>
     /// Class to persist current Debug settings across program restarts