Customizable ILogMessageFormatter across entire ActorSystem

docs/articles/utilities/logging.md

@@ -1,11 +1,12 @@
 ---
 uid: logging
-title: Logging
+title: Logging in Akka.NET
 ---
 
 # Logging
 
-For more info see real Akka's documentation: <http://doc.akka.io/docs/akka/2.0/scala/logging.html>
+> ![NOTE]
+> For information on how to use Serilog with Akka.NET, we have a dedicated page for that: "[Using Serilog for Akka.NET Logging](xref:serilog)."
 
 ## How to Log
 
@@ -52,13 +53,13 @@ name into the `akka.stdout-logger-class` HOCON settings.
 > Note that `MinimalLogger` are __NOT__ interchangeable with other Akka.NET loggers and there can
 > only be one `MinimalLogger` registered with the `ActorSystem` in the HOCON settings.
 
-## Contrib Loggers
+## Third Party Loggers
 
 These loggers are also available as separate nuget packages
 
-* __Akka.Logger.slf4net__ which logs using [slf4net](https://github.com/englishtown/slf4net)
 * __Akka.Logger.Serilog__ which logs using [serilog](http://serilog.net/). See [Detailed instructions on using Serilog](xref:serilog).
 * __Akka.Logger.NLog__  which logs using [NLog](http://nlog-project.org/)
+* __Microsoft.Extensions.Logging__ - which is [built into Akka.Hosting](https://github.com/akkadotnet/Akka.Hosting#microsoftextensionslogging-integration).
 
 Note that you need to modify the config as explained below.
 
@@ -84,6 +85,62 @@ akka {
 }
 ```
 
+Or using [Akka.Hosting](https://github.com/akkadotnet/Akka.Hosting), you can configure loggers programmatically using strongly typed references to the underlying logging classes:
+
+```csharp
+builder.Services.AddAkka("MyActorSystem", configurationBuilder =>
+{
+    configurationBuilder
+        .ConfigureLoggers(setup =>
+        {
+            // Example: This sets the minimum log level
+            setup.LogLevel = LogLevel.DebugLevel;
+
+            // Example: Clear all loggers
+            setup.ClearLoggers();
+
+            // Example: Add the default logger
+            // NOTE: You can also use setup.AddLogger<DefaultLogger>();
+            setup.AddDefaultLogger();
+
+            // Example: Add the ILoggerFactory logger
+            // NOTE:
+            //   - You can also use setup.AddLogger<LoggerFactoryLogger>();
+            //   - To use a specific ILoggerFactory instance, you can use setup.AddLoggerFactory(myILoggerFactory);
+            setup.AddLoggerFactory();
+
+            // Example: Adding a serilog logger
+            setup.AddLogger<SerilogLogger>();
+        })
+        .WithActors((system, registry) =>
+        {
+            var echo = system.ActorOf(act =>
+            {
+                act.ReceiveAny((o, context) =>
+                {
+                    Logging.GetLogger(context.System, "echo").Info($"Actor received {o}");
+                    context.Sender.Tell($"{context.Self} rcv {o}");
+                });
+            }, "echo");
+            registry.TryRegister<Echo>(echo); // register for DI
+        });
+});
+```
+
+### Customizing the `ILogMessageFormatter`
+
+A new feature introduced in [Akka.NET v1.5](xref:akkadotnet-v15-whats-new), you now have the ability to customize the `ILogMessageFormatter` - the component responsible for formatting output written to all `Logger` implementations in Akka.NET.
+
+The primary use case for this is supporting semantic logging across the board in your user-defined actors, which is something that [Akka.Logger.Serilog](xref:serilog) supports quite well.
+
+However, maybe there are certain pieces of data you want to have injected into all of the log messages produced by Akka.NET internally - that's the sort of thing you can accomplish by customizing the `ILogMessageFormatter`:
+
+[!code-csharp[CustomLogMessageFormatter](../../../src/core/Akka.Tests/Loggers/CustomLogFormatterSpec.cs?name=CustomLogFormatter)]
+
+This class will be responsible for formatting all log messages when they're written out to your configured sinks - once we configure it in HOCON using the `akka.logger-formatter` setting:
+
+[!code-csharp[CustomLogMessageFormatter](../../../src/core/Akka.Tests/Loggers/CustomLogFormatterSpec.cs?name=CustomLogFormatterConfig)]
+
 ## Logging Unhandled Messages
 
 It is possible to configure akka so that Unhandled messages are logged as Debug log events for debug purposes. This can be achieved using the following configuration setting:
@@ -113,7 +170,7 @@ akka {
 }
 ```
 
-## Logging All Receive'd Messages
+## Logging All Received Messages
 
 It is possible to log all Receive'd messages, usually for debug purposes. This can be achieved by implementing the ILogReceive interface:
 

docs/articles/utilities/serilog.md

@@ -1,9 +1,9 @@
 ---
 uid: serilog
-title: Serilog
+title: Using Serilog for Akka.NET Logging
 ---
 
-# Using Serilog
+# Using Serilog for Akka.NET Logging
 
 ## Setup
 
@@ -87,7 +87,28 @@ var log = Context.GetLogger();
 log.Info("The value is {Counter}", counter);
 ```
 
-## Extensions
+## Enabling Semantic Logging in Akka.NET v1.5+
+
+In order for logging statements like below to be parsed correctly:
+
+```csharp
+var log = Context.GetLogger();
+...
+log.Info("The value is {Counter}", counter);
+```
+
+You need to enable the `Akka.Logger.Serilog.SerilogLogMessageFormatter` across your entire `ActorSystem` - this will replace Akka.NET's default `ILogMessageFormatter` with Serilog's.
+
+You can accomplish this by setting the `akka.logger-formatter` setting like below:
+
+```hocon
+akka.logger-formatter="Akka.Logger.Serilog.SerilogLogMessageFormatter, Akka.Logger.Serilog"
+```
+
+## Extensions for Akka.NET v1.4 and Older
+
+> ![IMPORTANT]
+> This methodology is obsolete as of [Akka.NET v1.5](xref:akkadotnet-v15-whats-new), but we're leaving it documented for legacy purposes.
 
 The package __Akka.Logger.Serilog__ also includes the extension method `ForContext()` for `ILoggingAdapter` (the object returned by `Context.GetLogger()`). This is analogous to Serilog's `ForContext()` but instead of returning a Serilog `ILogger` it returns an Akka.NET `ILoggingAdapter`. This instance acts as contextual logger that will attach a property to all events logged through it.
 
@@ -133,26 +154,14 @@ There are few properties that one can use in their `OutputTemplate` for logger c
 
 ## HOCON Configuration
 
-In order to be able to change log level without the need to recompile, we need to employ some sort of application configuration.  To use Serilog via HOCON configuration, add the following to the __App.config__ of the project.
-
-```xml
-<configSections>    
-    <section name="akka" type="Akka.Configuration.Hocon.AkkaConfigurationSection, Akka" />
-</configSections>
-
-...
-
-<akka>
-    <hocon>
-      <![CDATA[
-      akka { 
-        loglevel=INFO,
-        loggers=["Akka.Logger.Serilog.SerilogLogger, Akka.Logger.Serilog"]
-      }
-    ]]>
-    </hocon>
-  </akka>
+In order to be able to change log level without the need to recompile, we need to employ some sort of application configuration.  To use Serilog via HOCON configuration, add the following to the HOCON of the project.
 
+```hocon
+akka { 
+    loglevel=INFO,
+    loggers=["Akka.Logger.Serilog.SerilogLogger, Akka.Logger.Serilog"]
+    logger-formatter="Akka.Logger.Serilog.SerilogLogMessageFormatter, Akka.Logger.Serilog"
+}
 ```
 
 The code can then be updated as follows removing the inline HOCON from the actor system creation code.  Note in the following example, if a minimum level is not specified, Information level events and higher will be processed.  Please read the documentation for [Serilog](https://serilog.net/) configuration for more details on this.  It is also possible to move serilog configuration to the application configuration, for example if using a rolling log file sink, again, browsing the serilog documentation is the best place for details on that feature.  

src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.Core.verified.txt

@@ -1720,6 +1720,7 @@ namespace Akka.Actor
         public int LogDeadLetters { get; }
         public bool LogDeadLettersDuringShutdown { get; }
         public System.TimeSpan LogDeadLettersSuspendDuration { get; }
+        public Akka.Event.ILogMessageFormatter LogFormatter { get; }
         public string LogLevel { get; }
         public bool LogSerializerOverrideOnStart { get; }
         public bool LoggerAsyncStart { get; }
@@ -3000,7 +3001,7 @@ namespace Akka.Event
         public Akka.Actor.IActorRef Sender { get; }
         public override string ToString() { }
     }
-    public class BusLogging : Akka.Event.LoggingAdapterBase
+    public sealed class BusLogging : Akka.Event.LoggingAdapterBase
     {
         public BusLogging(Akka.Event.LoggingBus bus, string logSource, System.Type logClass, Akka.Event.ILogMessageFormatter logMessageFormatter) { }
         public override bool IsDebugEnabled { get; }

src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.DotNet.verified.txt

@@ -1722,6 +1722,7 @@ namespace Akka.Actor
         public int LogDeadLetters { get; }
         public bool LogDeadLettersDuringShutdown { get; }
         public System.TimeSpan LogDeadLettersSuspendDuration { get; }
+        public Akka.Event.ILogMessageFormatter LogFormatter { get; }
         public string LogLevel { get; }
         public bool LogSerializerOverrideOnStart { get; }
         public bool LoggerAsyncStart { get; }
@@ -3005,7 +3006,7 @@ namespace Akka.Event
         public Akka.Actor.IActorRef Sender { get; }
         public override string ToString() { }
     }
-    public class BusLogging : Akka.Event.LoggingAdapterBase
+    public sealed class BusLogging : Akka.Event.LoggingAdapterBase
     {
         public BusLogging(Akka.Event.LoggingBus bus, string logSource, System.Type logClass, Akka.Event.ILogMessageFormatter logMessageFormatter) { }
         public override bool IsDebugEnabled { get; }

src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.Net.verified.txt

@@ -1720,6 +1720,7 @@ namespace Akka.Actor
         public int LogDeadLetters { get; }
         public bool LogDeadLettersDuringShutdown { get; }
         public System.TimeSpan LogDeadLettersSuspendDuration { get; }
+        public Akka.Event.ILogMessageFormatter LogFormatter { get; }
         public string LogLevel { get; }
         public bool LogSerializerOverrideOnStart { get; }
         public bool LoggerAsyncStart { get; }
@@ -3000,7 +3001,7 @@ namespace Akka.Event
         public Akka.Actor.IActorRef Sender { get; }
         public override string ToString() { }
     }
-    public class BusLogging : Akka.Event.LoggingAdapterBase
+    public sealed class BusLogging : Akka.Event.LoggingAdapterBase
     {
         public BusLogging(Akka.Event.LoggingBus bus, string logSource, System.Type logClass, Akka.Event.ILogMessageFormatter logMessageFormatter) { }
         public override bool IsDebugEnabled { get; }

src/core/Akka.Streams/Implementation/Fusing/ActorGraphInterpreter.cs

@@ -420,9 +420,9 @@ private GraphInterpreter GetInterpreter()
                 }, _settings.IsFuzzingMode, Self);
         }
 
-        private BusLogging GetLogger()
+        private ILoggingAdapter GetLogger()
         {
-            return new BusLogging(Materializer.System.EventStream, Self.ToString(), typeof(GraphInterpreterShell), DefaultLogMessageFormatter.Instance);
+            return new BusLogging(Materializer.System.EventStream, Self.ToString(), typeof(GraphInterpreterShell), Materializer.System.Settings.LogFormatter);
         }
 
         /// <summary>

src/core/Akka.Streams/Implementation/Fusing/Ops.cs

@@ -2949,7 +2949,7 @@ public override void PreStart()
                     try
                     {
                         var materializer = ActorMaterializerHelper.Downcast(Materializer);
-                        _log = new BusLogging(materializer.System.EventStream, _stage._name, GetType(), DefaultLogMessageFormatter.Instance);
+                        _log = new BusLogging(materializer.System.EventStream, _stage._name, GetType(), materializer.System.Settings.LogFormatter);
                     }
                     catch (Exception ex)
                     {

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

@@ -50,6 +50,7 @@ public void The_default_configuration_file_contain_all_configuration_properties(
             settings.LogDeadLetters.ShouldBe(10);
             settings.LogDeadLettersDuringShutdown.ShouldBeFalse();
             settings.LogDeadLettersSuspendDuration.ShouldBe(TimeSpan.FromMinutes(5));
+            settings.LogFormatter.Should().BeOfType<DefaultLogMessageFormatter>();
 
             settings.ProviderClass.ShouldBe(typeof (LocalActorRefProvider).FullName);
             settings.SupervisorStrategyClass.ShouldBe(typeof (DefaultSupervisorStrategy).FullName);

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

@@ -0,0 +1,78 @@
+//-----------------------------------------------------------------------
+// <copyright file="CustomLogFormatterSpec.cs" company="Akka.NET Project">
+//     Copyright (C) 2009-2023 Lightbend Inc. <http://www.lightbend.com>
+//     Copyright (C) 2013-2023 .NET Foundation <https://github.com/akkadotnet/akka.net>
+// </copyright>
+//-----------------------------------------------------------------------
+
+using System.Collections.Generic;
+using System.Linq;
+using System.Threading.Tasks;
+using Akka.Configuration;
+using Akka.Event;
+using Akka.TestKit;
+using FluentAssertions;
+using Xunit;
+using Xunit.Abstractions;
+
+namespace Akka.Tests.Loggers
+{
+    public class CustomLogFormatterSpec : AkkaSpec
+    {
+        // <CustomLogFormatter>
+        private class CustomLogFormatter : ILogMessageFormatter
+        {
+            public string Format(string format, params object[] args)
+            {
+                return string.Format("Custom: " + format, args);
+            }
+
+            public string Format(string format, IEnumerable<object> args)
+            {
+                return string.Format("Custom: " + format, args.ToArray());
+            }
+        }
+        // </CustomLogFormatter>
+
+        // <CustomLogFormatterConfig>
+        public static readonly Config Configuration = "akka.logger-formatter = \"Akka.Tests.Loggers.CustomLogFormatterSpec+CustomLogFormatter, Akka.Tests\"";
+        // </CustomLogFormatterConfig>
+
+        public CustomLogFormatterSpec(ITestOutputHelper output) : base(Configuration, output)
+        {
+        }
+
+        [Fact]
+        public async Task ShouldUseValidCustomLogFormatter()
+        {
+            // arrange
+            var probe = CreateTestProbe();
+            Sys.EventStream.Subscribe(probe.Ref, typeof(Error));
+
+            // act
+            Sys.Log.Error("This is a test {0}", 1); // formatters aren't used when we're logging const strings
+
+            // assert
+            var msg = await probe.ExpectMsgAsync<Error>();
+            msg.Message.Should().BeAssignableTo<LogMessage>();
+            msg.ToString().Should().Contain("Custom: This is a test 1");
+
+            await EventFilter.Error(contains: "Custom").ExpectOneAsync(() =>
+            {
+                Sys.Log.Error("This is a test {0}", 1);
+                return Task.CompletedTask;
+            });
+        }
+
+        [Fact]
+        public async Task ShouldDetectCustomLogFormatterOutputInEventFilter()
+        {
+            // the EventFilter filters on fully formatted output
+            await EventFilter.Error(contains: "Custom").ExpectOneAsync(() =>
+            {
+                Sys.Log.Error("This is a test {0}", 1);
+                return Task.CompletedTask;
+            });
+        }
+    }
+}

src/core/Akka/Actor/Internal/ActorSystemImpl.cs

@@ -464,7 +464,7 @@ private void ConfigureProvider()
 
         private void ConfigureLoggers()
         {
-            _log = new BusLogging(_eventStream, "ActorSystem(" + _name + ")", GetType(), DefaultLogMessageFormatter.Instance);
+            _log = new BusLogging(_eventStream, "ActorSystem(" + _name + ")", GetType(), _settings.LogFormatter);
         }
 
         private void ConfigureDispatchers()