diff --git a/src/benchmark/Akka.Benchmarks/Logging/SemanticLoggingBenchmarks.cs b/src/benchmark/Akka.Benchmarks/Logging/SemanticLoggingBenchmarks.cs new file mode 100644 index 00000000000..614cd1b82be --- /dev/null +++ b/src/benchmark/Akka.Benchmarks/Logging/SemanticLoggingBenchmarks.cs @@ -0,0 +1,534 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2025 Lightbend Inc. +// Copyright (C) 2013-2025 .NET Foundation +// +//----------------------------------------------------------------------- + +using System; +using System.Collections.Generic; +using System.Linq; +using Akka.Benchmarks.Configurations; +using Akka.Event; +using BenchmarkDotNet.Attributes; +using static Akka.Benchmarks.Configurations.BenchmarkCategories; + +namespace Akka.Benchmarks.Logging +{ + /// + /// Benchmarks for semantic logging implementation in Akka.NET. + /// Tests template parsing, property extraction, and message formatting performance. + /// + /// Performance Targets: + /// - Template cache hit: <100ns + /// - Template parse (uncached): <5μs + /// - Full format operation: <2μs + /// - Property extraction: <1μs (with caching) + /// - GC pressure: <200 bytes per log call + /// + [Config(typeof(MicroBenchmarkConfig))] + [MemoryDiagnoser] + public class SemanticLoggingBenchmarks + { + // ============================================================================ + // CATEGORY 1: Template Parsing - Cache Performance + // ============================================================================ + + private const string SimpleTemplate = "User {UserId} logged in"; + private const string ComplexTemplate = "Request {RequestId} from {IpAddress} at {Timestamp:yyyy-MM-dd} returned {StatusCode} in {Duration:N2}ms"; + private const string PositionalTemplate = "Value {0} and {1} and {2}"; + + private string[] _varyingTemplates; + private const int TemplateVariations = 100; + + [GlobalSetup] + public void Setup() + { + // Pre-generate varying templates to test cache effectiveness + _varyingTemplates = new string[TemplateVariations]; + for (int i = 0; i < TemplateVariations; i++) + { + _varyingTemplates[i] = $"User {{UserId}} performed action {{Action{i}}}"; + } + + // Warm up the cache with first template + MessageTemplateParser.GetPropertyNames(SimpleTemplate); + } + + [Benchmark(Description = "Template parse - COLD (first time)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList TemplateParse_Cold() + { + // This simulates a cold cache by using a unique template each time + // Note: In reality this will pollute the cache, but shows worst-case + var template = $"Unique template {{Prop{Guid.NewGuid()}}}"; + return MessageTemplateParser.GetPropertyNames(template); + } + + [Benchmark(Description = "Template parse - WARM (cached)", Baseline = true)] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList TemplateParse_Warm() + { + // Should hit ThreadStatic cache - target <100ns + return MessageTemplateParser.GetPropertyNames(SimpleTemplate); + } + + [Benchmark(Description = "Template parse - Complex template (cached)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList TemplateParse_ComplexCached() + { + return MessageTemplateParser.GetPropertyNames(ComplexTemplate); + } + + [Benchmark(Description = "Template parse - Positional {0} (cached)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList TemplateParse_PositionalCached() + { + return MessageTemplateParser.GetPropertyNames(PositionalTemplate); + } + + [Benchmark(Description = "Template parse - Cache thrashing (100 templates)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList TemplateParse_CacheThrashing() + { + // Tests LRU eviction by cycling through many templates + var result = default(IReadOnlyList); + for (int i = 0; i < TemplateVariations; i++) + { + result = MessageTemplateParser.GetPropertyNames(_varyingTemplates[i]); + } + return result; + } + + // ============================================================================ + // CATEGORY 2: Property Extraction - LogMessage Performance + // ============================================================================ + + private LogMessage _simpleLogMessage1Param; + private LogMessage _simpleLogMessage3Params; + private LogMessage _complexLogMessage5Params; + private LogMessage _positionalLogMessage; + + [GlobalSetup(Target = nameof(PropertyExtraction_1Param) + "," + + nameof(PropertyExtraction_3Params) + "," + + nameof(PropertyExtraction_5Params) + "," + + nameof(PropertyExtraction_Positional) + "," + + nameof(PropertyExtraction_Cached) + "," + + nameof(GetProperties_1Param) + "," + + nameof(GetProperties_3Params) + "," + + nameof(GetProperties_5Params) + "," + + nameof(GetProperties_Cached))] + public void SetupPropertyExtraction() + { + _simpleLogMessage1Param = new LogMessage>( + DefaultLogMessageFormatter.Instance, + "User {UserId} logged in", + new LogValues(12345) + ); + + _simpleLogMessage3Params = new LogMessage>( + DefaultLogMessageFormatter.Instance, + "User {UserId} from {IpAddress} at {Timestamp}", + new LogValues(12345, "192.168.1.1", DateTime.UtcNow) + ); + + _complexLogMessage5Params = new LogMessage>( + DefaultLogMessageFormatter.Instance, + ComplexTemplate, + new LogValues( + Guid.NewGuid(), "192.168.1.1", DateTime.UtcNow, 200, 123.45 + ) + ); + + _positionalLogMessage = new LogMessage>( + DefaultLogMessageFormatter.Instance, + "Value {0} and {1} and {2}", + new LogValues(42, "test", 3.14) + ); + } + + [Benchmark(Description = "PropertyNames - 1 param (lazy init)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList PropertyExtraction_1Param() + { + // Tests lazy initialization cost + var msg = new LogMessage>( + DefaultLogMessageFormatter.Instance, + SimpleTemplate, + new LogValues(12345) + ); + return msg.PropertyNames; + } + + [Benchmark(Description = "PropertyNames - 3 params (lazy init)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList PropertyExtraction_3Params() + { + var msg = new LogMessage>( + DefaultLogMessageFormatter.Instance, + "User {UserId} from {IpAddress} at {Timestamp}", + new LogValues(12345, "192.168.1.1", DateTime.UtcNow) + ); + return msg.PropertyNames; + } + + [Benchmark(Description = "PropertyNames - 5 params (lazy init)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList PropertyExtraction_5Params() + { + var msg = new LogMessage>( + DefaultLogMessageFormatter.Instance, + ComplexTemplate, + new LogValues( + Guid.NewGuid(), "192.168.1.1", DateTime.UtcNow, 200, 123.45 + ) + ); + return msg.PropertyNames; + } + + [Benchmark(Description = "PropertyNames - Positional")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList PropertyExtraction_Positional() + { + var msg = new LogMessage>( + DefaultLogMessageFormatter.Instance, + PositionalTemplate, + new LogValues(42, "test", 3.14) + ); + return msg.PropertyNames; + } + + [Benchmark(Description = "PropertyNames - Cached (2nd access)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList PropertyExtraction_Cached() + { + // Should be cached after first access - target ~10ns + return _simpleLogMessage1Param.PropertyNames; + } + + // ============================================================================ + // CATEGORY 3: GetProperties() - Dictionary Construction + // ============================================================================ + + [Benchmark(Description = "GetProperties - 1 param")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary GetProperties_1Param() + { + return _simpleLogMessage1Param.GetProperties(); + } + + [Benchmark(Description = "GetProperties - 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary GetProperties_3Params() + { + return _simpleLogMessage3Params.GetProperties(); + } + + [Benchmark(Description = "GetProperties - 5 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary GetProperties_5Params() + { + return _complexLogMessage5Params.GetProperties(); + } + + [Benchmark(Description = "GetProperties - Cached (2nd access)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary GetProperties_Cached() + { + // Should be cached - target ~5ns + return _simpleLogMessage1Param.GetProperties(); + } + + // ============================================================================ + // CATEGORY 4: Message Formatting - SemanticLogMessageFormatter vs Default + // ============================================================================ + + private object[] _args1 = new object[] { 12345 }; + private object[] _args3 = new object[] { 12345, "192.168.1.1", DateTime.UtcNow }; + private object[] _args5 = new object[] { Guid.NewGuid(), "192.168.1.1", DateTime.UtcNow, 200, 123.45 }; + + [Benchmark(Description = "Format - Semantic 1 param")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_Semantic_1Param() + { + return SemanticLogMessageFormatter.Instance.Format(SimpleTemplate, _args1); + } + + [Benchmark(Description = "Format - Semantic 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_Semantic_3Params() + { + return SemanticLogMessageFormatter.Instance.Format( + "User {UserId} from {IpAddress} at {Timestamp}", + _args3 + ); + } + + [Benchmark(Description = "Format - Semantic 5 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_Semantic_5Params() + { + return SemanticLogMessageFormatter.Instance.Format(ComplexTemplate, _args5); + } + + [Benchmark(Description = "Format - Semantic with format spec {Value:N2}")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_Semantic_WithFormatSpec() + { + return SemanticLogMessageFormatter.Instance.Format( + "Duration was {Duration:N2}ms", + new object[] { 123.456789 } + ); + } + + [Benchmark(Description = "Format - Default (positional) 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_Default_3Params() + { + return DefaultLogMessageFormatter.Instance.Format( + "Value {0} and {1} and {2}", + _args3 + ); + } + + [Benchmark(Description = "Format - Semantic Positional 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_Semantic_Positional_3Params() + { + return SemanticLogMessageFormatter.Instance.Format(PositionalTemplate, _args3); + } + + // ============================================================================ + // CATEGORY 5: End-to-End Logging Pipeline + // ============================================================================ + + private sealed class BenchmarkLogAdapter : LoggingAdapterBase + { + public LogEvent LastLog { get; private set; } + private readonly string _logSource; + private readonly Type _logClass; + + public BenchmarkLogAdapter(ILogMessageFormatter formatter) : base(formatter) + { + _logSource = LogSource.Create(this).Source; + _logClass = typeof(BenchmarkLogAdapter); + } + + public override bool IsDebugEnabled => true; + public override bool IsInfoEnabled => true; + public override bool IsWarningEnabled => true; + public override bool IsErrorEnabled => true; + + protected override void NotifyLog(LogLevel logLevel, object message, Exception cause = null) + { + LastLog = new Info(cause, _logSource, _logClass, message); + } + } + + private BenchmarkLogAdapter _defaultLogger; + private BenchmarkLogAdapter _semanticLogger; + + [GlobalSetup(Target = nameof(EndToEnd_Default_NoParams) + "," + + nameof(EndToEnd_Default_1Param) + "," + + nameof(EndToEnd_Default_3Params) + "," + + nameof(EndToEnd_Semantic_NoParams) + "," + + nameof(EndToEnd_Semantic_1Param) + "," + + nameof(EndToEnd_Semantic_3Params) + "," + + nameof(EndToEnd_Semantic_WithProperties))] + public void SetupEndToEnd() + { + _defaultLogger = new BenchmarkLogAdapter(DefaultLogMessageFormatter.Instance); + _semanticLogger = new BenchmarkLogAdapter(SemanticLogMessageFormatter.Instance); + } + + [Benchmark(Description = "E2E - Default formatter, no params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public LogEvent EndToEnd_Default_NoParams() + { + _defaultLogger.Info("User logged in"); + return _defaultLogger.LastLog; + } + + [Benchmark(Description = "E2E - Default formatter, 1 param")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public LogEvent EndToEnd_Default_1Param() + { + _defaultLogger.Info("User {0} logged in", 12345); + return _defaultLogger.LastLog; + } + + [Benchmark(Description = "E2E - Default formatter, 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public LogEvent EndToEnd_Default_3Params() + { + _defaultLogger.Info("User {0} from {1} at {2}", 12345, "192.168.1.1", DateTime.UtcNow); + return _defaultLogger.LastLog; + } + + [Benchmark(Description = "E2E - Semantic formatter, no params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public LogEvent EndToEnd_Semantic_NoParams() + { + _semanticLogger.Info("User logged in"); + return _semanticLogger.LastLog; + } + + [Benchmark(Description = "E2E - Semantic formatter, 1 param")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public LogEvent EndToEnd_Semantic_1Param() + { + _semanticLogger.Info("User {UserId} logged in", 12345); + return _semanticLogger.LastLog; + } + + [Benchmark(Description = "E2E - Semantic formatter, 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public LogEvent EndToEnd_Semantic_3Params() + { + _semanticLogger.Info("User {UserId} from {IpAddress} at {Timestamp}", + 12345, "192.168.1.1", DateTime.UtcNow); + return _semanticLogger.LastLog; + } + + [Benchmark(Description = "E2E - Semantic with GetProperties()")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary EndToEnd_Semantic_WithProperties() + { + _semanticLogger.Info("User {UserId} from {IpAddress}", 12345, "192.168.1.1"); + var logEvent = _semanticLogger.LastLog; + if (logEvent.TryGetProperties(out var props)) + return props; + return null; + } + + // ============================================================================ + // CATEGORY 6: Allocation Benchmarks - Memory Pressure Analysis + // ============================================================================ + + [Benchmark(Description = "Allocations - Parse template (cold)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyList Allocations_ParseCold() + { + // Unique template to avoid cache + var template = $"Event {{Id}} at {{Time}} with {{Data}}"; + return MessageTemplateParser.GetPropertyNames(template); + } + + [Benchmark(Description = "Allocations - Format semantic 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Allocations_FormatSemantic() + { + return SemanticLogMessageFormatter.Instance.Format( + "User {UserId} from {IpAddress} at {Timestamp}", + new object[] { 12345, "192.168.1.1", DateTime.UtcNow } + ); + } + + [Benchmark(Description = "Allocations - GetProperties 3 params")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary Allocations_GetProperties() + { + var msg = new LogMessage>( + DefaultLogMessageFormatter.Instance, + "User {UserId} from {IpAddress} at {Timestamp}", + new LogValues(12345, "192.168.1.1", DateTime.UtcNow) + ); + return msg.GetProperties(); + } + + [Benchmark(Description = "Allocations - Full log + properties")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public IReadOnlyDictionary Allocations_FullPipeline() + { + _semanticLogger.Info("User {UserId} from {IpAddress} performed {Action}", + 12345, "192.168.1.1", "login"); + if (_semanticLogger.LastLog.TryGetProperties(out var props)) + return props; + return null; + } + + // ============================================================================ + // CATEGORY 7: Escaped Brace Handling + // ============================================================================ + + private const string EscapedBracesOnly = "Use {{ and }} for literals"; + private const string EscapedBracesWithPlaceholder = "{First}}} text {{more {Second}"; + private const string NestedEscapedBraces = "{{{UserId}}}"; + private const string TrailingEscapedBrace = "{UserId}}"; + + [Benchmark(Description = "Format - Escaped braces only (no placeholders)")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_EscapedBracesOnly() + { + // Tests UnescapeBraces path - no placeholders, just {{ and }} + return SemanticLogMessageFormatter.Instance.Format(EscapedBracesOnly, Array.Empty()); + } + + [Benchmark(Description = "Format - Escaped braces with placeholders")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_EscapedBracesWithPlaceholders() + { + // Tests FormatNamedTemplate with mixed escaped braces and placeholders + return SemanticLogMessageFormatter.Instance.Format( + EscapedBracesWithPlaceholder, + new object[] { 1, 2 } + ); + } + + [Benchmark(Description = "Format - Nested escaped braces {{{Value}}}")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_NestedEscapedBraces() + { + // Tests {{{ }}} pattern: escaped brace + placeholder + escaped brace + return SemanticLogMessageFormatter.Instance.Format(NestedEscapedBraces, new object[] { 123 }); + } + + [Benchmark(Description = "Format - Trailing escaped brace {Value}}")] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public string Format_TrailingEscapedBrace() + { + // Tests placeholder followed by literal } + return SemanticLogMessageFormatter.Instance.Format(TrailingEscapedBrace, new object[] { 123 }); + } + + // ============================================================================ + // CATEGORY 8: Stress Tests - Real-world Patterns + // ============================================================================ + + private const int BatchSize = 1000; + + [Benchmark(Description = "Stress - 1K logs (same template)", OperationsPerInvoke = BatchSize)] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public void Stress_1K_SameTemplate() + { + for (int i = 0; i < BatchSize; i++) + { + _semanticLogger.Info("User {UserId} logged in", i); + } + } + + [Benchmark(Description = "Stress - 1K logs (varying templates)", OperationsPerInvoke = BatchSize)] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public void Stress_1K_VaryingTemplates() + { + for (int i = 0; i < BatchSize; i++) + { + _semanticLogger.Info(_varyingTemplates[i % TemplateVariations], i); + } + } + + [Benchmark(Description = "Stress - 1K logs with property extraction", OperationsPerInvoke = BatchSize)] + [BenchmarkCategory(MicroBenchmark, AkkaEventBenchmark)] + public int Stress_1K_WithPropertyExtraction() + { + int propCount = 0; + for (int i = 0; i < BatchSize; i++) + { + _semanticLogger.Info("User {UserId} performed {Action}", i, $"Action{i}"); + if (_semanticLogger.LastLog.TryGetProperties(out var props)) + propCount += props.Count; + } + return propCount; + } + } +} diff --git a/src/core/Akka.API.Tests/LogFormatSpec.cs b/src/core/Akka.API.Tests/LogFormatSpec.cs index 5775ffcbc1e..bda336d43ef 100644 --- a/src/core/Akka.API.Tests/LogFormatSpec.cs +++ b/src/core/Akka.API.Tests/LogFormatSpec.cs @@ -32,9 +32,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 +44,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 +109,76 @@ await AwaitConditionAsync(() => text = SanitizeThreadNumber(text); // to resolve https://github.com/akkadotnet/akka.net/issues/7421 text = SanitizeTestEventListener(text); - + await Verifier.Verify(text); } - + + [Fact] + public async Task ShouldHandleSemanticLogEdgeCases() + { + // arrange + var filePath = Path.GetTempFileName(); + + // act + using (new OutputRedirector(filePath)) + { + // Named properties + Sys.Log.Debug("User {UserId} logged in from {IpAddress}", 12345, "192.168.1.1"); + Sys.Log.Info("Processing order {OrderId} for customer {CustomerId}", "ORD-001", "CUST-999"); + + // Positional properties (old style) + Sys.Log.Warning("Processing item {0} of {1}", 5, 10); + + // Mixed types - use F2 instead of C for culture-independent output + Sys.Log.Info("Order total is ${Amount:F2} with {ItemCount} items", 123.45m, 3); + + // Edge cases + Sys.Log.Debug("Empty template"); + Sys.Log.Info("Single property {Value}", 42); + Sys.Log.Warning("Null value: {NullValue}", null); + Sys.Log.Error("Exception occurred for user {UserId}", 999); + + // Special characters and escaping + Sys.Log.Debug("Path: {FilePath}, Size: {FileSize} bytes", @"C:\temp\file.txt", 1024); + + // Boolean and date types - use explicit date format for culture-independent output + Sys.Log.Info("User {Username} is active: {IsActive}, joined on {JoinDate:yyyy-MM-dd}", "john.doe", true, DateTime.Parse("2024-01-15")); + + // Long strings and alignment + Sys.Log.Debug("Request from {RemoteAddress} to endpoint {Endpoint} took {DurationMs}ms", "192.168.1.100:54321", "/api/v1/users", 250); + + // force all logs to be received - wait for the last log message + await AwaitConditionAsync(() => Task.FromResult(_logger.Events.Any(e => e.Message.ToString()!.Contains("took 250ms"))), TimeSpan.FromSeconds(5)); + } + + // assert + // ReSharper disable once MethodHasAsyncOverload + var text = File.ReadAllText(filePath); + + // need to sanitize the thread id and timestamps + text = SanitizeDateTime(text); + text = SanitizeThreadNumber(text); + text = SanitizeTestEventListener(text); + text = SanitizeDefaultLoggersStarted(text); + text = SanitizeCustomLoggerRemoved(text); + + await Verifier.Verify(text); + } + + private static string SanitizeDefaultLoggersStarted(string logs) + { + var pattern = @"^.*Default Loggers started.*$\r?\n?"; + var result = Regex.Replace(logs, pattern, string.Empty, RegexOptions.Multiline); + return result; + } + + private static string SanitizeCustomLoggerRemoved(string logs) + { + var pattern = @"^.*CustomLogger being removed.*$\r?\n?"; + var result = Regex.Replace(logs, pattern, string.Empty, RegexOptions.Multiline); + return result; + } + private static string SanitizeTestEventListener(string logs) { var pattern = @"^.*Akka\.TestKit\.TestEventListener.*$"; 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 84f53c066a1..0e36be385d2 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 @@ -3483,6 +3483,17 @@ namespace Akka.Event public abstract Akka.Event.LogLevel LogLevel(); public override string ToString() { } } + [System.Runtime.CompilerServices.NullableAttribute(0)] + public class static LogEventExtensions + { + public static System.Collections.Generic.IEnumerable GetParameters(this Akka.Event.LogEvent evt) { } + public static System.Collections.Generic.IReadOnlyList GetPropertyNames(this Akka.Event.LogEvent evt) { } + public static string GetTemplate(this Akka.Event.LogEvent evt) { } + public static bool TryGetProperties(this Akka.Event.LogEvent evt, [System.Runtime.CompilerServices.NullableAttribute(new byte[] { + 2, + 1, + 1})] out System.Collections.Generic.IReadOnlyDictionary properties) { } + } public abstract class LogFilterBase : Akka.Actor.INoSerializationVerificationNeeded, Akka.Event.IDeadLetterSuppression { protected LogFilterBase() { } @@ -3542,6 +3553,8 @@ namespace Akka.Event protected readonly Akka.Event.ILogMessageFormatter Formatter; public LogMessage(Akka.Event.ILogMessageFormatter formatter, string format) { } public string Format { get; } + public System.Collections.Generic.IReadOnlyList PropertyNames { get; } + public System.Collections.Generic.IReadOnlyDictionary GetProperties() { } [Akka.Annotations.InternalApiAttribute()] public abstract System.Collections.Generic.IEnumerable Parameters(); [Akka.Annotations.InternalApiAttribute()] @@ -3719,6 +3732,12 @@ namespace Akka.Event public override Akka.Event.LogFilterType FilterType { get; } public override Akka.Event.LogFilterDecision ShouldKeepMessage(Akka.Event.LogEvent content, [System.Runtime.CompilerServices.NullableAttribute(2)] string expandedMessage = null) { } } + public sealed class SemanticLogMessageFormatter : Akka.Event.ILogMessageFormatter + { + public static readonly Akka.Event.SemanticLogMessageFormatter Instance; + public string Format(string format, params object[] args) { } + public string Format(string format, System.Collections.Generic.IEnumerable args) { } + } public class StandardOutLogger : Akka.Event.MinimalLogger { public StandardOutLogger() { } 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 6a23954802c..69fcd307543 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 @@ -3474,6 +3474,17 @@ namespace Akka.Event public abstract Akka.Event.LogLevel LogLevel(); public override string ToString() { } } + [System.Runtime.CompilerServices.NullableAttribute(0)] + public class static LogEventExtensions + { + public static System.Collections.Generic.IEnumerable GetParameters(this Akka.Event.LogEvent evt) { } + public static System.Collections.Generic.IReadOnlyList GetPropertyNames(this Akka.Event.LogEvent evt) { } + public static string GetTemplate(this Akka.Event.LogEvent evt) { } + public static bool TryGetProperties(this Akka.Event.LogEvent evt, [System.Runtime.CompilerServices.NullableAttribute(new byte[] { + 2, + 1, + 1})] out System.Collections.Generic.IReadOnlyDictionary properties) { } + } public abstract class LogFilterBase : Akka.Actor.INoSerializationVerificationNeeded, Akka.Event.IDeadLetterSuppression { protected LogFilterBase() { } @@ -3533,6 +3544,8 @@ namespace Akka.Event protected readonly Akka.Event.ILogMessageFormatter Formatter; public LogMessage(Akka.Event.ILogMessageFormatter formatter, string format) { } public string Format { get; } + public System.Collections.Generic.IReadOnlyList PropertyNames { get; } + public System.Collections.Generic.IReadOnlyDictionary GetProperties() { } [Akka.Annotations.InternalApiAttribute()] public abstract System.Collections.Generic.IEnumerable Parameters(); [Akka.Annotations.InternalApiAttribute()] @@ -3708,6 +3721,12 @@ namespace Akka.Event public override Akka.Event.LogFilterType FilterType { get; } public override Akka.Event.LogFilterDecision ShouldKeepMessage(Akka.Event.LogEvent content, [System.Runtime.CompilerServices.NullableAttribute(2)] string expandedMessage = null) { } } + public sealed class SemanticLogMessageFormatter : Akka.Event.ILogMessageFormatter + { + public static readonly Akka.Event.SemanticLogMessageFormatter Instance; + public string Format(string format, params object[] args) { } + public string Format(string format, System.Collections.Generic.IEnumerable args) { } + } public class StandardOutLogger : Akka.Event.MinimalLogger { public StandardOutLogger() { } diff --git a/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldHandleSemanticLogEdgeCases.DotNet.verified.txt b/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldHandleSemanticLogEdgeCases.DotNet.verified.txt new file mode 100644 index 00000000000..e2c9fd90769 --- /dev/null +++ b/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldHandleSemanticLogEdgeCases.DotNet.verified.txt @@ -0,0 +1,11 @@ +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] User 12345 logged in from 192.168.1.1 +[INFO][DateTime][Thread 0001][ActorSystem(test)] Processing order ORD-001 for customer CUST-999 +[WARNING][DateTime][Thread 0001][ActorSystem(test)] Processing item 5 of 10 +[INFO][DateTime][Thread 0001][ActorSystem(test)] Order total is $123.45 with 3 items +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] Empty template +[INFO][DateTime][Thread 0001][ActorSystem(test)] Single property 42 +[WARNING][DateTime][Thread 0001][ActorSystem(test)] Null value: {NullValue} +[ERROR][DateTime][Thread 0001][ActorSystem(test)] Exception occurred for user 999 +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] Path: C:\temp\file.txt, Size: 1024 bytes +[INFO][DateTime][Thread 0001][ActorSystem(test)] User john.doe is active: True, joined on 2024-01-15 +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] Request from 192.168.1.100:54321 to endpoint /api/v1/users took 250ms diff --git a/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldHandleSemanticLogEdgeCases.Net.verified.txt b/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldHandleSemanticLogEdgeCases.Net.verified.txt new file mode 100644 index 00000000000..e2c9fd90769 --- /dev/null +++ b/src/core/Akka.API.Tests/verify/DefaultLogFormatSpec.ShouldHandleSemanticLogEdgeCases.Net.verified.txt @@ -0,0 +1,11 @@ +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] User 12345 logged in from 192.168.1.1 +[INFO][DateTime][Thread 0001][ActorSystem(test)] Processing order ORD-001 for customer CUST-999 +[WARNING][DateTime][Thread 0001][ActorSystem(test)] Processing item 5 of 10 +[INFO][DateTime][Thread 0001][ActorSystem(test)] Order total is $123.45 with 3 items +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] Empty template +[INFO][DateTime][Thread 0001][ActorSystem(test)] Single property 42 +[WARNING][DateTime][Thread 0001][ActorSystem(test)] Null value: {NullValue} +[ERROR][DateTime][Thread 0001][ActorSystem(test)] Exception occurred for user 999 +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] Path: C:\temp\file.txt, Size: 1024 bytes +[INFO][DateTime][Thread 0001][ActorSystem(test)] User john.doe is active: True, joined on 2024-01-15 +[DEBUG][DateTime][Thread 0001][ActorSystem(test)] Request from 192.168.1.100:54321 to endpoint /api/v1/users took 250ms diff --git a/src/core/Akka.TestKit/EventFilter/Internal/EventFilterBase.cs b/src/core/Akka.TestKit/EventFilter/Internal/EventFilterBase.cs index 80ff0790281..69c9d9c9fd3 100644 --- a/src/core/Akka.TestKit/EventFilter/Internal/EventFilterBase.cs +++ b/src/core/Akka.TestKit/EventFilter/Internal/EventFilterBase.cs @@ -18,9 +18,9 @@ namespace Akka.TestKit.Internal /// TBD public delegate void EventMatched(EventFilterBase eventFilter, LogEvent logEvent); - /// Internal! + /// Internal! /// Facilities for selectively filtering out expected events from logging so - /// that you can keep your test run’s console output clean and do not miss real + /// that you can keep your test run's console output clean and do not miss real /// error messages. /// Note! Part of internal API. Breaking changes may occur without notice. Use at own risk. /// @@ -86,8 +86,26 @@ protected virtual void OnEventMatched(LogEvent logEvent) /// TBD protected bool InternalDoMatch(string src, object msg) { - var msgstr = msg == null ? "null" : msg.ToString(); - return _sourceMatcher.IsMatch(src) && _messageMatcher.IsMatch(msgstr); + // Check source matcher first (fast path) + if (!_sourceMatcher.IsMatch(src)) + return false; + + // For semantic logging support, try matching against both the formatted message + // and the unformatted template pattern + if (msg is LogMessage logMessage) + { + // Try matching against the template pattern first (e.g., "User {UserId} logged in") + if (_messageMatcher.IsMatch(logMessage.Format)) + return true; + + // Fall back to matching the formatted message (e.g., "User 12345 logged in") + var formattedMsg = logMessage.ToString() ?? "null"; + return _messageMatcher.IsMatch(formattedMsg); + } + + // Non-semantic logging or legacy messages + var msgstr = msg == null ? "null" : msg.ToString() ?? "null"; + return _messageMatcher.IsMatch(msgstr); } /// diff --git a/src/core/Akka.Tests/Configuration/ConfigurationSpec.cs b/src/core/Akka.Tests/Configuration/ConfigurationSpec.cs index 6241c7dfb41..6c204fcfa30 100644 --- a/src/core/Akka.Tests/Configuration/ConfigurationSpec.cs +++ b/src/core/Akka.Tests/Configuration/ConfigurationSpec.cs @@ -50,7 +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(); + settings.LogFormatter.Should().BeOfType(); settings.ProviderClass.ShouldBe(typeof (LocalActorRefProvider).FullName); settings.SupervisorStrategyClass.ShouldBe(typeof (DefaultSupervisorStrategy).FullName); diff --git a/src/core/Akka.Tests/Loggers/LogFilterEvaluatorSpecs.cs b/src/core/Akka.Tests/Loggers/LogFilterEvaluatorSpecs.cs index 1ce5487109d..c75bdb88cdb 100644 --- a/src/core/Akka.Tests/Loggers/LogFilterEvaluatorSpecs.cs +++ b/src/core/Akka.Tests/Loggers/LogFilterEvaluatorSpecs.cs @@ -227,4 +227,199 @@ public void ShouldFilterByLogMessageContains(LogEvent e, bool expected) Assert.Equal(expected, keepMessage); } } + + /// + /// Tests that log filtering works correctly with semantic logging templates + /// + public class SemanticLoggingFilterCases + { + private static ILoggingAdapter CreateAdapter() + { + var system = ActorSystem.Create("test-system"); + return Logging.GetLogger(system, "TestLogger"); + } + + [Fact] + public void ShouldFilterSemanticLogByFormattedMessageContent() + { + // Arrange: filter should exclude messages containing "12345" + var ruleBuilder = new LogFilterBuilder().ExcludeMessageContaining("12345"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + var adapter = CreateAdapter(); + + // Act: log with semantic template - the formatted value contains "12345" + adapter.Info("User {UserId} logged in", 12345); + + // Get the LogEvent that was created + var logEvent = new Info( + null, + "TestLogger", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "User {UserId} logged in", + 12345)); + + // Assert: should be filtered out because formatted message contains "12345" + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.False(keepMessage); + } + + [Fact] + public void ShouldKeepSemanticLogWhenFormattedMessageDoesNotMatchFilter() + { + // Arrange: filter excludes messages containing "admin" + var ruleBuilder = new LogFilterBuilder().ExcludeMessageContaining("admin"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: log message where neither template nor formatted value contains "admin" + var logEvent = new Info( + null, + "TestLogger", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "User {UserId} logged in from {IpAddress}", + 123, "192.168.1.1")); + + // Assert: should NOT be filtered (kept) + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.True(keepMessage); + } + + [Fact] + public void ShouldFilterSemanticLogByPropertyValue() + { + // Arrange: filter excludes messages containing "CRITICAL" + var ruleBuilder = new LogFilterBuilder().ExcludeMessageContaining("CRITICAL"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: the property value contains "CRITICAL" + var logEvent = new Warning( + null, + "TestLogger", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "Alert level {AlertLevel} triggered", + "CRITICAL")); + + // Assert: should be filtered because formatted message is "Alert level CRITICAL triggered" + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.False(keepMessage); + } + + [Fact] + public void ShouldFilterSemanticLogWithMultipleProperties() + { + // Arrange: filter excludes messages containing "ERROR" + var ruleBuilder = new LogFilterBuilder().ExcludeMessageContaining("ERROR"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: multiple properties, one contains "ERROR" + var logEvent = new Error( + null, + "TestLogger", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "Status: {Status}, Code: {ErrorCode}, User: {UserId}", + "ERROR", 500, 789)); + + // Assert: should be filtered + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.False(keepMessage); + } + + [Fact] + public void ShouldHandlePositionalTemplatesWithFiltering() + { + // Arrange: filter excludes "timeout" + var ruleBuilder = new LogFilterBuilder().ExcludeMessageContaining("timeout"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: positional template (backward compatibility) + var logEvent = new Warning( + null, + "TestLogger", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "Operation {0} failed with {1}", + "database query", "timeout")); + + // Assert: should be filtered because formatted contains "timeout" + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.False(keepMessage); + } + + [Fact] + public void ShouldFilterBySourceWithSemanticLogging() + { + // Arrange: filter excludes source starting with "Akka.Tests" + var ruleBuilder = new LogFilterBuilder().ExcludeSourceStartingWith("Akka.Tests"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: semantic log from filtered source + var logEvent = new Info( + null, + "Akka.Tests.MyTest", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "Test user {UserId} created", + 999)); + + // Assert: should be filtered by source (message content irrelevant) + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.False(keepMessage); + } + + [Fact] + public void ShouldKeepSemanticLogWhenSourceAndMessagePass() + { + // Arrange: filter excludes "ERROR" in message and "Akka.Tests" in source + var ruleBuilder = new LogFilterBuilder() + .ExcludeMessageContaining("ERROR") + .ExcludeSourceContaining("Akka.Tests"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: semantic log that doesn't match either filter + var logEvent = new Info( + null, + "Akka.Cluster.Gossip", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "Node {NodeAddress} joined cluster", + "akka.tcp://system@localhost:8080")); + + // Assert: should NOT be filtered (kept) + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.True(keepMessage); + } + + [Fact] + public void ShouldFilterComplexSemanticLogWithFormatSpecifiers() + { + // Arrange: filter excludes messages containing "1,234.56" (formatted number) + var ruleBuilder = new LogFilterBuilder().ExcludeMessageContaining("1,234.56"); + var evaluator = ruleBuilder.Build().CreateEvaluator(); + + // Act: semantic template with format specifier + var logEvent = new Info( + null, + "TestLogger", + typeof(SemanticLoggingFilterCases), + new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "Amount {Amount:N2} processed", + 1234.56m)); + + // Assert: should be filtered because formatted output contains "1,234.56" + var keepMessage = evaluator.ShouldTryKeepMessage(logEvent, out _); + Assert.False(keepMessage); + } + } } diff --git a/src/core/Akka.Tests/Loggers/SemanticLoggingSpecs.cs b/src/core/Akka.Tests/Loggers/SemanticLoggingSpecs.cs new file mode 100644 index 00000000000..a7f2b4e19a8 --- /dev/null +++ b/src/core/Akka.Tests/Loggers/SemanticLoggingSpecs.cs @@ -0,0 +1,495 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2025 Lightbend Inc. +// Copyright (C) 2013-2025 .NET Foundation +// +//----------------------------------------------------------------------- + +using System; +using System.Collections.Generic; +using System.Linq; +using Akka.Configuration; +using Akka.Event; +using Akka.TestKit; +using FluentAssertions; +using Xunit; + +namespace Akka.Tests.Loggers +{ + public class SemanticLoggingSpecs : AkkaSpec + { + public SemanticLoggingSpecs() : base(ConfigurationFactory.ParseString(@" + akka { + loglevel = INFO + stdout-loglevel = INFO + } + ")) + { + } + [Fact(DisplayName = "MessageTemplateParser should parse positional templates correctly")] + public void MessageTemplateParser_should_parse_positional_templates() + { + var template = "Value is {0} and status {1}"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + propertyNames.Should().NotBeNull(); + propertyNames.Should().HaveCount(2); + propertyNames[0].Should().Be("0"); + propertyNames[1].Should().Be("1"); + } + + [Fact(DisplayName = "MessageTemplateParser should parse named templates correctly")] + public void MessageTemplateParser_should_parse_named_templates() + { + var template = "User {UserId} logged in from {IpAddress}"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + propertyNames.Should().NotBeNull(); + propertyNames.Should().HaveCount(2); + propertyNames[0].Should().Be("UserId"); + propertyNames[1].Should().Be("IpAddress"); + } + + [Fact(DisplayName = "MessageTemplateParser should handle escaped braces")] + public void MessageTemplateParser_should_handle_escaped_braces() + { + var template = "Use {{braces}} for {Value}"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + propertyNames.Should().NotBeNull(); + propertyNames.Should().HaveCount(1); + propertyNames[0].Should().Be("Value"); + } + + [Fact(DisplayName = "MessageTemplateParser should handle format specifiers")] + public void MessageTemplateParser_should_handle_format_specifiers() + { + var template = "Value is {Amount:N2} dollars"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + propertyNames.Should().NotBeNull(); + propertyNames.Should().HaveCount(1); + propertyNames[0].Should().Be("Amount"); + } + + [Fact(DisplayName = "MessageTemplateParser should handle alignment specifiers")] + public void MessageTemplateParser_should_handle_alignment_specifiers() + { + var template = "Name: {Name,10} Age: {Age,-5}"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + propertyNames.Should().NotBeNull(); + propertyNames.Should().HaveCount(2); + propertyNames[0].Should().Be("Name"); + propertyNames[1].Should().Be("Age"); + } + + [Fact(DisplayName = "MessageTemplateParser should return empty list for no placeholders")] + public void MessageTemplateParser_should_return_empty_for_no_placeholders() + { + var template = "This is a plain message"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + propertyNames.Should().NotBeNull(); + propertyNames.Should().BeEmpty(); + } + + [Fact(DisplayName = "MessageTemplateParser should handle malformed templates gracefully")] + public void MessageTemplateParser_should_handle_malformed_templates() + { + var template = "Value is {0 and {1} without closing"; + var propertyNames = MessageTemplateParser.GetPropertyNames(template); + + // Should not throw, parses "0 and {1" from the first {..} pair + propertyNames.Should().NotBeNull(); + propertyNames.Should().HaveCount(1); + propertyNames[0].Should().Be("0 and {1"); + } + + [Fact(DisplayName = "MessageTemplateParser should cache parsed templates")] + public void MessageTemplateParser_should_cache_parsed_templates() + { + var template = "User {UserId} logged in"; + + // First call - cache miss + var result1 = MessageTemplateParser.GetPropertyNames(template); + + // Second call - should hit cache (same reference) + var result2 = MessageTemplateParser.GetPropertyNames(template); + + result1.Should().BeSameAs(result2, "cached results should return the same instance"); + } + + [Fact(DisplayName = "LogMessage should extract property names correctly")] + public void LogMessage_should_extract_property_names() + { + var formatter = DefaultLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId} logged in", 123); + + var propertyNames = logMessage.PropertyNames; + + propertyNames.Should().HaveCount(1); + propertyNames[0].Should().Be("UserId"); + } + + [Fact(DisplayName = "LogMessage should create property dictionary correctly")] + public void LogMessage_should_create_property_dictionary() + { + var formatter = DefaultLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId} from {IpAddress}", 123, "192.168.1.1"); + + var properties = logMessage.GetProperties(); + + properties.Should().HaveCount(2); + properties["UserId"].Should().Be(123); + properties["IpAddress"].Should().Be("192.168.1.1"); + } + + [Fact(DisplayName = "LogMessage should handle mismatched property counts")] + public void LogMessage_should_handle_mismatched_property_counts() + { + var formatter = DefaultLogMessageFormatter.Instance; + + // More values than properties + var logMessage1 = new DefaultLogMessage(formatter, "User {UserId}", 123, "extra"); + var properties1 = logMessage1.GetProperties(); + properties1.Should().HaveCount(1); + properties1["UserId"].Should().Be(123); + + // More properties than values + var logMessage2 = new DefaultLogMessage(formatter, "User {UserId} from {IpAddress}"); + var properties2 = logMessage2.GetProperties(); + properties2.Should().BeEmpty(); + } + + [Fact(DisplayName = "LogMessage property dictionary should be cached")] + public void LogMessage_property_dictionary_should_be_cached() + { + var formatter = DefaultLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId}", 123); + + var properties1 = logMessage.GetProperties(); + var properties2 = logMessage.GetProperties(); + + properties1.Should().BeSameAs(properties2, "cached properties should return the same instance"); + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should format positional templates")] + public void SemanticLogMessageFormatter_should_format_positional_templates() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("Value is {0} and status {1}", 42, "OK"); + + result.Should().Be("Value is 42 and status OK"); + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should format named templates")] + public void SemanticLogMessageFormatter_should_format_named_templates() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("User {UserId} logged in from {IpAddress}", 123, "192.168.1.1"); + + result.Should().Be("User 123 logged in from 192.168.1.1"); + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should handle format specifiers")] + public void SemanticLogMessageFormatter_should_handle_format_specifiers() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("Amount: {Amount:N2}", 1234.5); + + // Handle culture differences - just check it contains the number with decimals + result.Should().MatchRegex(@"Amount: \d[,\d]*\.50"); + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should handle missing arguments")] + public void SemanticLogMessageFormatter_should_handle_missing_arguments() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("User {UserId} from {IpAddress}", 123); + + result.Should().Contain("123"); + result.Should().Contain("{IpAddress}"); // Missing arg stays as placeholder + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should handle null values")] + public void SemanticLogMessageFormatter_should_handle_null_values() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("Value is {Value}", (object)null); + + result.Should().Be("Value is null"); + } + + [Fact(DisplayName = "LogEventExtensions.TryGetProperties should work with LogMessage")] + public void LogEventExtensions_TryGetProperties_should_work_with_LogMessage() + { + var formatter = SemanticLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId}", 123); + var logEvent = new Info(null, "TestSource", typeof(SemanticLoggingSpecs), logMessage); + + var result = logEvent.TryGetProperties(out var properties); + + result.Should().BeTrue(); + properties.Should().NotBeNull(); + properties["UserId"].Should().Be(123); + } + + [Fact(DisplayName = "LogEventExtensions.TryGetProperties should return false for string messages")] + public void LogEventExtensions_TryGetProperties_should_return_false_for_strings() + { + var logEvent = new Info(null, "TestSource", typeof(SemanticLoggingSpecs), "Plain string message"); + + var result = logEvent.TryGetProperties(out var properties); + + result.Should().BeFalse(); + properties.Should().BeNull(); + } + + [Fact(DisplayName = "LogEventExtensions.GetPropertyNames should work with LogMessage")] + public void LogEventExtensions_GetPropertyNames_should_work() + { + var formatter = SemanticLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId} from {IpAddress}", 123, "192.168.1.1"); + var logEvent = new Info(null, "TestSource", typeof(SemanticLoggingSpecs), logMessage); + + var propertyNames = logEvent.GetPropertyNames(); + + propertyNames.Should().HaveCount(2); + propertyNames.Should().Contain("UserId"); + propertyNames.Should().Contain("IpAddress"); + } + + [Fact(DisplayName = "LogEventExtensions.GetTemplate should extract format string")] + public void LogEventExtensions_GetTemplate_should_work() + { + var formatter = SemanticLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId}", 123); + var logEvent = new Info(null, "TestSource", typeof(SemanticLoggingSpecs), logMessage); + + var template = logEvent.GetTemplate(); + + template.Should().Be("User {UserId}"); + } + + [Fact(DisplayName = "LogEventExtensions.GetParameters should extract values")] + public void LogEventExtensions_GetParameters_should_work() + { + var formatter = SemanticLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId} from {IpAddress}", 123, "192.168.1.1"); + var logEvent = new Info(null, "TestSource", typeof(SemanticLoggingSpecs), logMessage); + + var parameters = logEvent.GetParameters().ToArray(); + + parameters.Should().HaveCount(2); + parameters[0].Should().Be(123); + parameters[1].Should().Be("192.168.1.1"); + } + + [Fact(DisplayName = "LruCache should evict oldest entries when full")] + public void LruCache_should_evict_oldest_entries() + { + var cache = new LruCache(3); + + cache.Add(1, "one"); + cache.Add(2, "two"); + cache.Add(3, "three"); + cache.Add(4, "four"); // Should evict 1 + + cache.TryGet(1, out _).Should().BeFalse("1 should have been evicted"); + cache.TryGet(2, out var val2).Should().BeTrue(); + val2.Should().Be("two"); + } + + [Fact(DisplayName = "LruCache should promote accessed entries")] + public void LruCache_should_promote_accessed_entries() + { + var cache = new LruCache(3); + + cache.Add(1, "one"); + cache.Add(2, "two"); + cache.Add(3, "three"); + + // Access 1, promoting it to front + cache.TryGet(1, out _).Should().BeTrue(); + + // Add 4, should evict 2 (oldest) + cache.Add(4, "four"); + + cache.TryGet(1, out _).Should().BeTrue("1 was promoted"); + cache.TryGet(2, out _).Should().BeFalse("2 should have been evicted"); + cache.TryGet(3, out _).Should().BeTrue(); + cache.TryGet(4, out _).Should().BeTrue(); + } + + [Fact(DisplayName = "End-to-end semantic logging should work")] + public void End_to_end_semantic_logging_should_work() + { + var formatter = SemanticLogMessageFormatter.Instance; + var logMessage = new DefaultLogMessage(formatter, "User {UserId} performed action {Action}", 123, "Login"); + var logEvent = new Info(null, "TestSource", typeof(SemanticLoggingSpecs), logMessage); + + // Property extraction + logEvent.TryGetProperties(out var properties).Should().BeTrue(); + properties["UserId"].Should().Be(123); + properties["Action"].Should().Be("Login"); + + // Template extraction + logEvent.GetTemplate().Should().Be("User {UserId} performed action {Action}"); + + // Message formatting + logMessage.ToString().Should().Be("User 123 performed action Login"); + } + + [Fact(DisplayName = "EventFilter should match semantic logging templates with named properties")] + public void EventFilter_should_match_semantic_templates() + { + // This test demonstrates the issue from GitHub #7932 + // EventFilter should match against the template pattern, not just the formatted output + + EventFilter.Info("OnCreateBet BetId:{BetId} created").ExpectOne(() => + { + Log.Info("OnCreateBet BetId:{BetId} created", 12345); + }); + } + + [Fact(DisplayName = "EventFilter should match semantic logging templates with contains")] + public void EventFilter_should_match_semantic_templates_with_contains() + { + EventFilter.Info(contains: "BetId:{BetId}").ExpectOne(() => + { + Log.Info("OnCreateBet BetId:{BetId} created", 12345); + }); + } + + [Fact(DisplayName = "EventFilter should match semantic logging templates with partial pattern")] + public void EventFilter_should_match_semantic_partial_pattern() + { + EventFilter.Info(start: "User {UserId}").ExpectOne(() => + { + Log.Info("User {UserId} logged in from {IpAddress}", 123, "192.168.1.1"); + }); + } + + [Fact(DisplayName = "EventFilter should still match formatted output when template doesn't match")] + public void EventFilter_should_fallback_to_formatted_output() + { + // Should also be able to match against the actual formatted values + EventFilter.Info(contains: "12345").ExpectOne(() => + { + Log.Info("OnCreateBet BetId:{BetId} created", 12345); + }); + } + + // BUG: Placeholder followed by }} fails + [Fact(DisplayName = "SemanticLogMessageFormatter should format '{UserId}}' with [123] to '123}'")] + public void Placeholder_followed_by_escaped_closing_brace_fails() + { + // CRITICAL: Parser treats }}} as "escaped brace", ignoring placeholder content + var propertyNames = MessageTemplateParser.GetPropertyNames("{UserId}}"); + propertyNames.Should().HaveCount(1, "parser must extract UserId"); + propertyNames[0].Should().Be("UserId"); + + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("{UserId}}", 123); + result.Should().Be("123}", "} closes placeholder, }} becomes }"); + } + + // BUG: Literal escaped braces not unescaped + [Fact(DisplayName = "SemanticLogMessageFormatter should format 'Use {{ and }}' to 'Use { and }'")] + public void Literal_escaped_braces_not_unescaped() + { + // CRITICAL: Templates without placeholders return raw string, no unescape + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("Use {{ and }} braces"); + result.Should().Be("Use { and } braces", "{{ → {, }} → }"); + } + + // BUG: Escaped braces around placeholders not unescaped + [Fact(DisplayName = "SemanticLogMessageFormatter should format '{First}}} text {{more {Second}' with [1, 2] to '1} text {more 2'")] + public void Escaped_braces_around_placeholders_not_unescaped() + { + // CRITICAL: Literal text between/after placeholders not processed for escaped braces + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("{First}}} text {{more {Second}", 1, 2); + result.Should().Be("1} text {more 2", "should unescape }} and {{ in literal text"); + } + + // BUG: Complex template {{{UserId}}} fails + [Fact(DisplayName = "SemanticLogMessageFormatter should format '{{{UserId}}}' with [123] to '{123}'")] + public void Complex_mixed_escaped_braces_and_placeholder_fails() + { + // CRITICAL: Combination of escaped braces + placeholder fails completely + var propertyNames = MessageTemplateParser.GetPropertyNames("{{{UserId}}}"); + propertyNames.Should().HaveCount(1, "must extract UserId"); + + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("{{{UserId}}}", 123); + result.Should().Be("{123}", "{{ → {, {UserId} → 123, }} → }"); + } + + // INVALID TEMPLATE: Empty property name with format specifier is not valid per Message Templates spec + // See: https://messagetemplates.org/ + // Property names must be valid identifiers - a format specifier alone ({:N2}) is malformed + [Fact(DisplayName = "Empty property name with format specifier {:N2} is invalid per spec")] + public void Empty_property_name_with_format_specifier_is_invalid() + { + // Per Message Templates spec, property names must be valid identifiers. + // {:N2} has no property name, only a format specifier - this is invalid. + // Current behavior: parser returns ":N2" as the property name (treating it as malformed but not crashing) + // This is acceptable "garbage in, garbage out" behavior for invalid templates. + var propertyNames = MessageTemplateParser.GetPropertyNames("{:N2}"); + + // We document but don't "fix" this - invalid templates have undefined behavior + propertyNames.Should().HaveCount(1, "parser extracts content even from invalid templates"); + // The colon is included because colonIndex > 0 check doesn't handle colon at position 0 + // This is intentional - we don't want to add complexity to handle invalid templates + } + + // BUG: Alignment specifiers ignored + [Fact(DisplayName = "SemanticLogMessageFormatter should format {Value,10:N2} with width and format")] + public void Alignment_specifiers_completely_ignored_in_named_templates() + { + // Per Message Templates spec, alignment IS supported: {PropertyName,Alignment:Format} + // Current code strips alignment but never applies it + var formatter = SemanticLogMessageFormatter.Instance; + + // Test 1: Simple alignment + var result1 = formatter.Format(">{Value,10}<", 123); + result1.Should().Be("> 123<", "positive alignment = right-align to 10 chars"); + + // Test 2: Negative alignment (left-align) + var result2 = formatter.Format(">{Value,-10}<", 123); + result2.Should().Be(">123 <", "negative alignment = left-align to 10 chars"); + + // Test 3: Combined alignment + format specifier + var result3 = formatter.Format("{Value,10:N2}", 123.456); + result3.Should().HaveLength(10, "alignment width must be applied"); + result3.Should().MatchRegex(@"^\s+\d{3}[.,]\d{2}$", "should be right-aligned with 2 decimals"); + } + + // BUG: ToString() returning null causes silent data loss + [Fact(DisplayName = "SemanticLogMessageFormatter should format ToString() returning null correctly")] + public void ToString_returning_null_should_be_handled() + { + // If type's ToString() returns null (violates .NET guidelines but possible), + // value silently disappears instead of showing "null" + var formatter = SemanticLogMessageFormatter.Instance; + var badObject = new TypeWithNullToString(); + + // Without format specifier - exercises line 258 + var result1 = formatter.Format("{Value}", badObject); + result1.Should().Be("null", "ToString() null should be treated as explicit null"); + + // With format specifier - exercises catch block line 253 + var result2 = formatter.Format("{Value:N2}", badObject); + result2.Should().Be("null", "ToString() null in catch block should be handled"); + } + + // Helper class for testing ToString() returning null + private class TypeWithNullToString + { + public override string ToString() => null; + } + } +} diff --git a/src/core/Akka/Actor/Settings.cs b/src/core/Akka/Actor/Settings.cs index 120663f5dae..3b180ba62be 100644 --- a/src/core/Akka/Actor/Settings.cs +++ b/src/core/Akka/Actor/Settings.cs @@ -182,6 +182,11 @@ public Settings(ActorSystem system, Config config, ActorSystemSetup setup) { LogFormatter = DefaultLogMessageFormatter.Instance; } + // SPECIAL CASE - check for the semantic log message formatter, which does not have an empty constructor (it's private) + else if (logFormatType == typeof(SemanticLogMessageFormatter)) + { + LogFormatter = SemanticLogMessageFormatter.Instance; + } else { try diff --git a/src/core/Akka/Configuration/akka.conf b/src/core/Akka/Configuration/akka.conf index df5704d8f94..86bb15706a9 100644 --- a/src/core/Akka/Configuration/akka.conf +++ b/src/core/Akka/Configuration/akka.conf @@ -32,7 +32,7 @@ akka { # Specifies the formatter used to format log messages. Can be customized # to use a different logging implementation, such as Serilog. - logger-formatter = "Akka.Event.DefaultLogMessageFormatter, Akka" + logger-formatter = "Akka.Event.SemanticLogMessageFormatter, Akka" # Log level used by the configured loggers (see "loggers") as soon # as they have been started; before that, see "stdout-loglevel" diff --git a/src/core/Akka/Event/LogEventExtensions.cs b/src/core/Akka/Event/LogEventExtensions.cs new file mode 100644 index 00000000000..9d8d5685070 --- /dev/null +++ b/src/core/Akka/Event/LogEventExtensions.cs @@ -0,0 +1,111 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2025 Lightbend Inc. +// Copyright (C) 2013-2025 .NET Foundation +// +//----------------------------------------------------------------------- + +#nullable enable + +using System; +using System.Collections.Generic; +using System.Linq; + +namespace Akka.Event +{ + /// + /// Extension methods for accessing semantic logging properties from instances. + /// These methods make it easy for custom logger implementations to extract structured properties. + /// + public static class LogEventExtensions + { + /// + /// Attempts to extract structured properties from the log event message. + /// + /// The log event + /// The extracted properties dictionary (if successful) + /// True if properties were extracted, false if message is a pre-formatted string + /// + /// + /// if (logEvent.TryGetProperties(out var properties)) + /// { + /// // Use structured properties with your native logger + /// foreach (var prop in properties) + /// { + /// Console.WriteLine($"{prop.Key} = {prop.Value}"); + /// } + /// } + /// + /// + public static bool TryGetProperties( + this LogEvent evt, + out IReadOnlyDictionary? properties) + { + if (evt.Message is LogMessage msg) + { + properties = msg.GetProperties(); + return true; + } + + properties = null; + return false; + } + + /// + /// Gets the property names from the log event's message template. + /// Returns empty list if message is a pre-formatted string. + /// + /// The log event + /// List of property names, or empty list + /// + /// + /// var names = logEvent.GetPropertyNames(); + /// // For "User {UserId} logged in", returns ["UserId"] + /// + /// + public static IReadOnlyList GetPropertyNames(this LogEvent evt) + { + return evt.Message is LogMessage msg + ? msg.PropertyNames + : Array.Empty(); + } + + /// + /// Gets the message template format string from the log event. + /// + /// The log event + /// Template string if LogMessage, otherwise the string representation + /// + /// + /// var template = logEvent.GetTemplate(); + /// // For semantic logs, returns "User {UserId} logged in" + /// // For pre-formatted strings, returns the actual message + /// + /// + public static string GetTemplate(this LogEvent evt) + { + return evt.Message is LogMessage msg + ? msg.Format + : evt.Message?.ToString() ?? string.Empty; + } + + /// + /// Gets the parameter values from the log message. + /// Returns empty enumerable if message is a pre-formatted string. + /// + /// The log event + /// Parameter values, or empty enumerable + /// + /// + /// var parameters = logEvent.GetParameters().ToArray(); + /// // For log.Info("User {0}", 123), returns [123] + /// + /// + public static IEnumerable GetParameters(this LogEvent evt) + { + return evt.Message is LogMessage msg + ? msg.Parameters() + : Enumerable.Empty(); + } + } +} diff --git a/src/core/Akka/Event/LogMessage.cs b/src/core/Akka/Event/LogMessage.cs index 955541dfe52..64eb3634c36 100644 --- a/src/core/Akka/Event/LogMessage.cs +++ b/src/core/Akka/Event/LogMessage.cs @@ -25,16 +25,35 @@ public static class LogMessageExtensions{ /// /// /// Call ToString to get the formatted output. + /// Supports semantic logging by extracting property names from message templates. /// public abstract class LogMessage { protected readonly ILogMessageFormatter Formatter; + private IReadOnlyList? _propertyNames; + private IReadOnlyDictionary? _properties; /// /// Gets the format string of this log message. /// public string Format { get; private set; } + /// + /// Gets the property names extracted from the message template. + /// For positional templates like "{0} and {1}", returns ["0", "1"]. + /// For named templates like "{UserId} logged in", returns ["UserId"]. + /// This property uses lazy initialization and caching for performance. + /// + public IReadOnlyList PropertyNames + { + get + { + if (_propertyNames == null) + _propertyNames = MessageTemplateParser.GetPropertyNames(Format); + return _propertyNames; + } + } + /// /// Initializes an instance of the LogMessage with the specified formatter, format and args. /// @@ -46,6 +65,98 @@ public LogMessage(ILogMessageFormatter formatter, string format) Format = format; } + /// + /// Gets a dictionary of property names to their values. + /// Combines PropertyNames with Parameters() to create name-value pairs. + /// This method uses lazy initialization and caching for performance. + /// + /// A read-only dictionary of property names and values + public IReadOnlyDictionary GetProperties() + { + if (_properties == null) + { + var names = PropertyNames; + var parameters = Parameters(); + + // Optimize: avoid ToArray() if Parameters() already returns IReadOnlyList + if (parameters is IReadOnlyList readOnlyList) + { + _properties = CreatePropertyDictionary(names, readOnlyList); + } + else if (parameters is object[] array) + { + _properties = CreatePropertyDictionary(names, array); + } + else + { + // Fallback: convert to array + _properties = CreatePropertyDictionary(names, parameters.ToArray()); + } + } + return _properties; + } + + private static IReadOnlyDictionary CreatePropertyDictionary( + IReadOnlyList names, + IReadOnlyList values) + { + // Handle empty case + if (names.Count == 0) + return EmptyDictionary; + + // Handle mismatched counts (more values than names, or vice versa) + var count = Math.Min(names.Count, values.Count); + if (count == 0) + return EmptyDictionary; + + var dict = new Dictionary(count); + for (int i = 0; i < count; i++) + { + dict[names[i]] = values[i]; + } + +#if NET8_0_OR_GREATER + // Use FrozenDictionary for optimal read performance on .NET 8+ + return System.Collections.Frozen.FrozenDictionary.ToFrozenDictionary(dict); +#else + return dict; +#endif + } + + private static IReadOnlyDictionary CreatePropertyDictionary( + IReadOnlyList names, + object[] values) + { + // Handle empty case + if (names.Count == 0) + return EmptyDictionary; + + // Handle mismatched counts (more values than names, or vice versa) + var count = Math.Min(names.Count, values.Length); + if (count == 0) + return EmptyDictionary; + + var dict = new Dictionary(count); + for (int i = 0; i < count; i++) + { + dict[names[i]] = values[i]; + } + +#if NET8_0_OR_GREATER + // Use FrozenDictionary for optimal read performance on .NET 8+ + return System.Collections.Frozen.FrozenDictionary.ToFrozenDictionary(dict); +#else + return dict; +#endif + } + + private static readonly IReadOnlyDictionary EmptyDictionary = +#if NET8_0_OR_GREATER + System.Collections.Frozen.FrozenDictionary.Empty; +#else + new Dictionary(); +#endif + /// /// INTERNAL API /// diff --git a/src/core/Akka/Event/MessageTemplateParser.cs b/src/core/Akka/Event/MessageTemplateParser.cs new file mode 100644 index 00000000000..be04997ad25 --- /dev/null +++ b/src/core/Akka/Event/MessageTemplateParser.cs @@ -0,0 +1,213 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2025 Lightbend Inc. +// Copyright (C) 2013-2025 .NET Foundation +// +//----------------------------------------------------------------------- + +using System; +using System.Collections.Generic; +using System.Linq; + +namespace Akka.Event +{ + /// + /// Parses message templates to extract property names for semantic logging. + /// Supports both positional templates ({0}, {1}) and named templates ({PropertyName}). + /// Uses ThreadStatic caching for performance. + /// + internal static class MessageTemplateParser + { + [ThreadStatic] + private static LruCache? _cache; + + private const int MaxCacheSize = 1000; + + private static LruCache Cache + { + get + { + if (_cache == null) + _cache = new LruCache(MaxCacheSize); + return _cache; + } + } + + /// + /// Gets the property names from a message template. + /// For positional templates like "{0} and {1}", returns ["0", "1"]. + /// For named templates like "{UserId} logged in", returns ["UserId"]. + /// Results are cached for performance. + /// + /// The message template string + /// List of property names + public static IReadOnlyList GetPropertyNames(string template) + { + if (string.IsNullOrEmpty(template)) + return Array.Empty(); + + var hash = template.GetHashCode(); + + // Try cache first + if (Cache.TryGet(hash, out var cached) && cached.Template == template) + return cached.PropertyNames; + + // Parse and cache + var propertyNames = ParseTemplate(template); + var parsed = new ParsedTemplate(template, propertyNames); + Cache.Add(hash, parsed); + + return propertyNames; + } + + /// + /// Parses a message template to extract property names. + /// + private static IReadOnlyList ParseTemplate(string template) + { + var properties = new List(); + var length = template.Length; + var i = 0; + + while (i < length) + { + var openBrace = template.IndexOf('{', i); + if (openBrace == -1) + break; + + // Check for escaped brace {{ + if (openBrace + 1 < length && template[openBrace + 1] == '{') + { + i = openBrace + 2; + continue; + } + + var closeBrace = template.IndexOf('}', openBrace + 1); + if (closeBrace == -1) + break; // Malformed template, stop parsing + + // Note: We do NOT check for }} here. The }} escape sequence only applies to literal + // text during formatting, not during property name extraction. After finding a valid + // placeholder {Name}, any subsequent } is a literal character, not an escape. + // For example: "{UserId}}" has placeholder "UserId" followed by literal "}" + + // Extract property name + var propertyLength = closeBrace - openBrace - 1; + if (propertyLength > 0) + { + var propertyName = template.Substring(openBrace + 1, propertyLength).Trim(); + + // Remove format specifiers (e.g., {Value:N2} -> Value) + var colonIndex = propertyName.IndexOf(':'); + if (colonIndex > 0) + propertyName = propertyName.Substring(0, colonIndex).Trim(); + + // Remove alignment specifiers (e.g., {Value,10} -> Value) + var commaIndex = propertyName.IndexOf(','); + if (commaIndex > 0) + propertyName = propertyName.Substring(0, commaIndex).Trim(); + + if (!string.IsNullOrEmpty(propertyName)) + properties.Add(propertyName); + } + + i = closeBrace + 1; + } + + return properties.ToArray(); + } + } + + /// + /// Represents a parsed message template with property names. + /// + internal sealed class ParsedTemplate + { + public string Template { get; } + public IReadOnlyList PropertyNames { get; } + + public ParsedTemplate(string template, IReadOnlyList propertyNames) + { + Template = template; + PropertyNames = propertyNames; + } + } + + /// + /// Simple LRU (Least Recently Used) cache implementation. + /// + internal sealed class LruCache where TKey : notnull + { + private readonly int _maxSize; + private readonly Dictionary> _cache; + private readonly LinkedList _lruList; + + public LruCache(int maxSize) + { + _maxSize = maxSize; + _cache = new Dictionary>(maxSize); + _lruList = new LinkedList(); + } + + /// + /// Tries to get a value from the cache. + /// If found, moves the entry to the front (most recently used). + /// + public bool TryGet(TKey key, out TValue value) + { + if (_cache.TryGetValue(key, out var node)) + { + // Move to front (most recently used) + _lruList.Remove(node); + _lruList.AddFirst(node); + + value = node.Value.Value; + return true; + } + + value = default!; + return false; + } + + /// + /// Adds a value to the cache. + /// If at capacity, evicts the least recently used entry. + /// + public void Add(TKey key, TValue value) + { + // If key already exists, update it + if (_cache.TryGetValue(key, out var existingNode)) + { + _lruList.Remove(existingNode); + _cache.Remove(key); + } + // Evict oldest if at capacity + else if (_cache.Count >= _maxSize) + { + var oldest = _lruList.Last; + if (oldest != null) + { + _lruList.RemoveLast(); + _cache.Remove(oldest.Value.Key); + } + } + + // Add new entry + var entry = new CacheEntry(key, value); + var node = _lruList.AddFirst(entry); + _cache[key] = node; + } + + private struct CacheEntry + { + public TKey Key { get; } + public TValue Value { get; } + + public CacheEntry(TKey key, TValue value) + { + Key = key; + Value = value; + } + } + } +} diff --git a/src/core/Akka/Event/SemanticLogMessageFormatter.cs b/src/core/Akka/Event/SemanticLogMessageFormatter.cs new file mode 100644 index 00000000000..73c3df71dd1 --- /dev/null +++ b/src/core/Akka/Event/SemanticLogMessageFormatter.cs @@ -0,0 +1,494 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2025 Lightbend Inc. +// Copyright (C) 2013-2025 .NET Foundation +// +//----------------------------------------------------------------------- + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; + +namespace Akka.Event +{ + /// + /// Message formatter that supports semantic logging with both positional and named templates. + /// Implements the Message Templates specification, + /// which is the language-neutral standard used by Serilog, Microsoft.Extensions.Logging, NLog, + /// and other structured logging frameworks. + /// + /// + /// Supported syntax: + /// + /// Named properties: {PropertyName} + /// Positional properties: {0}, {1} + /// Format specifiers: {Value:N2}, {Date:yyyy-MM-dd} + /// Alignment: {Value,10}, {Value,-10} + /// Escaped braces: {{ → {, }} → } + /// + /// Not supported: + /// + /// Destructuring operators: {@Object}, {$Object} (Serilog-specific) + /// Empty property names: {:N2} (invalid per spec) + /// + /// + public sealed class SemanticLogMessageFormatter : ILogMessageFormatter + { + /// + /// Gets the singleton instance of the . + /// + public static readonly SemanticLogMessageFormatter Instance = new(); + + private SemanticLogMessageFormatter() + { + } + + /// + /// Formats a log message using the specified format string and arguments. + /// + /// The format string (supports both {0} and {PropertyName} styles) + /// The arguments to format + /// The formatted message string + public string Format(string format, params object[] args) + { + return Format(format, (IEnumerable)args); + } + + /// + /// Formats a log message using the specified format string and arguments. + /// + /// The format string (supports both {0} and {PropertyName} styles) + /// The arguments to format + /// The formatted message string + public string Format(string format, IEnumerable args) + { + if (string.IsNullOrEmpty(format)) + return string.Empty; + + // Optimize: avoid ToArray() if args is already an array or IReadOnlyList + object[] argArray; + if (args == null) + { + argArray = Array.Empty(); + } + else if (args is object[] array) + { + argArray = array; + } + else if (args is IReadOnlyList readOnlyList) + { + // LogValues structs implement IReadOnlyList, use them directly + // Only convert to array for string.Format which requires object[] + var propertyNames = MessageTemplateParser.GetPropertyNames(format); + if (propertyNames.Count == 0) + return UnescapeBraces(format); + + var isPositional = propertyNames.Count > 0 && int.TryParse(propertyNames[0], out _); + + if (isPositional) + { + // string.Format requires object[], so convert here only + argArray = new object[readOnlyList.Count]; + for (int i = 0; i < readOnlyList.Count; i++) + argArray[i] = readOnlyList[i]; + + // For positional templates, use string.Format directly without catching FormatException + // to maintain backward compatibility with DefaultLogMessageFormatter behavior + return string.Format(format, argArray); + } + else + { + // Named template - use IReadOnlyList directly + return FormatNamedTemplate(format, propertyNames, readOnlyList); + } + } + else + { + argArray = args.ToArray(); + } + + if (argArray.Length == 0) + return UnescapeBraces(format); + + // Get property names from the template + var propertyNames2 = MessageTemplateParser.GetPropertyNames(format); + if (propertyNames2.Count == 0) + return UnescapeBraces(format); + + // Check if this is a positional template or named template + var isPositional2 = propertyNames2.Count > 0 && int.TryParse(propertyNames2[0], out _); + + if (isPositional2) + { + // For positional templates, use string.Format directly without catching FormatException + // to maintain backward compatibility with DefaultLogMessageFormatter behavior + return string.Format(format, argArray); + } + else + { + // Named template - do semantic substitution + return FormatNamedTemplate(format, propertyNames2, argArray); + } + } + + /// + /// Unescapes {{ to { and }} to } in a string that has no placeholders. + /// + private static string UnescapeBraces(string format) + { + // Fast path: if no escaped braces, return as-is + if (format.IndexOf('{') == -1 && format.IndexOf('}') == -1) + return format; + + var result = new StringBuilder(format.Length); + var length = format.Length; + var i = 0; + + while (i < length) + { + var ch = format[i]; + + if (ch == '{' && i + 1 < length && format[i + 1] == '{') + { + result.Append('{'); + i += 2; + } + else if (ch == '}' && i + 1 < length && format[i + 1] == '}') + { + result.Append('}'); + i += 2; + } + else + { + result.Append(ch); + i++; + } + } + + return result.ToString(); + } + + /// + /// Formats a named template by replacing {PropertyName} with values. + /// Handles escaped braces: {{ → {, }} → } + /// + private static string FormatNamedTemplate(string format, IReadOnlyList propertyNames, IReadOnlyList args) + { + var result = new StringBuilder(format.Length + args.Count * 10); + var length = format.Length; + var i = 0; + var argIndex = 0; + + while (i < length) + { + var ch = format[i]; + + // Check for escaped }} in literal text + if (ch == '}' && i + 1 < length && format[i + 1] == '}') + { + result.Append('}'); + i += 2; + continue; + } + + // Check for placeholder start + if (ch == '{') + { + // Check for escaped brace {{ + if (i + 1 < length && format[i + 1] == '{') + { + result.Append('{'); + i += 2; + continue; + } + + // Find closing brace for placeholder + var closeBrace = format.IndexOf('}', i + 1); + if (closeBrace == -1) + { + // Malformed template, append rest and break + result.Append(format.Substring(i)); + break; + } + + // Extract the placeholder content + var placeholderLength = closeBrace - i - 1; + if (placeholderLength > 0) + { + var placeholder = format.Substring(i + 1, placeholderLength).Trim(); + + // Parse placeholder: {Name,alignment:format} + // First, find the property name (before comma or colon) + var commaIndex = placeholder.IndexOf(','); + var colonIndex = placeholder.IndexOf(':'); + string propertyName; + string alignmentSpec = null; + string formatSpec = null; + + // Determine the property name endpoint + var endOfName = placeholder.Length; + if (commaIndex >= 0 && (colonIndex < 0 || commaIndex < colonIndex)) + { + // Comma comes first (or no colon) + endOfName = commaIndex; + } + else if (colonIndex >= 0) + { + // Colon comes first (or no comma) + endOfName = colonIndex; + } + + propertyName = placeholder.Substring(0, endOfName).Trim(); + + // Extract alignment if present + if (commaIndex >= 0) + { + var alignmentStart = commaIndex + 1; + var alignmentEnd = colonIndex >= 0 ? colonIndex : placeholder.Length; + alignmentSpec = placeholder.Substring(alignmentStart, alignmentEnd - alignmentStart).Trim(); + } + + // Extract format specifier if present + if (colonIndex >= 0) + { + formatSpec = placeholder.Substring(colonIndex + 1).Trim(); + } + + placeholder = propertyName; + + // Substitute the value + if (argIndex < args.Count) + { + var value = args[argIndex]; + string formattedValue; + + if (value != null) + { + // First get the string representation + var strValue = value.ToString(); + + if (strValue != null) + { + // Apply format specifier if present + if (!string.IsNullOrEmpty(formatSpec)) + { + try + { + formattedValue = string.Format($"{{0:{formatSpec}}}", value); + } + catch + { + // If formatting fails, use the plain string + formattedValue = strValue; + } + } + else + { + formattedValue = strValue; + } + } + else + { + // ToString() returned null + formattedValue = "null"; + } + } + else + { + formattedValue = "null"; + } + + // Apply alignment if present + if (!string.IsNullOrEmpty(alignmentSpec) && int.TryParse(alignmentSpec, out var alignment)) + { + formattedValue = alignment > 0 + ? formattedValue.PadLeft(alignment) + : formattedValue.PadRight(-alignment); + } + + result.Append(formattedValue); + argIndex++; + } + else + { + // Not enough args, keep the placeholder + result.Append('{').Append(placeholder).Append('}'); + } + } + + i = closeBrace + 1; + } + else + { + // Regular character + result.Append(ch); + i++; + } + } + + return result.ToString(); + } + + /// + /// Formats a named template by replacing {PropertyName} with values. + /// Handles escaped braces: {{ → {, }} → } + /// + private static string FormatNamedTemplate(string format, IReadOnlyList propertyNames, object[] args) + { + var result = new StringBuilder(format.Length + args.Length * 10); + var length = format.Length; + var i = 0; + var argIndex = 0; + + while (i < length) + { + var ch = format[i]; + + // Check for escaped }} in literal text + if (ch == '}' && i + 1 < length && format[i + 1] == '}') + { + result.Append('}'); + i += 2; + continue; + } + + // Check for placeholder start + if (ch == '{') + { + // Check for escaped brace {{ + if (i + 1 < length && format[i + 1] == '{') + { + result.Append('{'); + i += 2; + continue; + } + + // Find closing brace for placeholder + var closeBrace = format.IndexOf('}', i + 1); + if (closeBrace == -1) + { + // Malformed template, append rest and break + result.Append(format.Substring(i)); + break; + } + + // Extract the placeholder content + var placeholderLength = closeBrace - i - 1; + if (placeholderLength > 0) + { + var placeholder = format.Substring(i + 1, placeholderLength).Trim(); + + // Parse placeholder: {Name,alignment:format} + // First, find the property name (before comma or colon) + var commaIndex = placeholder.IndexOf(','); + var colonIndex = placeholder.IndexOf(':'); + string propertyName; + string alignmentSpec = null; + string formatSpec = null; + + // Determine the property name endpoint + var endOfName = placeholder.Length; + if (commaIndex >= 0 && (colonIndex < 0 || commaIndex < colonIndex)) + { + // Comma comes first (or no colon) + endOfName = commaIndex; + } + else if (colonIndex >= 0) + { + // Colon comes first (or no comma) + endOfName = colonIndex; + } + + propertyName = placeholder.Substring(0, endOfName).Trim(); + + // Extract alignment if present + if (commaIndex >= 0) + { + var alignmentStart = commaIndex + 1; + var alignmentEnd = colonIndex >= 0 ? colonIndex : placeholder.Length; + alignmentSpec = placeholder.Substring(alignmentStart, alignmentEnd - alignmentStart).Trim(); + } + + // Extract format specifier if present + if (colonIndex >= 0) + { + formatSpec = placeholder.Substring(colonIndex + 1).Trim(); + } + + placeholder = propertyName; + + // Substitute the value + if (argIndex < args.Length) + { + var value = args[argIndex]; + string formattedValue; + + if (value != null) + { + // First get the string representation + var strValue = value.ToString(); + + if (strValue != null) + { + // Apply format specifier if present + if (!string.IsNullOrEmpty(formatSpec)) + { + try + { + formattedValue = string.Format($"{{0:{formatSpec}}}", value); + } + catch + { + // If formatting fails, use the plain string + formattedValue = strValue; + } + } + else + { + formattedValue = strValue; + } + } + else + { + // ToString() returned null + formattedValue = "null"; + } + } + else + { + formattedValue = "null"; + } + + // Apply alignment if present + if (!string.IsNullOrEmpty(alignmentSpec) && int.TryParse(alignmentSpec, out var alignment)) + { + formattedValue = alignment > 0 + ? formattedValue.PadLeft(alignment) + : formattedValue.PadRight(-alignment); + } + + result.Append(formattedValue); + argIndex++; + } + else + { + // Not enough args, keep the placeholder + result.Append('{').Append(placeholder).Append('}'); + } + } + + i = closeBrace + 1; + } + else + { + // Regular character + result.Append(ch); + i++; + } + } + + return result.ToString(); + } + } +} diff --git a/src/core/Akka/Event/StandardOutLogger.cs b/src/core/Akka/Event/StandardOutLogger.cs index 037cab22c41..1215fffedae 100644 --- a/src/core/Akka/Event/StandardOutLogger.cs +++ b/src/core/Akka/Event/StandardOutLogger.cs @@ -6,6 +6,7 @@ //----------------------------------------------------------------------- using System; +using System.Linq; using Akka.Actor; using Akka.Util; using System.Text; @@ -126,7 +127,7 @@ internal static void PrintLogEvent(LogEvent logEvent, LogFilterEvaluator filter) // short circuit if we're not going to print this message if (!filter.ShouldTryKeepMessage(logEvent, out var expandedLogMessage)) return; - + ConsoleColor? color = null; if (UseColors)