diff --git a/src/core/Akka.API.Tests/LogFormatSpec.cs b/src/core/Akka.API.Tests/LogFormatSpec.cs index 5775ffcbc1e..25f9c44a8d4 100644 --- a/src/core/Akka.API.Tests/LogFormatSpec.cs +++ b/src/core/Akka.API.Tests/LogFormatSpec.cs @@ -8,6 +8,7 @@ using System; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics; using System.IO; using System.Linq; using System.Text.RegularExpressions; @@ -32,9 +33,9 @@ public DefaultLogFormatSpec() : base(CustomLoggerSetup()) { _logger = (CustomLogger)Sys.Settings.StdoutLogger; } - + private readonly CustomLogger _logger; - + public class CustomLogger : StandardOutLogger { protected override void Log(object message) @@ -44,13 +45,13 @@ protected override void Log(object message) { _events.Add(e); } - + } - + private readonly ConcurrentBag _events = new(); public IReadOnlyCollection Events => _events; } - + public static ActorSystemSetup CustomLoggerSetup() { var hocon = @$" @@ -109,10 +110,51 @@ await AwaitConditionAsync(() => text = SanitizeThreadNumber(text); // to resolve https://github.com/akkadotnet/akka.net/issues/7421 text = SanitizeTestEventListener(text); - + await Verifier.Verify(text); } - + + /// + /// Validation spec for https://github.com/akkadotnet/akka.net/issues/6855 + /// + [Fact] + public async Task ShouldUseDefaultLogFormatWithTraceCorrelation() + { + // arrange + var filePath = Path.GetTempFileName(); + + // act + using (new OutputRedirector(filePath)) + { + using var activity = new Activity("test").Start(); + Activity.Current = activity; + + Sys.Log.Debug("This is a test {0} {1}", 1, "cheese"); + Sys.Log.Info("This is a test {0}", 1); + Sys.Log.Warning("This is a test {0}", 1); + Sys.Log.Error("This is a test {0}", 1); + + // force all logs to be received + await AwaitConditionAsync(() => + { + return _logger.Events.Count(c => c.Message.ToString()!.Contains("This is a test")) == 4; + }); + } + + // ReSharper disable once MethodHasAsyncOverload + var text = File.ReadAllText(filePath); + + // need to sanitize the thread id + text = SanitizeDateTime(text); + text = SanitizeThreadNumber(text); + // to resolve https://github.com/akkadotnet/akka.net/issues/7421 + text = SanitizeTestEventListener(text); + text = SanitizeTraceId(text); + + await Verifier.Verify(text); + + } + private static string SanitizeTestEventListener(string logs) { var pattern = @"^.*Akka\.TestKit\.TestEventListener.*$"; @@ -138,4 +180,17 @@ private static string SanitizeDateTime(string logs, string replacement = "DateTi return result; } -} + + // Matches TraceId=, SpanId= + private const string PATTERN = + @"TraceId=([0-9a-f]{32}), SpanId=([0-9a-f]{16})"; + + private const string REPLACEMENT = + "TraceId=00000000000000000000000000000000, SpanId=0000000000000000"; + + private static string SanitizeTraceId(string logs) + { + var result = Regex.Replace(logs, PATTERN, REPLACEMENT); + return result; + } +} \ No newline at end of file diff --git a/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.DotNet.verified.txt b/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.DotNet.verified.txt index 104827f2cf0..5e92da4de9e 100644 --- a/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.DotNet.verified.txt +++ b/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.DotNet.verified.txt @@ -3320,6 +3320,7 @@ namespace Akka.Event public Akka.Actor.IActorRef Sender { get; } public override string ToString() { } } + [System.Runtime.CompilerServices.NullableAttribute(0)] public sealed class BusLogging : Akka.Event.LoggingAdapterBase { public BusLogging(Akka.Event.LoggingBus bus, string logSource, System.Type logClass, Akka.Event.ILogMessageFormatter logMessageFormatter) { } @@ -3349,6 +3350,7 @@ namespace Akka.Event { public Debug(string logSource, System.Type logClass, object message) { } public Debug(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Debug(System.Exception cause, string logSource, System.Type logClass, object message, [System.Runtime.CompilerServices.IsReadOnlyAttribute()] ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } public class DefaultLogMessageFormatter : Akka.Event.ILogMessageFormatter @@ -3376,6 +3378,7 @@ namespace Akka.Event public class Error : Akka.Event.LogEvent { public Error(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Error(System.Exception cause, string logSource, System.Type logClass, object message, [System.Runtime.CompilerServices.IsReadOnlyAttribute()] ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } public abstract class EventBus @@ -3434,6 +3437,7 @@ namespace Akka.Event { public Info(string logSource, System.Type logClass, object message) { } public Info(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Info(System.Exception cause, string logSource, System.Type logClass, object message, [System.Runtime.CompilerServices.IsReadOnlyAttribute()] ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } public class InitializeLogger : Akka.Actor.INoSerializationVerificationNeeded @@ -3441,9 +3445,12 @@ namespace Akka.Event public InitializeLogger(Akka.Event.LoggingBus loggingBus) { } public Akka.Event.LoggingBus LoggingBus { get; } } + [System.Runtime.CompilerServices.NullableAttribute(0)] public abstract class LogEvent : Akka.Actor.INoSerializationVerificationNeeded { protected LogEvent() { } + public System.Diagnostics.ActivityContext ActivityContext { get; set; } + [System.Runtime.CompilerServices.NullableAttribute(2)] public System.Exception Cause { get; set; } public System.Type LogClass { get; set; } public string LogSource { get; set; } @@ -3723,6 +3730,7 @@ namespace Akka.Event { public Warning(string logSource, System.Type logClass, object message) { } public Warning(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Warning(System.Exception cause, string logSource, System.Type logClass, object message, [System.Runtime.CompilerServices.IsReadOnlyAttribute()] ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } } diff --git a/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.Net.verified.txt b/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.Net.verified.txt index 9b8a28e3d35..ebfdc33f3e5 100644 --- a/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.Net.verified.txt +++ b/src/core/Akka.API.Tests/verify/CoreAPISpec.ApproveCore.Net.verified.txt @@ -3312,6 +3312,7 @@ namespace Akka.Event public Akka.Actor.IActorRef Sender { get; } public override string ToString() { } } + [System.Runtime.CompilerServices.NullableAttribute(0)] public sealed class BusLogging : Akka.Event.LoggingAdapterBase { public BusLogging(Akka.Event.LoggingBus bus, string logSource, System.Type logClass, Akka.Event.ILogMessageFormatter logMessageFormatter) { } @@ -3341,6 +3342,7 @@ namespace Akka.Event { public Debug(string logSource, System.Type logClass, object message) { } public Debug(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Debug(System.Exception cause, string logSource, System.Type logClass, object message, ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } public class DefaultLogMessageFormatter : Akka.Event.ILogMessageFormatter @@ -3368,6 +3370,7 @@ namespace Akka.Event public class Error : Akka.Event.LogEvent { public Error(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Error(System.Exception cause, string logSource, System.Type logClass, object message, ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } public abstract class EventBus @@ -3426,6 +3429,7 @@ namespace Akka.Event { public Info(string logSource, System.Type logClass, object message) { } public Info(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Info(System.Exception cause, string logSource, System.Type logClass, object message, ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } public class InitializeLogger : Akka.Actor.INoSerializationVerificationNeeded @@ -3433,9 +3437,12 @@ namespace Akka.Event public InitializeLogger(Akka.Event.LoggingBus loggingBus) { } public Akka.Event.LoggingBus LoggingBus { get; } } + [System.Runtime.CompilerServices.NullableAttribute(0)] public abstract class LogEvent : Akka.Actor.INoSerializationVerificationNeeded { protected LogEvent() { } + public System.Diagnostics.ActivityContext ActivityContext { get; set; } + [System.Runtime.CompilerServices.NullableAttribute(2)] public System.Exception Cause { get; set; } public System.Type LogClass { get; set; } public string LogSource { get; set; } @@ -3713,6 +3720,7 @@ namespace Akka.Event { public Warning(string logSource, System.Type logClass, object message) { } public Warning(System.Exception cause, string logSource, System.Type logClass, object message) { } + public Warning(System.Exception cause, string logSource, System.Type logClass, object message, ref System.Diagnostics.ActivityContext context) { } public override Akka.Event.LogLevel LogLevel() { } } } diff --git a/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldUseDefaultLogFormatWithTraceCorrelation.DotNet.verified.txt b/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldUseDefaultLogFormatWithTraceCorrelation.DotNet.verified.txt new file mode 100644 index 00000000000..e5a62a5be93 --- /dev/null +++ b/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldUseDefaultLogFormatWithTraceCorrelation.DotNet.verified.txt @@ -0,0 +1,4 @@ +[DEBUG][DateTime][Thread 0001][ActorSystem(test)][TraceId=00000000000000000000000000000000, SpanId=0000000000000000, TraceFlags=None] This is a test 1 cheese +[INFO][DateTime][Thread 0001][ActorSystem(test)][TraceId=00000000000000000000000000000000, SpanId=0000000000000000, TraceFlags=None] This is a test 1 +[WARNING][DateTime][Thread 0001][ActorSystem(test)][TraceId=00000000000000000000000000000000, SpanId=0000000000000000, TraceFlags=None] This is a test 1 +[ERROR][DateTime][Thread 0001][ActorSystem(test)][TraceId=00000000000000000000000000000000, SpanId=0000000000000000, TraceFlags=None] This is a test 1 diff --git a/src/core/Akka/Akka.csproj b/src/core/Akka/Akka.csproj index c2317dd306a..14e6c2de149 100644 --- a/src/core/Akka/Akka.csproj +++ b/src/core/Akka/Akka.csproj @@ -24,6 +24,7 @@ + diff --git a/src/core/Akka/Event/BusLogging.cs b/src/core/Akka/Event/BusLogging.cs index 43767ceeb96..19251f533bf 100644 --- a/src/core/Akka/Event/BusLogging.cs +++ b/src/core/Akka/Event/BusLogging.cs @@ -4,7 +4,7 @@ // Copyright (C) 2013-2025 .NET Foundation // //----------------------------------------------------------------------- - +#nullable enable using System; using Akka.Actor; @@ -72,14 +72,16 @@ public BusLogging(LoggingBus bus, string logSource, Type logClass, ILogMessageFo /// public override bool IsWarningEnabled { get; } - private LogEvent CreateLogEvent(LogLevel logLevel, object message, Exception cause = null) + private LogEvent CreateLogEvent(LogLevel logLevel, object message, Exception? cause = null) { + var currentContext = (System.Diagnostics.Activity.Current?.Context ?? default); + return logLevel switch { - LogLevel.DebugLevel => new Debug(cause, LogSource, LogClass, message), - LogLevel.InfoLevel => new Info(cause, LogSource, LogClass, message), - LogLevel.WarningLevel => new Warning(cause, LogSource, LogClass, message), - LogLevel.ErrorLevel => new Error(cause, LogSource, LogClass, message), + LogLevel.DebugLevel => new Debug(cause, LogSource, LogClass, message, currentContext), + LogLevel.InfoLevel => new Info(cause, LogSource, LogClass, message, currentContext), + LogLevel.WarningLevel => new Warning(cause, LogSource, LogClass, message, currentContext), + LogLevel.ErrorLevel => new Error(cause, LogSource, LogClass, message, currentContext), _ => throw new ArgumentOutOfRangeException(nameof(logLevel), logLevel, null) }; } diff --git a/src/core/Akka/Event/Debug.cs b/src/core/Akka/Event/Debug.cs index 1fd625d1c25..5163cd5d9f3 100644 --- a/src/core/Akka/Event/Debug.cs +++ b/src/core/Akka/Event/Debug.cs @@ -6,6 +6,7 @@ //----------------------------------------------------------------------- using System; +using System.Diagnostics; namespace Akka.Event { @@ -32,12 +33,26 @@ public Debug(string logSource, Type logClass, object message) /// The source that generated the log event. /// The type of logger used to log the event. /// The message that is being logged. - public Debug(Exception cause, string logSource, Type logClass, object message) + public Debug(Exception cause, string logSource, Type logClass, object message) + : this(cause, logSource, logClass, message, default) + { + } + + /// + /// Initializes a new instance of the class. + /// + /// The exception that generated the log event. + /// The source that generated the log event. + /// The type of logger used to log the event. + /// The message that is being logged. + /// The current 's context, if one is present.> + public Debug(Exception cause, string logSource, Type logClass, object message, in ActivityContext context) { LogSource = logSource; LogClass = logClass; Message = message; Cause = cause; + ActivityContext = context; } /// diff --git a/src/core/Akka/Event/Error.cs b/src/core/Akka/Event/Error.cs index 384a722e226..61dcef6822c 100644 --- a/src/core/Akka/Event/Error.cs +++ b/src/core/Akka/Event/Error.cs @@ -6,6 +6,7 @@ //----------------------------------------------------------------------- using System; +using System.Diagnostics; namespace Akka.Event { @@ -22,11 +23,25 @@ public class Error : LogEvent /// The type of logger used to log the event. /// The message that is being logged. public Error(Exception cause, string logSource, Type logClass, object message) + : this(cause, logSource, logClass, message, default) + { + } + + /// + /// Initializes a new instance of the class. + /// + /// The exception that caused the log event. + /// The source that generated the log event. + /// The type of logger used to log the event. + /// The message that is being logged. + /// The current 's context, if one is present. + public Error(Exception cause, string logSource, Type logClass, object message, in ActivityContext context) { Cause = cause; LogSource = logSource; LogClass = logClass; Message = message; + ActivityContext = context; } /// diff --git a/src/core/Akka/Event/Info.cs b/src/core/Akka/Event/Info.cs index 51f8afdcf7f..88828a0e301 100644 --- a/src/core/Akka/Event/Info.cs +++ b/src/core/Akka/Event/Info.cs @@ -6,6 +6,7 @@ //----------------------------------------------------------------------- using System; +using System.Diagnostics; namespace Akka.Event { @@ -32,12 +33,27 @@ public Info(string logSource, Type logClass, object message) /// The source that generated the log event. /// The type of logger used to log the event. /// The message that is being logged. - public Info(Exception cause, string logSource, Type logClass, object message) + public Info(Exception cause, string logSource, Type logClass, object message) + : this(cause, logSource, logClass, message, default) + { + + } + + /// + /// Initializes a new instance of the class. + /// + /// The exception that generated the log event. + /// The source that generated the log event. + /// The type of logger used to log the event. + /// The message that is being logged. + /// The current 's context, if one is present. + public Info(Exception cause, string logSource, Type logClass, object message, in ActivityContext context) { Cause = cause; LogSource = logSource; LogClass = logClass; Message = message; + ActivityContext = context; } /// diff --git a/src/core/Akka/Event/LogEvent.cs b/src/core/Akka/Event/LogEvent.cs index a17e13c0308..2cd7d80737f 100644 --- a/src/core/Akka/Event/LogEvent.cs +++ b/src/core/Akka/Event/LogEvent.cs @@ -4,11 +4,14 @@ // Copyright (C) 2013-2025 .NET Foundation // //----------------------------------------------------------------------- - +#nullable enable using System; using System.Collections.Generic; +using System.Diagnostics; +using System.Text; using System.Threading; using Akka.Actor; +using Microsoft.Extensions.ObjectPool; namespace Akka.Event { @@ -35,6 +38,11 @@ public static string PrettyNameFor(this LogLevel level) { return PrettyPrintedLogLevel[level]; } + + /// + /// For formatting the instances. + /// + public static readonly ObjectPool StringBuilderPool = new DefaultObjectPoolProvider().CreateStringBuilderPool(10, 1024); } /// @@ -45,7 +53,9 @@ public abstract class LogEvent : INoSerializationVerificationNeeded /// /// Initializes a new instance of the class. /// +#pragma warning disable CS8618, CS9264 protected LogEvent() +#pragma warning restore CS8618, CS9264 { Timestamp = DateTime.UtcNow; Thread = Thread.CurrentThread; @@ -54,7 +64,7 @@ protected LogEvent() /// /// The exception that caused the log event. Can be null /// - public Exception Cause { get; protected set; } + public Exception? Cause { get; protected set; } /// /// The timestamp that this event occurred. @@ -86,6 +96,15 @@ protected LogEvent() /// /// The used to classify this event. public abstract LogLevel LogLevel(); + + /// + /// Used to help correlate Akka.NET logs with OpenTelemetry traces. + /// + /// + /// Works best in combination with manual instrumentation of Akka.NET actors or + /// for automatic instrumentation. + /// + public ActivityContext ActivityContext { get; protected set; } /// /// Returns a that represents this LogEvent. @@ -93,9 +112,37 @@ protected LogEvent() /// A that represents this LogEvent. public override string ToString() { - return Cause == null - ? $"[{LogLevel().PrettyNameFor()}][{Timestamp:MM/dd/yyyy HH:mm:ss.fffK}][Thread {Thread.ManagedThreadId:0000}][{LogSource}] {Message}" - : $"[{LogLevel().PrettyNameFor()}][{Timestamp:MM/dd/yyyy HH:mm:ss.fffK}][Thread {Thread.ManagedThreadId:0000}][{LogSource}] {Message}{Environment.NewLine}Cause: {Cause}"; + return FormatLog(this); + } + + private static string FormatLog(LogEvent log) + { + var stringBuilder = LogFormats.StringBuilderPool.Get(); + try + { + // loglevel and timestamp go first followed by thread id and log source + stringBuilder.AppendFormat("[{0}][{1:MM/dd/yyyy HH:mm:ss.fffK}][Thread {2:0000}][{3}]", log.LogLevel().PrettyNameFor(), + log.Timestamp, log.Thread.ManagedThreadId, log.LogSource); + + // next: we do the OpenTelemetry ActivityContext, if it's present + if(log.ActivityContext != default) + { + stringBuilder.AppendFormat("[TraceId={0}, SpanId={1}, TraceFlags={2}]", log.ActivityContext.TraceId.ToHexString(), log.ActivityContext.SpanId.ToHexString(), log.ActivityContext.TraceFlags); + } + + // then the message + stringBuilder.Append(' ').Append(log.Message); + if(log.Cause != null) + { + stringBuilder.AppendLine().Append("Cause: ").Append(log.Cause); + } + + return stringBuilder.ToString(); + } + finally + { + LogFormats.StringBuilderPool.Return(stringBuilder); + } } } } diff --git a/src/core/Akka/Event/Warning.cs b/src/core/Akka/Event/Warning.cs index fc5650e1fc3..776d13feb85 100644 --- a/src/core/Akka/Event/Warning.cs +++ b/src/core/Akka/Event/Warning.cs @@ -6,6 +6,7 @@ //----------------------------------------------------------------------- using System; +using System.Diagnostics; namespace Akka.Event { @@ -33,11 +34,25 @@ public Warning(string logSource, Type logClass, object message) /// The type of logger used to log the event. /// The message that is being logged. public Warning(Exception cause, string logSource, Type logClass, object message) + : this(cause, logSource, logClass, message, default) + { + } + + /// + /// Initializes a new instance of the class. + /// + /// The exception that caused the log event. + /// The source that generated the log event. + /// The type of logger used to log the event. + /// The message that is being logged. + /// The current 's context, if one is present. + public Warning(Exception cause, string logSource, Type logClass, object message, in ActivityContext context) { LogSource = logSource; LogClass = logClass; Message = message; Cause = cause; + ActivityContext = context; } ///