Merge pull request #19 from altso/log-timestamp

Support timestamps in log messages
altso · Apr 17, 2023 · 8e15a09 · 8e15a09
2 parents ef028d4 + 240c00d
commit 8e15a09
Show file tree

Hide file tree

Showing 4 changed files with 121 additions and 16 deletions.
diff --git a/Source/ExcelRna.Extensions.Logging.Tests/LogDisplayLoggerTests.cs b/Source/ExcelRna.Extensions.Logging.Tests/LogDisplayLoggerTests.cs
@@ -42,7 +42,7 @@ public void Log_is_noop_when_not_enabled()
         // ARRANGE
         var logger = new LogDisplayLogger("Test")
         {
-            RecordLine = Mock.Of<Action<string, string[]>>(MockBehavior.Strict),
+            RecordLine = Mock.Of<Action<string, object[]>>(MockBehavior.Strict),
         };
 
         // ACT
@@ -55,7 +55,7 @@ public void Log_is_noop_when_message_is_empty()
         // ARRANGE
         var logger = new LogDisplayLogger("Test")
         {
-            RecordLine = Mock.Of<Action<string, string[]>>(MockBehavior.Strict),
+            RecordLine = Mock.Of<Action<string, object[]>>(MockBehavior.Strict),
         };
 
         // ACT
@@ -68,7 +68,7 @@ public void Log_throws_when_formatter_is_null()
         // ARRANGE
         var logger = new LogDisplayLogger("Test")
         {
-            RecordLine = Mock.Of<Action<string, string[]>>(MockBehavior.Strict),
+            RecordLine = Mock.Of<Action<string, object[]>>(MockBehavior.Strict),
         };
 
         // ACT & ASSERT
@@ -79,34 +79,96 @@ public void Log_throws_when_formatter_is_null()
     public void Log_includes_exception()
     {
         // ARRANGE
-        var logger = new LogDisplayLogger("Test")
+        var logger = new LogDisplayLogger("Test", new LogDisplayLoggerOptions
+        {
+            TimestampFormat = "G",
+        })
         {
-            RecordLine = Mock.Of<Action<string, string[]>>(),
+            RecordLine = Mock.Of<Action<string, object[]>>(),
         };
 
         // ACT
-        logger.Log(LogLevel.Information, new Exception("TestException"), "TestMessage");
+        logger.Log(LogLevel.Debug, new Exception("TestException"), "TestMessage");
 
         // ASSERT
         Mock.Get(logger.RecordLine).Verify(invoke => invoke(
             It.Is<string>(s => s.Contains("TestMessage") && s.Contains("TestException")),
-            It.Is<string[]>(p => p.Length == 0)), Times.Once);
+            It.Is<object[]>(p => p.Length == 0)), Times.Once);
     }
 
     [Fact]
-    public void Log_auto_shows_LogDisplay()
+    public void Log_includes_timestamp()
+    {
+        // ARRANGE
+        var logger = new LogDisplayLogger("Test", new LogDisplayLoggerOptions
+        {
+            TimestampFormat = "yyyy-MM-dd HH:mm:ss ",
+        })
+        {
+            RecordLine = Mock.Of<Action<string, object[]>>(),
+            GetCurrentTimestamp = () => new DateTimeOffset(2023, 04, 17, 13, 34, 00, TimeSpan.Zero),
+        };
+
+        // ACT
+        logger.Log(LogLevel.Trace, new Exception("TestException"), "TestMessage");
+
+        // ASSERT
+        Mock.Get(logger.RecordLine).Verify(invoke => invoke(
+            It.Is<string>(s => s.Contains("2023-04-17 13:34:00")),
+            It.Is<object[]>(p => p.Length == 0)), Times.Once);
+    }
+
+
+    [Theory]
+    [InlineData(LogLevel.Error)]
+    [InlineData(LogLevel.Critical)]
+    public void Log_auto_shows_LogDisplay(LogLevel level)
     {
         // ARRANGE
         var logger = new LogDisplayLogger("Test")
         {
-            RecordLine = Mock.Of<Action<string, string[]>>(),
+            RecordLine = Mock.Of<Action<string, object[]>>(),
             Show = Mock.Of<Action>(),
         };
 
         // ACT
-        logger.Log(LogLevel.Error, new Exception("TestException"), "TestMessage");
+        logger.Log(level, new Exception("TestException"), "TestMessage");
 
         // ASSERT
         Mock.Get(logger.Show).Verify(invoke => invoke(), Times.Once);
     }
+
+    [Theory]
+    [InlineData(LogLevel.Trace)]
+    [InlineData(LogLevel.Debug)]
+    [InlineData(LogLevel.Information)]
+    [InlineData(LogLevel.Warning)]
+    public void Log_does_not_show_LogDisplay(LogLevel level)
+    {
+        // ARRANGE
+        var logger = new LogDisplayLogger("Test")
+        {
+            RecordLine = Mock.Of<Action<string, object[]>>(),
+            Show = Mock.Of<Action>(),
+        };
+
+        // ACT
+        logger.Log(level, new Exception("TestException"), "TestMessage");
+
+        // ASSERT
+        Mock.Get(logger.Show).Verify(invoke => invoke(), Times.Never);
+    }
+
+    [Fact]
+    public void Log_throws_when_logLevel_is_wrong()
+    {
+        // ARRANGE
+        var logger = new LogDisplayLogger("Test");
+
+        // ACT & ASSERT
+        Assert.Throws<ArgumentOutOfRangeException>(() =>
+        {
+            logger.Log((LogLevel)100, new Exception("TestException"), "TestMessage");
+        });
+    }
 }
diff --git a/Source/ExcelRna.Extensions.Logging/LogDisplayLogger.cs b/Source/ExcelRna.Extensions.Logging/LogDisplayLogger.cs
@@ -1,4 +1,5 @@
 using System;
+using System.Text;
 using ExcelDna.Logging;
 using Microsoft.Extensions.Logging;
 
@@ -22,20 +23,23 @@ public LogDisplayLogger(string name, LogDisplayLoggerOptions? options = null)
         Options = options ?? new LogDisplayLoggerOptions();
     }
 
-    internal Action<string, string[]> RecordLine { get; set; } = LogDisplay.RecordLine;
+    internal Action<string, object[]> RecordLine { get; set; } = LogDisplay.RecordLine;
 
     internal Action Show { get; set; } = LogDisplay.Show;
 
     internal LogDisplayLoggerOptions Options { get; set; }
 
+    internal Func<DateTimeOffset> GetCurrentTimestamp { get; set; } = () => DateTimeOffset.Now;
+
     /// <inheritdoc />
     public bool IsEnabled(LogLevel logLevel) => logLevel != LogLevel.None;
 
     /// <inheritdoc />
     public IDisposable BeginScope<TState>(TState state) => NullScope.Instance;
 
     /// <inheritdoc />
-    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception,
+        Func<TState, Exception?, string> formatter)
     {
         if (!IsEnabled(logLevel))
         {
@@ -54,18 +58,46 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
             return;
         }
 
-        message = $"{_name} [{logLevel}] {message}";
+        StringBuilder builder = new();
+
+        if (Options.TimestampFormat != null)
+        {
+            DateTimeOffset dateTimeOffset = GetCurrentTimestamp();
+            builder.Append(dateTimeOffset.ToString(Options.TimestampFormat));
+            builder.Append(" ");
+        }
+
+        builder.Append(GetLogLevelString(logLevel));
+        builder.Append(": ");
+        builder.Append(_name);
+        builder.Append(" ");
+        builder.Append(message);
 
         if (exception != null)
         {
-            message += Environment.NewLine + exception;
+            builder.AppendLine();
+            builder.Append(exception);
         }
 
-        RecordLine(message, Array.Empty<string>());
+        RecordLine(builder.ToString(), Array.Empty<object>());
 
         if (logLevel >= Options.AutoShowLogDisplayThreshold)
         {
             Show();
         }
     }
+
+    private static string GetLogLevelString(LogLevel logLevel)
+    {
+        return logLevel switch
+        {
+            LogLevel.Trace => "trce",
+            LogLevel.Debug => "dbug",
+            LogLevel.Information => "info",
+            LogLevel.Warning => "warn",
+            LogLevel.Error => "fail",
+            LogLevel.Critical => "crit",
+            _ => throw new ArgumentOutOfRangeException(nameof(logLevel))
+        };
+    }
 }
diff --git a/Source/ExcelRna.Extensions.Logging/LogDisplayLoggerOptions.cs b/Source/ExcelRna.Extensions.Logging/LogDisplayLoggerOptions.cs
@@ -5,4 +5,9 @@ namespace ExcelRna.Extensions.Logging;
 public class LogDisplayLoggerOptions
 {
     public LogLevel AutoShowLogDisplayThreshold { get; set; } = LogLevel.Error;
+
+    /// <summary>
+    /// Gets or sets format string used to format timestamp in logging messages. Defaults to <c>null</c>.
+    /// </summary>
+    public string? TimestampFormat { get; set; }
 }
diff --git a/Source/Samples/QuickStart/QuickStartAddIn.cs b/Source/Samples/QuickStart/QuickStartAddIn.cs
@@ -19,7 +19,13 @@ public class QuickStartAddIn : HostedExcelAddIn
     protected override void AutoClose(IHost host) => IntelliSenseServer.Uninstall();
 
     protected override IHostBuilder CreateHostBuilder() => Host.CreateDefaultBuilder()
-        .ConfigureLogging(logging => { logging.AddLogDisplay(); })
+        .ConfigureLogging(logging =>
+        {
+            logging.AddLogDisplay(options =>
+        {
+            options.TimestampFormat = "G";
+        });
+        })
         .ConfigureServices(services =>
         {
             services.AddTransient<IQuickStartService, QuickStartService>();