Merge pull request #174 from PepperDash/feature-2/fix-logError-message

Logging updates

src/Pepperdash Core/Logging/CrestronEnricher.cs

@@ -0,0 +1,37 @@
+using Crestron.SimplSharp;
+using Serilog.Core;
+using Serilog.Events;
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+
+namespace PepperDash.Core.Logging
+{
+    public class CrestronEnricher : ILogEventEnricher
+    {
+        static readonly string _appName;
+
+        static CrestronEnricher()
+        {
+            switch (CrestronEnvironment.DevicePlatform)
+            {
+                case eDevicePlatform.Appliance:
+                    _appName = $"App {InitialParametersClass.ApplicationNumber}";
+                    break;
+                case eDevicePlatform.Server:
+                    _appName = $"{InitialParametersClass.RoomId}";
+                    break;
+            }
+        }
+            
+
+        public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
+        {
+            var property = propertyFactory.CreateProperty("App", _appName);
+
+            logEvent.AddOrUpdateProperty(property);
+        }
+    }
+}

src/Pepperdash Core/Logging/Debug.cs

@@ -10,6 +10,7 @@ using Serilog.Core;
 using Serilog.Events;
 using Serilog.Formatting.Compact;
 using Serilog.Formatting.Json;
+using Serilog.Templates;
 using System;
 using System.Collections.Generic;
 using System.Reflection;
@@ -143,12 +144,17 @@ namespace PepperDash.Core
 
             CrestronConsole.PrintLine($"Saving log files to {logFilePath}");
 
+            var errorLogTemplate = CrestronEnvironment.DevicePlatform == eDevicePlatform.Appliance 
+                ? "{@t:fff}ms [{@l:u4}]{#if Key is not null}[{Key}]{#end} {@m}{#if @x is not null}\r\n{@x}{#end}"
+                : "[{@t:yyyy-MM-dd HH:mm:ss.fff}][{@l:u4}][{App}]{#if Key is not null}[{Key}]{#end} {@m}{#if @x is not null}\r\n{@x}{#end}";
+
             _defaultLoggerConfiguration = new LoggerConfiguration()
                 .MinimumLevel.Verbose()
                 .Enrich.FromLogContext()
-                .WriteTo.Sink(new DebugConsoleSink(new JsonFormatter(renderMessage: true)), levelSwitch: _consoleLoggingLevelSwitch)
+                .Enrich.With(new CrestronEnricher())
+                .WriteTo.Sink(new DebugConsoleSink(new ExpressionTemplate("[{@t:yyyy-MM-dd HH:mm:ss.fff}][{@l:u4}][{App}]{#if Key is not null}[{Key}]{#end} {@m}{#if @x is not null}\r\n{@x}{#end}")), levelSwitch: _consoleLoggingLevelSwitch)
                 .WriteTo.Sink(_websocketSink, levelSwitch: _websocketLoggingLevelSwitch)
-                .WriteTo.Sink(new DebugErrorLogSink(), levelSwitch: _errorLogLevelSwitch)
+                .WriteTo.Sink(new DebugErrorLogSink(new ExpressionTemplate(errorLogTemplate)), levelSwitch: _errorLogLevelSwitch)
                 .WriteTo.File(new RenderedCompactJsonFormatter(), logFilePath,                                    
                     rollingInterval: RollingInterval.Day,
                     restrictedToMinimumLevel: LogEventLevel.Debug,
@@ -187,7 +193,7 @@ namespace PepperDash.Core
 
             CrestronConsole.PrintLine(msg);
 
-            LogError(ErrorLogLevel.Notice, msg);
+            LogMessage(LogEventLevel.Information,msg);
 
 			IncludedExcludedKeys = new Dictionary<string, object>();
             
@@ -591,7 +597,7 @@ namespace PepperDash.Core
         /// <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))
+            using (LogContext.PushProperty("Key", device?.Key))
             {
                 _logger.Error(ex, message, args);
             }
@@ -606,7 +612,7 @@ namespace PepperDash.Core
         /// <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))
+            using (LogContext.PushProperty("Key", device?.Key))
             {
                 _logger.Write(level, message, args);
             }
@@ -691,25 +697,8 @@ namespace PepperDash.Core
         [Obsolete("Use LogMessage methods")]
         public static void Console(uint level, IKeyed dev, ErrorLogLevel errorLogLevel,
             string format, params object[] items)
-        {
+        {           
-
-            var str = string.Format("[{0}] {1}", dev.Key, string.Format(format, items));
-            if (errorLogLevel != ErrorLogLevel.None)
-            {
-                LogError(errorLogLevel, str);
-            }
-
             LogMessage(level, dev, format, items);
-
-            //var log = _logger.ForContext("Key", dev.Key);
-            //var message = string.Format(format, items);
-
-            //log.Write((LogEventLevel)level, message);
-
-            //if (Level >= level)
-            //{
-            //    Console(level, str);
-            //}
         }
 
         /// <summary>
@@ -719,17 +708,7 @@ namespace PepperDash.Core
         public static void Console(uint level, ErrorLogLevel errorLogLevel,
             string format, params object[] items)
         {
-            var str = string.Format(format, items);
-            if (errorLogLevel != ErrorLogLevel.None)
-            {
-                LogError(errorLogLevel, str);
-            }
-
             LogMessage(level, format, items);
-			//if (Level >= level)
-			//{
-			//	Console(level, str);
-			//}
         }
 
         /// <summary>
@@ -770,18 +749,16 @@ namespace PepperDash.Core
         [Obsolete("Use LogMessage methods")]
         public static void LogError(ErrorLogLevel errorLogLevel, string str)
         {
-
-            var msg = IsRunningOnAppliance ? string.Format("App {0}:{1}", InitialParametersClass.ApplicationNumber, str) : string.Format("Room {0}:{1}", InitialParametersClass.RoomId, str);
             switch (errorLogLevel)
             {
                 case ErrorLogLevel.Error:
-                    ErrorLog.Error(msg);
+                    LogMessage(LogEventLevel.Error, str);
                     break;
                 case ErrorLogLevel.Warning:
-                    ErrorLog.Warn(msg);
+                    LogMessage(LogEventLevel.Warning, str);
                     break;
                 case ErrorLogLevel.Notice:
-                    ErrorLog.Notice(msg);
+                    LogMessage(LogEventLevel.Information, str);
                     break;
             }
         }

src/Pepperdash Core/Logging/DebugConsoleSink.cs

@@ -5,6 +5,8 @@ using Serilog.Core;
 using Serilog.Events;
 using Serilog.Formatting;
 using Serilog.Formatting.Json;
+using System.IO;
+using System.Text;
 
 
 namespace PepperDash.Core
@@ -17,12 +19,18 @@ namespace PepperDash.Core
         {
             if (!Debug.IsRunningOnAppliance) return;            
 
-            string message = $"[{logEvent.Timestamp}][{logEvent.Level}][App {InitialParametersClass.ApplicationNumber}]{logEvent.RenderMessage()}";
+            /*string message = $"[{logEvent.Timestamp}][{logEvent.Level}][App {InitialParametersClass.ApplicationNumber}]{logEvent.RenderMessage()}";
 
             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,3}]: {logEvent.RenderMessage()}";
-            }
+            }*/
+
+            var buffer = new StringWriter(new StringBuilder(256));
+
+            _textFormatter.Format(logEvent, buffer);
+
+            var message = buffer.ToString();
 
             CrestronConsole.PrintLine(message);
         }

src/Pepperdash Core/Logging/DebugErrorLogSink.cs

@@ -1,8 +1,10 @@
 using Crestron.SimplSharp;
 using Serilog.Core;
 using Serilog.Events;
+using Serilog.Formatting;
 using System;
 using System.Collections.Generic;
+using System.IO;
 using System.Linq;
 using System.Text;
 using System.Threading.Tasks;
@@ -11,6 +13,8 @@ namespace PepperDash.Core.Logging
 {
     public class DebugErrorLogSink : ILogEventSink
     {
+        private ITextFormatter _formatter;
+
         private Dictionary<LogEventLevel, Action<string>> _errorLogMap = new Dictionary<LogEventLevel, Action<string>>
         {
             { LogEventLevel.Verbose, (msg) => ErrorLog.Notice(msg) },
@@ -22,15 +26,27 @@ namespace PepperDash.Core.Logging
         };
         public void Emit(LogEvent logEvent)
         {
-            var programId = CrestronEnvironment.DevicePlatform == eDevicePlatform.Appliance
+            string message;
-                ? $"App {InitialParametersClass.ApplicationNumber}"
-                : $"Room {InitialParametersClass.RoomId}";
 
-            string message = $"[{logEvent.Timestamp}][{logEvent.Level}][{programId}]{logEvent.RenderMessage()}";
+            if (_formatter == null)
-
-            if (logEvent.Properties.TryGetValue("Key", out var value) && value is ScalarValue sv && sv.Value is string rawValue)
             {
-                message = $"[{logEvent.Timestamp}][{logEvent.Level}][{programId}][{rawValue}]: {logEvent.RenderMessage()}";
+                var programId = CrestronEnvironment.DevicePlatform == eDevicePlatform.Appliance
+                    ? $"App {InitialParametersClass.ApplicationNumber}"
+                    : $"Room {InitialParametersClass.RoomId}";
+
+                message = $"[{logEvent.Timestamp}][{logEvent.Level}][{programId}]{logEvent.RenderMessage()}";
+
+                if (logEvent.Properties.TryGetValue("Key", out var value) && value is ScalarValue sv && sv.Value is string rawValue)
+                {
+                    message = $"[{logEvent.Timestamp}][{logEvent.Level}][{programId}][{rawValue}]: {logEvent.RenderMessage()}";
+                }
+            } else
+            {
+                var buffer = new StringWriter(new StringBuilder(256));
+
+                _formatter.Format(logEvent, buffer);
+
+                message = buffer.ToString();
             }
 
             if(!_errorLogMap.TryGetValue(logEvent.Level, out var handler))
@@ -40,5 +56,10 @@ namespace PepperDash.Core.Logging
 
             handler(message);
         }
+
+        public DebugErrorLogSink(ITextFormatter formatter = null)
+        {
+            _formatter = formatter;
+        }
     }
 }

src/Pepperdash Core/Logging/DebugExtensions.cs

@@ -0,0 +1,39 @@
+using Serilog;
+using Serilog.Events;
+using Log = PepperDash.Core.Debug;
+
+namespace PepperDash.Core.Logging
+{
+    public static class DebugExtensions
+    {
+        public static void LogVerbose(this IKeyed device, string message, params object[] args)
+        {
+            Log.LogMessage(LogEventLevel.Verbose, device, message, args);
+        }
+
+        public static void LogDebug(this IKeyed device, string message, params object[] args)
+        {
+            Log.LogMessage(LogEventLevel.Debug, device, message, args);
+        }
+
+        public static void LogInformation(this IKeyed device, string message, params object[] args)
+        {
+            Log.LogMessage(LogEventLevel.Information, device, message, args);
+        }
+
+        public static void LogWarning(this IKeyed device, string message, params object[] args)
+        {
+            Log.LogMessage(LogEventLevel.Warning, device, message, args);
+        }
+
+        public static void LogError(this IKeyed device, string message, params object[] args)
+        {
+            Log.LogMessage(LogEventLevel.Error, device, message, args);
+        }
+
+        public static void LogFatal(this IKeyed device, string message, params object[] args)
+        {
+            Log.LogMessage(LogEventLevel.Fatal, device, message, args);
+        }
+    }
+}

src/Pepperdash Core/PepperDash_Core.csproj

@@ -33,10 +33,11 @@
   </ItemGroup>
   <ItemGroup>
     <PackageReference Include="BouncyCastle" Version="1.8.9" />
-    <PackageReference Include="Crestron.SimplSharp.SDK.Library" Version="2.20.42" />
+    <PackageReference Include="Crestron.SimplSharp.SDK.Library" Version="2.20.66" />
     <PackageReference Include="Serilog" Version="3.1.1" />
+    <PackageReference Include="Serilog.Expressions" Version="4.0.0" />
     <PackageReference Include="Serilog.Formatting.Compact" Version="2.0.0" />
-    <PackageReference Include="Serilog.Sinks.Console" Version="5.0.0" />
+    <PackageReference Include="Serilog.Sinks.Console" Version="5.0.1" />
     <PackageReference Include="Serilog.Sinks.File" Version="5.0.0" />
     <PackageReference Include="WebSocketSharp" Version="1.0.3-rc11" />
   </ItemGroup>