diff --git a/src/core/Akka.Tests/Event/FormatterSpecs.cs b/src/core/Akka.Tests/Event/FormatterSpecs.cs new file mode 100644 index 00000000000..4db5efef36d --- /dev/null +++ b/src/core/Akka.Tests/Event/FormatterSpecs.cs @@ -0,0 +1,120 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2025 Lightbend Inc. +// Copyright (C) 2013-2025 .NET Foundation +// +//----------------------------------------------------------------------- + +using System; +using Akka.Event; +using FluentAssertions; +using Xunit; + +namespace Akka.Tests.Event +{ + public class FormatterSpecs + { + [Fact(DisplayName = "SemanticLogMessageFormatter should return diagnostic for mismatched positional args")] + public void SemanticLogMessageFormatter_should_return_diagnostic_for_mismatched_positional_args() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("{0} {1} {2}", new object[] { "a", "b" }); + + result.Should().StartWith("[INVALID LOG FORMAT]"); + result.Should().Contain("{0} {1} {2}"); + result.Should().Contain("a"); + result.Should().Contain("b"); + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should return diagnostic for mismatched positional args via IReadOnlyList path")] + public void SemanticLogMessageFormatter_should_return_diagnostic_for_mismatched_positional_args_via_readonly_list() + { + var formatter = SemanticLogMessageFormatter.Instance; + var args = new LogValues("a", "b"); + var result = formatter.Format("{0} {1} {2}", args); + + result.Should().StartWith("[INVALID LOG FORMAT]"); + result.Should().Contain("{0} {1} {2}"); + } + + [Fact(DisplayName = "DefaultLogMessageFormatter should return diagnostic for mismatched positional args")] + public void DefaultLogMessageFormatter_should_return_diagnostic_for_mismatched_positional_args() + { + var formatter = DefaultLogMessageFormatter.Instance; + var result = formatter.Format("{0} {1} {2}", new object[] { "a", "b" }); + + result.Should().StartWith("[INVALID LOG FORMAT]"); + result.Should().Contain("{0} {1} {2}"); + result.Should().Contain("a"); + result.Should().Contain("b"); + } + + [Fact(DisplayName = "DefaultLogMessageFormatter should return diagnostic for mismatched positional args via IEnumerable overload")] + public void DefaultLogMessageFormatter_should_return_diagnostic_for_mismatched_positional_args_via_enumerable() + { + var formatter = DefaultLogMessageFormatter.Instance; + var result = formatter.Format("{0} {1} {2}", new object[] { "a", "b" }); + + result.Should().StartWith("[INVALID LOG FORMAT]"); + result.Should().Contain("{0} {1} {2}"); + } + + [Fact(DisplayName = "LogFilterEvaluator should handle FormatException gracefully")] + public void LogFilterEvaluator_should_handle_FormatException_gracefully() + { + // Use the empty evaluator (no filters) - this is the path third-party loggers hit + var evaluator = LogFilterEvaluator.NoFilters; + + // Create a log event with a bad format string + var badMessage = new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "{0} {1} {2}", + "a", "b"); + + var evt = new Warning("test-source", typeof(FormatterSpecs), badMessage); + + var result = evaluator.ShouldTryKeepMessage(evt, out var expandedMessage); + + result.Should().BeTrue(); + expandedMessage.Should().NotBeNullOrEmpty(); + expandedMessage.Should().Contain("[INVALID LOG FORMAT]"); + } + + [Fact(DisplayName = "LogFilterEvaluator with content filters should handle FormatException gracefully")] + public void LogFilterEvaluator_with_content_filters_should_handle_FormatException_gracefully() + { + // Create an evaluator with a content filter to exercise the non-empty filter path + var filter = new RegexLogMessageFilter( + new System.Text.RegularExpressions.Regex("never_match_anything")); + var evaluator = new LogFilterEvaluator(new LogFilterBase[] { filter }); + + var badMessage = new DefaultLogMessage( + SemanticLogMessageFormatter.Instance, + "{0} {1} {2}", + "a", "b"); + + var evt = new Warning("test-source", typeof(FormatterSpecs), badMessage); + + var result = evaluator.ShouldTryKeepMessage(evt, out var expandedMessage); + + result.Should().BeTrue(); + expandedMessage.Should().Contain("[INVALID LOG FORMAT]"); + } + + [Fact(DisplayName = "SemanticLogMessageFormatter should still format valid positional templates correctly")] + public void SemanticLogMessageFormatter_should_still_format_valid_positional_templates() + { + var formatter = SemanticLogMessageFormatter.Instance; + var result = formatter.Format("{0} and {1}", new object[] { "hello", "world" }); + result.Should().Be("hello and world"); + } + + [Fact(DisplayName = "DefaultLogMessageFormatter should still format valid positional templates correctly")] + public void DefaultLogMessageFormatter_should_still_format_valid_positional_templates() + { + var formatter = DefaultLogMessageFormatter.Instance; + var result = formatter.Format("{0} and {1}", new object[] { "hello", "world" }); + result.Should().Be("hello and world"); + } + } +} diff --git a/src/core/Akka.Tests/Loggers/LoggerSpec.cs b/src/core/Akka.Tests/Loggers/LoggerSpec.cs index a052b94ce3d..c4f9d851338 100644 --- a/src/core/Akka.Tests/Loggers/LoggerSpec.cs +++ b/src/core/Akka.Tests/Loggers/LoggerSpec.cs @@ -37,40 +37,28 @@ public LoggerSpec(ITestOutputHelper output) : base(Config, output) [Fact] public async Task TestOutputLogger_WithBadFormattingMustNotThrow() { - var events = new List(); - // Need to wait until TestOutputLogger initializes await Task.Delay(500); Sys.EventStream.Subscribe(TestActor, typeof(LogEvent)); + // Bad format strings should now produce diagnostic messages rather than throwing FormatException. + // Only the original log event should be published (no secondary Error event). Sys.Log.Error(new FakeException("BOOM"), Case.t, Case.p); - events.Add(await ExpectMsgAsync()); - events.Add(await ExpectMsgAsync()); - - events.All(e => e is Error).Should().BeTrue(); - events.Select(e => e.Cause).Any(c => c is FakeException).Should().BeTrue(); - events.Select(e => e.Cause).Any(c => c is AggregateException).Should().BeTrue(); + var errorEvt = await ExpectMsgAsync(); + errorEvt.Cause.Should().BeOfType(); + errorEvt.ToString().Should().Contain("[INVALID LOG FORMAT]"); - events.Clear(); Sys.Log.Warning(Case.t, Case.p); - events.Add(await ExpectMsgAsync()); - events.Add(await ExpectMsgAsync()); - events.Any(e => e is Warning).Should().BeTrue(); - events.First(e => e is Error).Cause.Should().BeOfType(); + var warningEvt = await ExpectMsgAsync(); + warningEvt.ToString().Should().Contain("[INVALID LOG FORMAT]"); - events.Clear(); Sys.Log.Info(Case.t, Case.p); - events.Add(await ExpectMsgAsync()); - events.Add(await ExpectMsgAsync()); - events.Any(e => e is Info).Should().BeTrue(); - events.First(e => e is Error).Cause.Should().BeOfType(); + var infoEvt = await ExpectMsgAsync(); + infoEvt.ToString().Should().Contain("[INVALID LOG FORMAT]"); - events.Clear(); Sys.Log.Debug(Case.t, Case.p); - events.Add(await ExpectMsgAsync()); - events.Add(await ExpectMsgAsync()); - events.Any(e => e is Debug).Should().BeTrue(); - events.First(e => e is Error).Cause.Should().BeOfType(); + var debugEvt = await ExpectMsgAsync(); + debugEvt.ToString().Should().Contain("[INVALID LOG FORMAT]"); } [Fact] diff --git a/src/core/Akka/Event/DefaultLogMessageFormatter.cs b/src/core/Akka/Event/DefaultLogMessageFormatter.cs index e38e90c82ba..3e982576871 100644 --- a/src/core/Akka/Event/DefaultLogMessageFormatter.cs +++ b/src/core/Akka/Event/DefaultLogMessageFormatter.cs @@ -5,6 +5,7 @@ // //----------------------------------------------------------------------- +using System; using System.Collections.Generic; using System.Linq; @@ -17,15 +18,32 @@ public class DefaultLogMessageFormatter : ILogMessageFormatter { public static readonly DefaultLogMessageFormatter Instance = new(); private DefaultLogMessageFormatter(){} - + public string Format(string format, params object[] args) { - return string.Format(format, args); + try + { + return string.Format(format, args); + } + catch (FormatException) + { + return $"[INVALID LOG FORMAT] str=[{format}], args=[{string.Join(", ", args)}]. " + + "Please fix the format string in the logging call site."; + } } public string Format(string format, IEnumerable args) { - return string.Format(format, args.ToArray()); + var argsArray = args.ToArray(); + try + { + return string.Format(format, argsArray); + } + catch (FormatException) + { + return $"[INVALID LOG FORMAT] str=[{format}], args=[{string.Join(", ", argsArray)}]. " + + "Please fix the format string in the logging call site."; + } } } } diff --git a/src/core/Akka/Event/LogFilter.cs b/src/core/Akka/Event/LogFilter.cs index e6a65a51fea..7a6333a2f1b 100644 --- a/src/core/Akka/Event/LogFilter.cs +++ b/src/core/Akka/Event/LogFilter.cs @@ -190,7 +190,15 @@ public virtual bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMes else { // allocate the message just once - var nullCheck = evt.ToString(); + string nullCheck; + try + { + nullCheck = evt.ToString(); + } + catch (FormatException) + { + nullCheck = FallbackFormat(evt); + } if (nullCheck == null) return false; // no message to filter @@ -207,10 +215,28 @@ public virtual bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMes // expand the message if we haven't already // NOTE: might result in duplicate allocations in third party logging libraries. They'll have to adjust their // code accordingly after this feature ships. - expandedLogMessage = (string.IsNullOrEmpty(expandedLogMessage) ? evt.Message.ToString() : expandedLogMessage)!; + if (string.IsNullOrEmpty(expandedLogMessage)) + { + try + { + expandedLogMessage = evt.Message.ToString()!; + } + catch (FormatException) + { + expandedLogMessage = FallbackFormat(evt); + } + } return true; } + private static string FallbackFormat(LogEvent evt) + { + if (evt.Message is LogMessage lm) + return $"[INVALID LOG FORMAT] str=[{lm.Format}], args=[{lm.Unformatted()}]. " + + "Please fix the format string in the logging call site."; + return evt.Message?.ToString() ?? string.Empty; + } + /// /// INTERNAL API - used to prevent unnecessary iterations when no filters are present /// @@ -224,7 +250,14 @@ private EmptyLogFilterEvaluator() : base(Array.Empty()) public override bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMessage) { - expandedLogMessage = evt.ToString()!; + try + { + expandedLogMessage = evt.ToString()!; + } + catch (FormatException) + { + expandedLogMessage = FallbackFormat(evt); + } return true; } } diff --git a/src/core/Akka/Event/SemanticLogMessageFormatter.cs b/src/core/Akka/Event/SemanticLogMessageFormatter.cs index 2ceeb679793..b94d85604a9 100644 --- a/src/core/Akka/Event/SemanticLogMessageFormatter.cs +++ b/src/core/Akka/Event/SemanticLogMessageFormatter.cs @@ -100,9 +100,14 @@ public string Format(string format, IEnumerable args) 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); + try + { + return string.Format(format, argArray); + } + catch (FormatException) + { + return FormatDiagnostic(format, argArray); + } } else { @@ -128,9 +133,14 @@ public string Format(string format, IEnumerable args) if (isPositional2) { - // For positional templates, use string.Format directly without catching FormatException - // to maintain backward compatibility with DefaultLogMessageFormatter behavior - return string.Format(format, argArray); + try + { + return string.Format(format, argArray); + } + catch (FormatException) + { + return FormatDiagnostic(format, argArray); + } } else { @@ -139,6 +149,15 @@ public string Format(string format, IEnumerable args) } } + /// + /// Produces a diagnostic string when string.Format fails due to mismatched format/args. + /// + private static string FormatDiagnostic(string format, object[] args) + { + return $"[INVALID LOG FORMAT] str=[{format}], args=[{string.Join(", ", args)}]. " + + "Please fix the format string in the logging call site."; + } + /// /// Unescapes {{ to { and }} to } in a string that has no placeholders. ///