Skip to content

Commit 9846ef6

Browse files
0xced0xced
committed
Format messages without quotes when log events come from Microsoft.Extensions.Logging
Also add the possibility to completely customize how the message is formatted with the new `Log4NetTextFormatterOptionsBuilder.UseMessageFormatter` method. Fixes #277
1 parent 6ce9b2b commit 9846ef6

12 files changed

+192
-3
lines changed

‎src/Log4NetTextFormatter.cs

Lines changed: 48 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,12 @@ public class Log4NetTextFormatter : ITextFormatter
5353
/// <remarks>https://github.com/pmetz-steelcase/Serilog.Enrichers.WithCaller/blob/1.2.0/Serilog.Enrichers.WithCaller/CallerEnricher.cs#L66</remarks>
5454
private const string CallerPropertyName = "Caller";
5555

56+
/// <summary>
57+
/// The name of the event id property, set by <a href="https://www.nuget.org/packages/Serilog.Extensions.Logging/">Serilog.Extensions.Logging</a>
58+
/// </summary>
59+
/// <remarks>https://github.com/serilog/serilog-extensions-logging/blob/v9.0.1/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs#L158</remarks>
60+
private const string EventIdPropertyName = "EventId";
61+
5662
/// <summary>
5763
/// The regular exception matching "class", "method", and optionally "file" and "line" for the caller property.
5864
/// </summary>
@@ -130,6 +136,36 @@ public void Format(LogEvent logEvent, TextWriter output)
130136
output.Write(_options.XmlWriterSettings.NewLineChars);
131137
}
132138

139+
/// <summary>
140+
/// The default message formatter.
141+
/// <list type="bullet">
142+
/// <item>If the log event comes from <c>Microsoft.Extensions.Logging</c> (detected by the presence of the <c>EventId</c> property) then the message is formatted by switching off quoting of strings.</item>
143+
/// <item>If the log event comes from Serilog, then the message is formatted by calling <see cref="LogEvent.RenderMessage(System.IO.TextWriter,System.IFormatProvider)"/>.</item>
144+
/// </list>
145+
/// </summary>
146+
/// <param name="logEvent">The log event to format.</param>
147+
/// <param name="formatProvider">The <see cref="IFormatProvider"/> that supplies culture-specific formatting information, or <see langword="null"/>.</param>
148+
/// <returns>The formatted message.</returns>
149+
internal static string DefaultMessageFormatter(LogEvent logEvent, IFormatProvider? formatProvider)
150+
{
151+
// https://github.com/serilog/serilog-extensions-logging/blob/v9.0.1/src/Serilog.Extensions.Logging/Extensions/Logging/EventIdPropertyCache.cs#L58-L73
152+
var isMicrosoftExtensionsLoggingEvent = logEvent.Properties.TryGetValue(EventIdPropertyName, out var property)
153+
&& property is StructureValue structure
154+
&& structure.Properties.Count == 2
155+
&& structure.Properties[0].Name == "Id"
156+
&& structure.Properties[1].Name == "Name";
157+
158+
if (isMicrosoftExtensionsLoggingEvent)
159+
{
160+
var formatter = new MessageTemplateTextFormatter($"{{{OutputProperties.MessagePropertyName}:l}}", formatProvider);
161+
using var output = new StringWriter();
162+
formatter.Format(logEvent, output);
163+
return output.ToString();
164+
}
165+
166+
return logEvent.RenderMessage(formatProvider);
167+
}
168+
133169
/// <summary>
134170
/// The default exception formatter. Calls the <see cref="Exception.ToString"/> method on the exception.
135171
/// </summary>
@@ -386,9 +422,20 @@ private void WritePropertyElement(XmlWriter writer, string name, LogEventPropert
386422
/// <param name="logEvent">The log event.</param>
387423
/// <param name="writer">The XML writer.</param>
388424
/// <remarks>https://github.com/apache/logging-log4net/blob/rel/2.0.8/src/Layout/XmlLayout.cs#L245-L257</remarks>
425+
[SuppressMessage("Microsoft.Design", "CA1031", Justification = "Protecting from user-provided code which might throw anything")]
389426
private void WriteMessage(LogEvent logEvent, XmlWriter writer)
390427
{
391-
var message = logEvent.RenderMessage(_options.FormatProvider);
428+
string message;
429+
try
430+
{
431+
message = _options.FormatMessage(logEvent, _options.FormatProvider);
432+
}
433+
catch (Exception exception)
434+
{
435+
Debugging.SelfLog.WriteLine($"[{GetType().FullName}] An exception was thrown while formatting a message. Using the default message formatter.\n{exception}");
436+
message = DefaultMessageFormatter(logEvent, _options.FormatProvider);
437+
}
438+
392439
WriteContent(writer, "message", message);
393440
}
394441

‎src/Log4NetTextFormatterOptions.cs

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,13 +8,14 @@ namespace Serilog.Formatting.Log4Net;
88
/// </summary>
99
internal sealed class Log4NetTextFormatterOptions
1010
{
11-
internal Log4NetTextFormatterOptions(IFormatProvider? formatProvider, CDataMode cDataMode, XmlQualifiedName? xmlNamespace, XmlWriterSettings xmlWriterSettings, PropertyFilter filterProperty, ExceptionFormatter formatException)
11+
internal Log4NetTextFormatterOptions(IFormatProvider? formatProvider, CDataMode cDataMode, XmlQualifiedName? xmlNamespace, XmlWriterSettings xmlWriterSettings, PropertyFilter filterProperty, MessageFormatter formatMessage, ExceptionFormatter formatException)
1212
{
1313
FormatProvider = formatProvider;
1414
CDataMode = cDataMode;
1515
XmlNamespace = xmlNamespace;
1616
XmlWriterSettings = xmlWriterSettings;
1717
FilterProperty = filterProperty;
18+
FormatMessage = formatMessage;
1819
FormatException = formatException;
1920
}
2021

@@ -33,6 +34,9 @@ internal Log4NetTextFormatterOptions(IFormatProvider? formatProvider, CDataMode
3334
/// <summary>See <see cref="Log4NetTextFormatterOptionsBuilder.UsePropertyFilter"/></summary>
3435
internal PropertyFilter FilterProperty { get; }
3536

37+
/// <summary>See <see cref="Log4NetTextFormatterOptionsBuilder.UseMessageFormatter"/></summary>
38+
internal MessageFormatter FormatMessage { get; }
39+
3640
/// <summary>See <see cref="Log4NetTextFormatterOptionsBuilder.UseExceptionFormatter"/></summary>
3741
internal ExceptionFormatter FormatException { get; }
3842
}

‎src/Log4NetTextFormatterOptionsBuilder.cs

Lines changed: 29 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,9 @@ internal Log4NetTextFormatterOptionsBuilder()
4646
/// <summary>See <see cref="UsePropertyFilter"/></summary>
4747
private PropertyFilter _filterProperty = (_, _) => true;
4848

49+
/// <summary>See <see cref="UseMessageFormatter"/></summary>
50+
private MessageFormatter _formatMessage = Log4NetTextFormatter.DefaultMessageFormatter;
51+
4952
/// <summary>See <see cref="UseExceptionFormatter"/></summary>
5053
private ExceptionFormatter _formatException = Log4NetTextFormatter.DefaultExceptionFormatter;
5154

@@ -136,6 +139,23 @@ public Log4NetTextFormatterOptionsBuilder UsePropertyFilter(PropertyFilter filte
136139
return this;
137140
}
138141

142+
/// <summary>
143+
/// Sets the <see cref="MessageFormatter"/> controlling how all messages are formatted.
144+
/// <para/>
145+
/// The default message formatter has two formatting modes.
146+
/// <list type="bullet">
147+
/// <item>If the log event comes from <c>Microsoft.Extensions.Logging</c> (detected by the presence of the <c>EventId</c> property) then the message is formatted by switching off quoting of strings.</item>
148+
/// <item>If the log event comes from Serilog, then the message is formatted by calling <see cref="LogEvent.RenderMessage(System.IO.TextWriter,System.IFormatProvider)"/>.</item>
149+
/// </list>
150+
/// </summary>
151+
/// <remarks>If an exception is thrown while executing the formatter, the default formatter will be used.</remarks>
152+
/// <returns>The builder in order to fluently chain all options.</returns>
153+
public Log4NetTextFormatterOptionsBuilder UseMessageFormatter(MessageFormatter formatMessage)
154+
{
155+
_formatMessage = formatMessage ?? throw new ArgumentNullException(nameof(formatMessage), "The message formatter can not be null.");
156+
return this;
157+
}
158+
139159
/// <summary>
140160
/// Sets the <see cref="ExceptionFormatter"/> controlling how all exceptions are formatted.
141161
/// <para/>
@@ -177,7 +197,7 @@ public void UseLog4JCompatibility()
177197
}
178198

179199
internal Log4NetTextFormatterOptions Build()
180-
=> new(_formatProvider, _cDataMode, _xmlNamespace, CreateXmlWriterSettings(_lineEnding, _indentationSettings), _filterProperty, _formatException);
200+
=> new(_formatProvider, _cDataMode, _xmlNamespace, CreateXmlWriterSettings(_lineEnding, _indentationSettings), _filterProperty, _formatMessage, _formatException);
181201

182202
private static XmlWriterSettings CreateXmlWriterSettings(LineEnding lineEnding, IndentationSettings? indentationSettings)
183203
{
@@ -203,6 +223,14 @@ private static XmlWriterSettings CreateXmlWriterSettings(LineEnding lineEnding,
203223
/// <returns><see langword="true"/> to include the Serilog property in the log4net properties or <see langword="false"/> to ignore the Serilog property.</returns>
204224
public delegate bool PropertyFilter(LogEvent logEvent, string propertyName);
205225

226+
/// <summary>
227+
/// Represents the method that formats the message for a <see cref="LogEvent"/>.
228+
/// </summary>
229+
/// <param name="logEvent">The log event to format.</param>
230+
/// <param name="formatProvider">The <see cref="IFormatProvider"/> that supplies culture-specific formatting information, or <see langword="null"/>.</param>
231+
/// <returns>The formatted message.</returns>
232+
public delegate string MessageFormatter(LogEvent logEvent, IFormatProvider? formatProvider);
233+
206234
/// <summary>
207235
/// Represents the method that formats an <see cref="Exception"/>.
208236
/// </summary>

‎tests/Log4NetTextFormatterTest.CustomMessageFormatter.verified.xml

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
<log4net:event timestamp="2003-01-04T15:09:26.535+01:00" level="INFO" xmlns:log4net="http://logging.apache.org/log4net/schemas/log4net-events-1.2/">
2+
<log4net:message><![CDATA[Custom message]]></log4net:message>
3+
</log4net:event>

‎tests/Log4NetTextFormatterTest.DefaultMessageFormatter_hasEventId=False.verified.xml

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
<log4net:event timestamp="2003-01-04T15:09:26.535+01:00" level="INFO" xmlns:log4net="http://logging.apache.org/log4net/schemas/log4net-events-1.2/">
2+
<log4net:properties>
3+
<log4net:data name="Name" value="World" />
4+
</log4net:properties>
5+
<log4net:message><![CDATA[Hello "World"!]]></log4net:message>
6+
</log4net:event>

‎tests/Log4NetTextFormatterTest.DefaultMessageFormatter_hasEventId=True.verified.xml

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,8 @@
1+
<log4net:event timestamp="2003-01-04T15:09:26.535+01:00" level="INFO" xmlns:log4net="http://logging.apache.org/log4net/schemas/log4net-events-1.2/">
2+
<log4net:properties>
3+
<log4net:data name="Name" value="World" />
4+
<log4net:data name="EventId.Id" value="1" />
5+
<log4net:data name="EventId.Name" value="EventIdName" />
6+
</log4net:properties>
7+
<log4net:message><![CDATA[Hello World!]]></log4net:message>
8+
</log4net:event>

‎tests/Log4NetTextFormatterTest.MessageFormatterReturningNull.verified.xml

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
<log4net:event timestamp="2003-01-04T15:09:26.535+01:00" level="INFO" xmlns:log4net="http://logging.apache.org/log4net/schemas/log4net-events-1.2/">
2+
<log4net:message><![CDATA[]]></log4net:message>
3+
</log4net:event>

‎tests/Log4NetTextFormatterTest.MessageFormatterThrowing.verified.xml

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
<log4net:event timestamp="2003-01-04T15:09:26.535+01:00" level="INFO" xmlns:log4net="http://logging.apache.org/log4net/schemas/log4net-events-1.2/">
2+
<log4net:message><![CDATA[Hello from Serilog]]></log4net:message>
3+
</log4net:event>

‎tests/Log4NetTextFormatterTest.cs

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,18 @@ public void SettingPropertyFilterToNullThrowsArgumentNullException()
9494
.And.ParamName.Should().Be("filterProperty");
9595
}
9696

97+
[Fact]
98+
public void SettingMessageFormatterToNullThrowsArgumentNullException()
99+
{
100+
// Act
101+
Action action = () => _ = new Log4NetTextFormatter(c => c.UseMessageFormatter(null!));
102+
103+
// Assert
104+
action.Should().ThrowExactly<ArgumentNullException>()
105+
.WithMessage("The message formatter can not be null.*")
106+
.And.ParamName.Should().Be("formatMessage");
107+
}
108+
97109
[Fact]
98110
public void SettingExceptionFormatterToNullThrowsArgumentNullException()
99111
{
@@ -438,6 +450,75 @@ public Task Exception()
438450
return Verify(output);
439451
}
440452

453+
[Theory]
454+
[InlineData(true)]
455+
[InlineData(false)]
456+
public Task DefaultMessageFormatter(bool hasEventId)
457+
{
458+
// Arrange
459+
using var output = new StringWriter();
460+
List<LogEventProperty> properties = [ new("Name", new ScalarValue("World")) ];
461+
if (hasEventId)
462+
{
463+
LogEventProperty[] eventIdProperties = [ new("Id", new ScalarValue(1)), new("Name", new ScalarValue("EventIdName")) ];
464+
properties.Add(new LogEventProperty("EventId", new StructureValue(eventIdProperties)));
465+
}
466+
var logEvent = CreateLogEvent(messageTemplate: "Hello {Name}!", properties: properties.ToArray());
467+
var formatter = new Log4NetTextFormatter();
468+
469+
// Act
470+
formatter.Format(logEvent, output);
471+
472+
// Assert
473+
return Verify(output).UseParameters(hasEventId);
474+
}
475+
476+
[Fact]
477+
public Task CustomMessageFormatter()
478+
{
479+
// Arrange
480+
using var output = new StringWriter();
481+
var logEvent = CreateLogEvent();
482+
var formatter = new Log4NetTextFormatter(options => options.UseMessageFormatter((_, _) => "Custom message"));
483+
484+
// Act
485+
formatter.Format(logEvent, output);
486+
487+
// Assert
488+
return Verify(output);
489+
}
490+
491+
[Fact]
492+
public Task MessageFormatterReturningNull()
493+
{
494+
// Arrange
495+
using var output = new StringWriter();
496+
var logEvent = CreateLogEvent();
497+
var formatter = new Log4NetTextFormatter(options => options.UseMessageFormatter((_, _) => null!));
498+
499+
// Act
500+
formatter.Format(logEvent, output);
501+
502+
// Assert
503+
return Verify(output);
504+
}
505+
506+
[Fact]
507+
public Task MessageFormatterThrowing()
508+
{
509+
// Arrange
510+
using var output = new StringWriter();
511+
var logEvent = CreateLogEvent();
512+
var formatter = new Log4NetTextFormatter(options => options.UseMessageFormatter((_, _) => throw new InvalidOperationException("💥 Boom 💥")));
513+
514+
// Act
515+
formatter.Format(logEvent, output);
516+
517+
// Assert
518+
SelfLogValue.Should().Contain("[Serilog.Formatting.Log4Net.Log4NetTextFormatter] An exception was thrown while formatting a message.");
519+
return Verify(output);
520+
}
521+
441522
[Fact]
442523
public Task ExceptionFormatter()
443524
{

‎tests/PublicApi.net6.0.verified.cs

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -42,9 +42,11 @@ public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UseFormatPr
4242
public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UseIndentationSettings(Serilog.Formatting.Log4Net.IndentationSettings indentationSettings) { }
4343
public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UseLineEnding(Serilog.Formatting.Log4Net.LineEnding lineEnding) { }
4444
public void UseLog4JCompatibility() { }
45+
public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UseMessageFormatter(Serilog.Formatting.Log4Net.MessageFormatter formatMessage) { }
4546
public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UseNoIndentation() { }
4647
public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UseNoXmlNamespace() { }
4748
public Serilog.Formatting.Log4Net.Log4NetTextFormatterOptionsBuilder UsePropertyFilter(Serilog.Formatting.Log4Net.PropertyFilter filterProperty) { }
4849
}
50+
public delegate string MessageFormatter(Serilog.Events.LogEvent logEvent, System.IFormatProvider? formatProvider);
4951
public delegate bool PropertyFilter(Serilog.Events.LogEvent logEvent, string propertyName);
5052
}

0 commit comments

Comments
 (0)