Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
120 changes: 120 additions & 0 deletions src/core/Akka.Tests/Event/FormatterSpecs.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,120 @@
//-----------------------------------------------------------------------
// <copyright file="FormatterSpecs.cs" company="Akka.NET Project">
// Copyright (C) 2009-2025 Lightbend Inc. <http://www.lightbend.com>
// Copyright (C) 2013-2025 .NET Foundation <https://github.com/akkadotnet/akka.net>
// </copyright>
//-----------------------------------------------------------------------

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<string, string>("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");
}
}
}
34 changes: 11 additions & 23 deletions src/core/Akka.Tests/Loggers/LoggerSpec.cs
Original file line number Diff line number Diff line change
Expand Up @@ -37,40 +37,28 @@ public LoggerSpec(ITestOutputHelper output) : base(Config, output)
[Fact]
public async Task TestOutputLogger_WithBadFormattingMustNotThrow()
{
var events = new List<LogEvent>();

// 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<Error>());
events.Add(await ExpectMsgAsync<Error>());

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<Error>();
errorEvt.Cause.Should().BeOfType<FakeException>();
errorEvt.ToString().Should().Contain("[INVALID LOG FORMAT]");

events.Clear();
Sys.Log.Warning(Case.t, Case.p);
events.Add(await ExpectMsgAsync<LogEvent>());
events.Add(await ExpectMsgAsync<LogEvent>());
events.Any(e => e is Warning).Should().BeTrue();
events.First(e => e is Error).Cause.Should().BeOfType<FormatException>();
var warningEvt = await ExpectMsgAsync<Warning>();
warningEvt.ToString().Should().Contain("[INVALID LOG FORMAT]");

events.Clear();
Sys.Log.Info(Case.t, Case.p);
events.Add(await ExpectMsgAsync<LogEvent>());
events.Add(await ExpectMsgAsync<LogEvent>());
events.Any(e => e is Info).Should().BeTrue();
events.First(e => e is Error).Cause.Should().BeOfType<FormatException>();
var infoEvt = await ExpectMsgAsync<Info>();
infoEvt.ToString().Should().Contain("[INVALID LOG FORMAT]");

events.Clear();
Sys.Log.Debug(Case.t, Case.p);
events.Add(await ExpectMsgAsync<LogEvent>());
events.Add(await ExpectMsgAsync<LogEvent>());
events.Any(e => e is Debug).Should().BeTrue();
events.First(e => e is Error).Cause.Should().BeOfType<FormatException>();
var debugEvt = await ExpectMsgAsync<Debug>();
debugEvt.ToString().Should().Contain("[INVALID LOG FORMAT]");
}

[Fact]
Expand Down
24 changes: 21 additions & 3 deletions src/core/Akka/Event/DefaultLogMessageFormatter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
// </copyright>
//-----------------------------------------------------------------------

using System;
using System.Collections.Generic;
using System.Linq;

Expand All @@ -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<object> 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.";
}
}
}
}
39 changes: 36 additions & 3 deletions src/core/Akka/Event/LogFilter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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;
}

/// <summary>
/// INTERNAL API - used to prevent unnecessary iterations when no filters are present
/// </summary>
Expand All @@ -224,7 +250,14 @@ private EmptyLogFilterEvaluator() : base(Array.Empty<LogFilterBase>())

public override bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMessage)
{
expandedLogMessage = evt.ToString()!;
try
{
expandedLogMessage = evt.ToString()!;
}
catch (FormatException)
{
expandedLogMessage = FallbackFormat(evt);
}
return true;
}
}
Expand Down
31 changes: 25 additions & 6 deletions src/core/Akka/Event/SemanticLogMessageFormatter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -100,9 +100,14 @@ public string Format(string format, IEnumerable<object> 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
{
Expand All @@ -128,9 +133,14 @@ public string Format(string format, IEnumerable<object> 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
{
Expand All @@ -139,6 +149,15 @@ public string Format(string format, IEnumerable<object> args)
}
}

/// <summary>
/// Produces a diagnostic string when string.Format fails due to mismatched format/args.
/// </summary>
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.";
}

/// <summary>
/// Unescapes {{ to { and }} to } in a string that has no placeholders.
/// </summary>
Expand Down
Loading