Make sure stdout-loglevel setting is honored through the whole actor system lifecycle

src/contrib/testkits/Akka.TestKit.Xunit/Internals/Loggers.cs

@@ -5,6 +5,7 @@
 // </copyright>
 //-----------------------------------------------------------------------
 
+using System;
 using Akka.Actor;
 using Akka.Event;
 using Xunit.Abstractions;
@@ -16,20 +17,44 @@ namespace Akka.TestKit.Xunit.Internals
     /// </summary>
     public class TestOutputLogger : ReceiveActor
     {
+        private readonly ITestOutputHelper _output;
+
         /// <summary>
         /// Initializes a new instance of the <see cref="TestOutputLogger"/> class.
         /// </summary>
         /// <param name="output">The provider used to write test output.</param>
         public TestOutputLogger(ITestOutputHelper output)
         {
-            Receive<Debug>(e => output.WriteLine(e.ToString()));
-            Receive<Info>(e => output.WriteLine(e.ToString()));
-            Receive<Warning>(e => output.WriteLine(e.ToString()));
-            Receive<Error>(e => output.WriteLine(e.ToString()));
+            _output = output;
+
+            Receive<Debug>(Write);
+            Receive<Info>(Write);
+            Receive<Warning>(Write);
+            Receive<Error>(Write);
             Receive<InitializeLogger>(e =>
             {
                 e.LoggingBus.Subscribe(Self, typeof (LogEvent));
             });
         }
+
+        private void Write(LogEvent e)
+        {
+            try
+            {
+                _output.WriteLine(e.ToString());
+            }
+            catch (FormatException ex)
+            {
+                if (e.Message is LogMessage msg)
+                {
+                    var message =
+                        $"Received a malformed formatted message. Log level: [{e.LogLevel()}], Template: [{msg.Format}], args: [{string.Join(",", msg.Args)}]";
+                    if(e.Cause != null)
+                        throw new AggregateException(message, ex, e.Cause);
+                    throw new FormatException(message, ex);
+                }
+                throw;
+            }
+        }
     }
 }

src/core/Akka.API.Tests/CoreAPISpec.ApproveCore.approved.txt

@@ -1697,6 +1697,7 @@ namespace Akka.Actor
         public bool SerializeAllMessages { get; }
         public Akka.Actor.Setup.ActorSystemSetup Setup { get; }
         public string StdoutLogLevel { get; }
+        public Akka.Event.MinimalLogger StdoutLogger { get; }
         public string SupervisorStrategyClass { get; }
         public Akka.Actor.ActorSystem System { get; }
         public System.TimeSpan UnstartedPushTimeout { get; }
@@ -3090,7 +3091,7 @@ namespace Akka.Event
         public static string FromType(System.Type t, Akka.Actor.ActorSystem system) { }
         public static System.Type SourceType(object o) { }
     }
-    public class LoggerInitialized : Akka.Actor.INoSerializationVerificationNeeded
+    public class LoggerInitialized : Akka.Actor.INoSerializationVerificationNeeded, Akka.Event.IDeadLetterSuppression
     {
         public LoggerInitialized() { }
     }
@@ -3100,7 +3101,6 @@ namespace Akka.Event
     }
     public class static Logging
     {
-        public static readonly Akka.Event.StandardOutLogger StandardOutLogger;
         public static System.Type ClassFor(this Akka.Event.LogLevel logLevel) { }
         public static Akka.Event.ILoggingAdapter GetLogger(this Akka.Actor.IActorContext context, Akka.Event.ILogMessageFormatter logMessageFormatter = null) { }
         public static Akka.Event.ILoggingAdapter GetLogger(Akka.Actor.ActorSystem system, object logSourceObj, Akka.Event.ILogMessageFormatter logMessageFormatter = null) { }
@@ -3153,6 +3153,14 @@ namespace Akka.Event
         public void SetLogLevel(Akka.Event.LogLevel logLevel) { }
         public void StartStdoutLogger(Akka.Actor.Settings config) { }
     }
+    public abstract class MinimalLogger : Akka.Actor.MinimalActorRef
+    {
+        protected MinimalLogger() { }
+        public virtual Akka.Actor.ActorPath Path { get; }
+        public virtual Akka.Actor.IActorRefProvider Provider { get; }
+        protected abstract void Log(object message);
+        protected virtual void TellInternal(object message, Akka.Actor.IActorRef sender) { }
+    }
     public sealed class NoLogger : Akka.Event.ILoggingAdapter
     {
         public static readonly Akka.Event.ILoggingAdapter Instance;
@@ -3173,18 +3181,15 @@ namespace Akka.Event
         public void Warning(string format, params object[] args) { }
         public void Warning(System.Exception cause, string format, params object[] args) { }
     }
-    public class StandardOutLogger : Akka.Actor.MinimalActorRef
+    public class StandardOutLogger : Akka.Event.MinimalLogger
     {
         public StandardOutLogger() { }
         public static System.ConsoleColor DebugColor { get; set; }
         public static System.ConsoleColor ErrorColor { get; set; }
         public static System.ConsoleColor InfoColor { get; set; }
-        public override Akka.Actor.ActorPath Path { get; }
-        public override Akka.Actor.IActorRefProvider Provider { get; }
         public static bool UseColors { get; set; }
         public static System.ConsoleColor WarningColor { get; set; }
-        public static void PrintLogEvent(Akka.Event.LogEvent logEvent) { }
-        protected override void TellInternal(object message, Akka.Actor.IActorRef sender) { }
+        protected override void Log(object message) { }
     }
     public class Subscription<TSubscriber, TClassifier>
     {

src/core/Akka.TestKit/EventFilter/TestEventListener.cs

@@ -30,57 +30,65 @@ public class TestEventListener : DefaultLogger
         /// <returns>TBD</returns>
         protected override bool Receive(object message)
         {
-            if(message is InitializeLogger)
+            switch (message)
             {
-                var initLogger = (InitializeLogger)message;
-                var bus = initLogger.LoggingBus;
-                var self = Context.Self;
-                bus.Subscribe(self, typeof(Mute));
-                bus.Subscribe(self, typeof(Unmute));
-                bus.Subscribe(self, typeof(DeadLetter));
-                bus.Subscribe(self, typeof(UnhandledMessage));
-                Sender.Tell(new LoggerInitialized());
-            }
-            else if(message is Mute)
-            {
-                var mute = (Mute)message;
-                foreach(var filter in mute.Filters)
+                case InitializeLogger initLogger:
                 {
-                    AddFilter(filter);
+                    base.Receive(message);
+                    var bus = initLogger.LoggingBus;
+                    var self = Context.Self;
+                    bus.Subscribe(self, typeof(Mute));
+                    bus.Subscribe(self, typeof(Unmute));
+                    bus.Subscribe(self, typeof(DeadLetter));
+                    bus.Subscribe(self, typeof(UnhandledMessage));
+                    Sender.Tell(new LoggerInitialized());
+                    break;
                 }
-            }
-            else if(message is Unmute)
-            {
-                var unmute = (Unmute)message;
-                foreach(var filter in unmute.Filters)
+                case Mute mute:
                 {
-                    RemoveFilter(filter);
+                    foreach(var filter in mute.Filters)
+                    {
+                        AddFilter(filter);
+                    }
+
+                    break;
                 }
-            }
-            else if(message is LogEvent)
-            {
-                var logEvent = (LogEvent)message;
-                if(!ShouldFilter(logEvent))
+                case Unmute unmute:
                 {
-                    Print(logEvent);
+                    foreach(var filter in unmute.Filters)
+                    {
+                        RemoveFilter(filter);
+                    }
+
+                    break;
                 }
+                case LogEvent logEvent:
+                {
+                    if(!ShouldFilter(logEvent))
+                    {
+                        Print(logEvent);
+                    }
+
+                    break;
+                }
+                case DeadLetter letter:
+                    HandleDeadLetter(letter);
+                    break;
+
+                case UnhandledMessage un:
+                {
+                    var rcp = un.Recipient;
+                    var warning = new Warning(rcp.Path.ToString(), rcp.GetType(), "Unhandled message from " + un.Sender + ": " + un.Message);
+                    if(!ShouldFilter(warning))
+                        Print(warning);
+                    break;
+                }
+
+                default:
+                    Print(new Debug(Context.System.Name,GetType(),message));
+                    break;
             }
-            else if(message is DeadLetter)
-            {
-                HandleDeadLetter((DeadLetter)message);
-            }
-            else if(message is UnhandledMessage)
-            {
-                var un = (UnhandledMessage) message;
-                var rcp = un.Recipient;
-                var warning = new Warning(rcp.Path.ToString(), rcp.GetType(), "Unhandled message from " + un.Sender + ": " + un.Message);
-                if(!ShouldFilter(warning))
-                    Print(warning);
-            }
-            else
-            {
-                Print(new Debug(Context.System.Name,GetType(),message));
-            }
+
             return true;
         }
 

src/core/Akka.Tests/Configuration/ConfigurationSpec.cs

@@ -42,6 +42,8 @@ public void The_default_configuration_file_contain_all_configuration_properties(
             settings.LoggerStartTimeout.Seconds.ShouldBe(5);
             settings.LogLevel.ShouldBe("INFO");
             settings.StdoutLogLevel.ShouldBe("WARNING");
+            settings.StdoutLogger.Should().NotBeNull();
+            settings.StdoutLogger.Should().BeOfType<StandardOutLogger>();
             settings.LogConfigOnStart.ShouldBeFalse();
             settings.LogDeadLetters.ShouldBe(10);
             settings.LogDeadLettersDuringShutdown.ShouldBeFalse();

src/core/Akka.Tests/Loggers/ShutdownLoggerSpec.cs

@@ -0,0 +1,84 @@
+// //-----------------------------------------------------------------------
+// // <copyright file="ShutdownLoggerSpec.cs" company="Akka.NET Project">
+// //     Copyright (C) 2009-2021 Lightbend Inc. <http://www.lightbend.com>
+// //     Copyright (C) 2013-2021 .NET Foundation <https://github.com/akkadotnet/akka.net>
+// // </copyright>
+// //-----------------------------------------------------------------------
+
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Reflection;
+using System.Threading.Tasks;
+using Akka.Actor;
+using Akka.Configuration;
+using Akka.Event;
+using Akka.TestKit;
+using FluentAssertions;
+using Xunit;
+using Xunit.Abstractions;
+
+namespace Akka.Tests.Loggers
+{
+    public class ShutdownLoggerSpec: AkkaSpec
+    {
+        private static readonly Config Config = ConfigurationFactory.ParseString(@"
+akka.loglevel = OFF
+akka.stdout-loglevel = OFF
+akka.stdout-logger-class = ""Akka.Tests.Loggers.ThrowingLogger, Akka.Tests""");
+
+        public ShutdownLoggerSpec(ITestOutputHelper output) : base(Config, output)
+        {
+        }
+
+        [Fact(DisplayName = "StandardOutLogger should not be called on shutdown when stdout-loglevel is set to OFF")]
+        public async Task StandardOutLoggerShouldNotBeCalled()
+        {
+            Sys.Settings.StdoutLogger.Should().BeOfType<ThrowingLogger>();
+
+            var probeRef = Sys.ActorOf(Props.Create(() => new LogProbe()));
+            probeRef.Tell(new InitializeLogger(Sys.EventStream));
+            var probe = await probeRef.Ask<LogProbe>("hey");
+
+            await Sys.Terminate();
+
+            await Task.Delay(RemainingOrDefault);
+            if (probe.Events.Any(o => o is Error err && err.Cause is ShutdownLogException))
+                throw new Exception("Test failed, log should not be called after shutdown.");
+        }
+    }
+
+    internal class LogProbe : ReceiveActor
+    {
+        public List<LogEvent> Events { get; } = new List<LogEvent>();
+
+        public LogProbe()
+        {
+            Receive<string>(msg => Sender.Tell(this));
+            Receive<LogEvent>(Events.Add);
+            Receive<InitializeLogger>(e =>
+            {
+                e.LoggingBus.Subscribe(Self, typeof (LogEvent));
+                Sender.Tell(new LoggerInitialized());
+            });
+
+        }
+    }
+
+    internal class ShutdownLogException : Exception
+    {
+        public ShutdownLogException()
+        { }
+
+        public ShutdownLogException(string msg) : base(msg)
+        { }
+    }
+
+    internal class ThrowingLogger : MinimalLogger
+    {
+        protected override void Log(object message)
+        {
+            throw new ShutdownLogException("This logger should never be called.");
+        }
+    }
+}

src/core/Akka/Actor/Settings.cs

@@ -11,6 +11,7 @@
 using Akka.Actor.Setup;
 using Akka.Configuration;
 using Akka.Dispatch;
+using Akka.Event;
 using Akka.Routing;
 using ConfigurationFactory = Akka.Configuration.ConfigurationFactory;
 
@@ -109,6 +110,31 @@ public Settings(ActorSystem system, Config config, ActorSystemSetup setup)
 
             LogLevel = Config.GetString("akka.loglevel", null);
             StdoutLogLevel = Config.GetString("akka.stdout-loglevel", null);
+
+            var stdoutClassName = Config.GetString("akka.stdout-logger-class", null);
+            if (string.IsNullOrWhiteSpace(stdoutClassName))
+            {
+                StdoutLogger = new StandardOutLogger();
+            }
+            else
+            {
+                var stdoutLoggerType = Type.GetType(stdoutClassName);
+                if (stdoutLoggerType == null)
+                    throw new ArgumentException($"Could not load type of {stdoutClassName} for standard out logger.");
+                if(!typeof(MinimalLogger).IsAssignableFrom(stdoutLoggerType))
+                    throw new ArgumentException("Standard out logger type must inherit from the MinimalLogger abstract class.");
+
+                try
+                {
+                    StdoutLogger = (MinimalLogger)Activator.CreateInstance(stdoutLoggerType);
+                }
+                catch (MissingMethodException)
+                {
+                    throw new MissingMethodException(
+                        "Standard out logger type must inherit from the MinimalLogger abstract class and have an empty constructor.");
+                }
+            }
+
             Loggers = Config.GetStringList("akka.loggers", new string[] { });
             LoggersDispatcher = Config.GetString("akka.loggers-dispatcher", null);
             LoggerStartTimeout = Config.GetTimeSpan("akka.logger-startup-timeout", null);
@@ -247,6 +273,11 @@ public Settings(ActorSystem system, Config config, ActorSystemSetup setup)
         /// <value>The stdout log level.</value>
         public string StdoutLogLevel { get; private set; }
 
+        /// <summary>
+        /// Returns a singleton instance of the standard out logger.
+        /// </summary>
+        public MinimalLogger StdoutLogger { get; }
+
         /// <summary>
         ///     Gets the loggers.
         /// </summary>

src/core/Akka/Configuration/Pigeon.conf

@@ -42,6 +42,10 @@ akka {
   # Log level for the very basic logger activated during AkkaApplication startup
   # Options: OFF, ERROR, WARNING, INFO, DEBUG
   stdout-loglevel = "WARNING"
+
+  # Fully qualified class name (FQCN) of the very basic logger used on startup and shutdown.
+  # You can substitute the logger by supplying an FQCN to a custom class that implements Akka.Event.MinimumLogger
+  stdout-logger-class = "Akka.Event.StandardOutLogger"
 
   # Log the complete configuration at INFO level when the actor system is started.
   # This is useful when you are uncertain of what configuration is used.