Log output verification test

src/Akka.Logger.Serilog.Tests/LogMessageSpecs.cs

@@ -1,4 +1,5 @@
 using System;
+using System.Collections.Generic;
 using Akka.Actor;
 using Akka.Configuration;
 using Akka.Event;
@@ -7,6 +8,7 @@
 using Serilog.Events;
 using Xunit;
 using Xunit.Abstractions;
+using LogEvent = Akka.Event.LogEvent;
 
 namespace Akka.Logger.Serilog.Tests
 {
@@ -16,17 +18,50 @@ public class LogMessageSpecs : TestKit.Xunit2.TestKit
                                                  akka.loggers=[""Akka.Logger.Serilog.SerilogLogger, Akka.Logger.Serilog""]";
 
         private readonly ILoggingAdapter _loggingAdapter;
-        private readonly TestSink _sink = new TestSink();
+        private readonly TestSink _sink;
 
         public LogMessageSpecs(ITestOutputHelper helper) : base(Config, output: helper)
         {
+            _sink = new TestSink(helper);
             global::Serilog.Log.Logger = new LoggerConfiguration()
                 .WriteTo.Sink(_sink)
                 .MinimumLevel.Debug()
                 .CreateLogger();
             _loggingAdapter = Sys.Log;
         }
 
+        [Fact]
+        public void LogOutputRegressionTest()
+        {
+            const string message = "{0} {1} {2} {3}";
+            const string expectedMessage = "[0, 1, 2] [0.1, 0.2, 0.3] [\"One\", \"Two\"] [1, 2, 3]";
+            var args = new object[]
+            {
+                new int[] { 0, 1, 2 },
+                new double[] { 0.1, 0.2, 0.3 },
+                new string[] { "One", "Two" },
+                new List<double> { 1, 2, 3 }
+            };
+
+            _sink.Clear();
+            AwaitCondition(() => _sink.Writes.Count == 0);
+
+            global::Serilog.Log.Logger.Information(message, args);
+            AwaitCondition(() => _sink.Writes.Count == 1);
+
+            _sink.Writes.TryDequeue(out var logEvent).Should().BeTrue();
+            logEvent.RenderMessage().Should().Be(expectedMessage);
+
+            Sys.EventStream.Subscribe(TestActor, typeof(LogEvent));
+            _loggingAdapter.Info(message, args);
+            var akkaLogEvent = ExpectMsg<LogEvent>();
+            AwaitCondition(() => _sink.Writes.Count == 1);
+            _sink.Writes.TryDequeue(out logEvent).Should().BeTrue();
+
+            logEvent.RenderMessage().Should().Contain(expectedMessage);
+            akkaLogEvent.ToString().Should().Contain(expectedMessage);
+        }
+
         [Fact]
         public void ShouldLogDebugLevelMessage()
         {

src/Akka.Logger.Serilog.Tests/SerilogFormattingSpecs.cs

@@ -1,34 +1,75 @@
 using System;
+using System.Collections.Generic;
 using Akka.Actor;
 using Akka.Configuration;
 using Akka.Event;
 using FluentAssertions;
 using Serilog;
 using Xunit;
 using Xunit.Abstractions;
+using SerilogLog = Serilog.Log;
 
 namespace Akka.Logger.Serilog.Tests
 {
     public class SerilogFormattingSpecs : TestKit.Xunit2.TestKit
     {
-        public static readonly Config Config = @"akka.loglevel = DEBUG";
-        private ILogger _serilogLogger;
+        public static readonly Config Config = 
+@"
+akka.loglevel = DEBUG
+# akka.loggers=[""Akka.Logger.Serilog.SerilogLogger, Akka.Logger.Serilog""]
+";
+        private readonly ILogger _serilogLogger;
+        private readonly TestSink _sink;
 
-        private ILoggingAdapter _loggingAdapter;
+        private readonly ILoggingAdapter _loggingAdapter;
 
         public SerilogFormattingSpecs(ITestOutputHelper helper) : base(Config, output: helper)
         {
+            _sink = new TestSink(helper);
+
             _serilogLogger = new LoggerConfiguration()
                 .WriteTo.ColoredConsole()
+                .WriteTo.Sink(_sink)
                 .MinimumLevel.Information()
                 .CreateLogger();
+
+            SerilogLog.Logger = _serilogLogger;
 
             var logSource = Sys.Name;
             var logClass = typeof(ActorSystem);
 
             _loggingAdapter = new SerilogLoggingAdapter(Sys.EventStream, logSource, logClass);
         }
 
+        [Fact]
+        public void LogOutputRegressionTest()
+        {
+            const string message = "{IntArray} {DoubleArray} {StringArray} {DoubleList}";
+            const string expectedMessage = "[0, 1, 2] [0.1, 0.2, 0.3] [\"One\", \"Two\"] [1, 2, 3]";
+            var args = new object[]
+            {
+                new int[] { 0, 1, 2 },
+                new double[] { 0.1, 0.2, 0.3 },
+                new string[] { "One", "Two" },
+                new List<double> { 1, 2, 3 }
+            };
+
+            _sink.Clear();
+            AwaitCondition(() => _sink.Writes.Count == 0);
+
+            _serilogLogger.Information(message, args);
+            AwaitCondition(() => _sink.Writes.Count == 1);
+
+            _sink.Writes.TryDequeue(out var logEvent).Should().BeTrue();
+            logEvent.RenderMessage().Should().Be(expectedMessage);
+
+            Sys.EventStream.Subscribe(TestActor, typeof(LogEvent));
+            _loggingAdapter.Log(LogLevel.InfoLevel, message, args);
+            var akkaLogEvent = ExpectMsg<LogEvent>();
+
+            akkaLogEvent.ToString().Should().Contain(expectedMessage);
+        }
+
         [Theory]
         [InlineData(LogLevel.DebugLevel, "test case {0}", new object[]{ 1 })]
         [InlineData(LogLevel.DebugLevel, "test case {myNum}", new object[] { 1 })]

src/Akka.Logger.Serilog.Tests/TestSink.cs

@@ -2,6 +2,7 @@
 using Serilog.Core;
 using Serilog.Events;
 using Xunit;
+using Xunit.Abstractions;
 
 [assembly: CollectionBehavior(DisableTestParallelization = true)]
 
@@ -15,6 +16,18 @@ public sealed class TestSink : ILogEventSink
     {
         public ConcurrentQueue<global::Serilog.Events.LogEvent> Writes { get; private set; } = new ConcurrentQueue<global::Serilog.Events.LogEvent>();
 
+        private readonly ITestOutputHelper _output;
+        private int _count;
+
+        public TestSink(): this(null)
+        { }
+
+        public TestSink(ITestOutputHelper output)
+        {
+            _output = output;
+        }
+
+
         /// <summary>
         /// Resets the contents of the queue
         /// </summary>
@@ -25,6 +38,8 @@ public void Clear()
 
         public void Emit(global::Serilog.Events.LogEvent logEvent)
         {
+            _count++;
+            _output?.WriteLine($"[{nameof(TestSink)}][{_count}]: {logEvent.RenderMessage()}");
             Writes.Enqueue(logEvent);
         }
     }