From 0fdc163ce34e528b9611883f4c60ab5abe0bde27 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Fri, 26 Jul 2024 10:18:28 +1000 Subject: [PATCH 1/2] Pre-render message when accepting dotted property names --- README.md | 2 +- .../Sinks/Seq/SeqCompactJsonFormatter.cs | 80 ++++++++++--------- .../SeqCompactJsonFormatterTests.cs | 36 ++++++--- 3 files changed, 69 insertions(+), 49 deletions(-) diff --git a/README.md b/README.md index ab5f3e8..70ed47d 100644 --- a/README.md +++ b/README.md @@ -5,7 +5,7 @@ A Serilog sink that writes events to the [Seq](https://datalust.co/seq) structur [Package Logo](https://nuget.org/packages/serilog.sinks.seq) > [!TIP] -> If you would like to see timing and dependency information in Seq, [SerilogTracing](https://github.com/serilog-tracing/serilog-tracing) is a Serilog extension that supports both logs and traces. +> If you would like to see timing and dependency information in Seq, [SerilogTracing](https://github.com/serilog-tracing/serilog-tracing) is a Serilog extension that can send both logs and traces through this sink. ### Getting started diff --git a/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs b/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs index 86a8470..406891a 100644 --- a/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs +++ b/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs @@ -36,43 +36,48 @@ namespace Serilog.Sinks.Seq; /// implicit SerilogTracing span support. public class SeqCompactJsonFormatter: ITextFormatter { - static readonly IDottedPropertyNameConvention DottedPropertyNameConvention = - AppContext.TryGetSwitch("Serilog.Parsing.MessageTemplateParser.AcceptDottedPropertyNames", out var accept) && accept ? - new UnflattenDottedPropertyNames() : - new PreserveDottedPropertyNames(); - - readonly JsonValueFormatter _valueFormatter = new("$type"); + readonly IDottedPropertyNameConvention _dottedPropertyNameConvention; + readonly JsonValueFormatter _valueFormatter; readonly IFormatProvider _formatProvider; - + readonly bool _renderMessages; + + /// Construct a . + /// A value formatter for s on the event. /// An that will be used to render log event tokens. - public SeqCompactJsonFormatter(IFormatProvider? formatProvider = null) + public SeqCompactJsonFormatter(IFormatProvider? formatProvider = null, JsonValueFormatter? valueFormatter = null) { + var acceptDottedPropertyNames = AppContext.TryGetSwitch("Serilog.Parsing.MessageTemplateParser.AcceptDottedPropertyNames", out var accept) && accept; + + _renderMessages = acceptDottedPropertyNames || formatProvider != null && !ReferenceEquals(formatProvider, CultureInfo.InvariantCulture); + + _dottedPropertyNameConvention = acceptDottedPropertyNames ? + new UnflattenDottedPropertyNames() : + new PreserveDottedPropertyNames(); + _formatProvider = formatProvider ?? CultureInfo.InvariantCulture; + _valueFormatter = valueFormatter ?? new("$type"); } /// - /// Format the log event into the output. Subsequent events will be newline-delimited. + /// Format the log event into the output. Successive events will be newline-delimited. /// /// The event to format. /// The output. public void Format(LogEvent logEvent, TextWriter output) { - FormatEvent(logEvent, output, _valueFormatter, _formatProvider); + FormatEvent(logEvent, output); output.WriteLine(); } /// - /// Format the log event into the output. + /// Format the log event into the output, without newline delimiters. /// /// The event to format. /// The output. - /// A value formatter for s on the event. - /// An that will be used to render log event tokens. - public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFormatter valueFormatter, IFormatProvider formatProvider) + public void FormatEvent(LogEvent logEvent, TextWriter output) { if (logEvent == null) throw new ArgumentNullException(nameof(logEvent)); if (output == null) throw new ArgumentNullException(nameof(output)); - if (valueFormatter == null) throw new ArgumentNullException(nameof(valueFormatter)); output.Write("{\"@t\":\""); output.Write(logEvent.Timestamp.UtcDateTime.ToString("O")); @@ -80,35 +85,38 @@ public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFo output.Write("\",\"@mt\":"); JsonValueFormatter.WriteQuotedJsonString(logEvent.MessageTemplate.Text, output); - if (!formatProvider.Equals(CultureInfo.InvariantCulture)) + if (_renderMessages) { // `@m` is normally created during ingestion, however, it must be sent from the client // to honour non-default IFormatProviders output.Write(",\"@m\":"); JsonValueFormatter.WriteQuotedJsonString( - CleanMessageTemplateFormatter.Format(logEvent.MessageTemplate, logEvent.Properties, formatProvider), + CleanMessageTemplateFormatter.Format(logEvent.MessageTemplate, logEvent.Properties, _formatProvider), output); } - - var tokensWithFormat = logEvent.MessageTemplate.Tokens - .OfType() - .Where(pt => pt.Format != null); - - // Better not to allocate an array in the 99.9% of cases where this is false - // ReSharper disable once PossibleMultipleEnumeration - if (tokensWithFormat.Any()) + else { - output.Write(",\"@r\":["); - var delim = ""; - foreach (var r in tokensWithFormat) + var tokensWithFormat = logEvent.MessageTemplate.Tokens + .OfType() + .Where(pt => pt.Format != null); + + // Better not to allocate an array in the 99.9% of cases where this is false + // ReSharper disable once PossibleMultipleEnumeration + if (tokensWithFormat.Any()) { - output.Write(delim); - delim = ","; - var space = new StringWriter(); - r.Render(logEvent.Properties, space, formatProvider); - JsonValueFormatter.WriteQuotedJsonString(space.ToString(), output); + output.Write(",\"@r\":["); + var delim = ""; + foreach (var r in tokensWithFormat) + { + output.Write(delim); + delim = ","; + var space = new StringWriter(); + r.Render(logEvent.Properties, space, _formatProvider); + JsonValueFormatter.WriteQuotedJsonString(space.ToString(), output); + } + + output.Write(']'); } - output.Write(']'); } if (logEvent.Level != LogEventLevel.Information) @@ -167,7 +175,7 @@ public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFo } } - var properties = DottedPropertyNameConvention.ProcessDottedPropertyNames(logEvent.Properties); + var properties = _dottedPropertyNameConvention.ProcessDottedPropertyNames(logEvent.Properties); foreach (var property in properties) { var name = property.Key; @@ -184,7 +192,7 @@ public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFo output.Write(','); JsonValueFormatter.WriteQuotedJsonString(name, output); output.Write(':'); - valueFormatter.Format(property.Value, output); + _valueFormatter.Format(property.Value, output); } output.Write('}'); diff --git a/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs b/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs index 71a5c2c..fa2b055 100644 --- a/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs +++ b/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs @@ -12,6 +12,7 @@ using Serilog.Parsing; using Xunit; // ReSharper disable AccessToDisposedClosure +// ReSharper disable ParameterOnlyUsedForPreconditionCheck.Local namespace Serilog.Sinks.Seq.Tests; @@ -23,7 +24,7 @@ JObject AssertValidJson(Action act, IFormatProvider? formatProvider = n var logger = new LoggerConfiguration() .Destructure.AsScalar() .Destructure.AsScalar() - .WriteTo.TextWriter(new SeqCompactJsonFormatter(formatProvider ?? CultureInfo.InvariantCulture), sw) + .WriteTo.TextWriter(new SeqCompactJsonFormatter(formatProvider), sw) .CreateLogger(); act(logger); logger.Dispose(); @@ -41,23 +42,25 @@ JObject AssertValidJson(Action act, IFormatProvider? formatProvider = n } [Theory] - [InlineData("fr-FR", "31\u202f415,927 19/07/2024 10:00:59 12\u202f345,67 €", "31\u202f415,927", "12\u202f345,67 €")] - [InlineData("en-US", "31,415.927 7/19/2024 10:00:59 AM $12,345.67", "31,415.927", "$12,345.67")] - public void PropertiesFormatCorrectlyForTheFormatProvider( - string cultureName, - string expectedMessage, - string renderedNumber, - string renderedCurrency) + [InlineData("fr-FR")] + [InlineData("en-US")] + public void PropertiesFormatCorrectlyForTheFormatProvider(string cultureName) { + var cultureInfo = new CultureInfo(cultureName); + var number = Math.PI * 10000; var date = new DateTime(2024, 7, 19, 10, 00, 59); var currency = 12345.67M; + + // Culture-specific formatting differs by .NET version (and possibly OS). + var messageBuilder = new StringWriter(cultureInfo); + messageBuilder.Write("{0:n} {1} {2:C}", number, date, currency); + var expectedMessage = messageBuilder.ToString(); - AssertValidJson(log => log.Information("{a:n} {b} {c:C}", number, date, currency), new CultureInfo(cultureName), evt => + AssertValidJson(log => log.Information("{a:n} {b} {c:C}", number, date, currency), cultureInfo, evt => { - Assert.Equal(expectedMessage, evt["@m"]!.ToString()); - Assert.Equal(renderedNumber, evt["@r"]![0]!.ToString()); - Assert.Equal(renderedCurrency, evt["@r"]![1]!.ToString()); + Assert.Equal(expectedMessage, evt["@m"]!.Value()); + Assert.Null(evt["@r"]); }); } @@ -70,6 +73,15 @@ public void MessageNotRenderedForDefaultFormatProvider() }); } + [Fact] + public void MessageNotRenderedForExplicitInvariantCulture() + { + AssertValidJson(log => log.Information("{a}", 1.234), CultureInfo.InvariantCulture, evt => + { + Assert.Null(evt["@m"]); + }); + } + [Fact] public void AnEmptyEventIsValidJson() { From e1336eb601dfbda7843b117220998e9f47027254 Mon Sep 17 00:00:00 2001 From: Nicholas Blumhardt Date: Fri, 26 Jul 2024 10:43:43 +1000 Subject: [PATCH 2/2] Back out message pre-rendering --- .../CleanMessageTemplateFormatter.cs | 146 ------------------ .../Sinks/Seq/Formatting/Padding.cs | 54 ------- .../Sinks/Seq/SeqCompactJsonFormatter.cs | 55 +++---- .../SeqCompactJsonFormatterTests.cs | 43 ++---- 4 files changed, 30 insertions(+), 268 deletions(-) delete mode 100644 src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/CleanMessageTemplateFormatter.cs delete mode 100644 src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/Padding.cs diff --git a/src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/CleanMessageTemplateFormatter.cs b/src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/CleanMessageTemplateFormatter.cs deleted file mode 100644 index d082b35..0000000 --- a/src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/CleanMessageTemplateFormatter.cs +++ /dev/null @@ -1,146 +0,0 @@ -// Copyright © Serilog Contributors -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -using System; -using System.Collections.Generic; -using System.IO; -using Serilog.Events; -using Serilog.Formatting.Json; -using Serilog.Parsing; - -namespace Serilog.Sinks.Seq.Formatting; - -/// -/// Matches the `:lj` clean formatting style now employed by Serilog.Expressions, Serilog.Sinks.Console, and elsewhere. -/// In this mode, strings embedded in message templates are unquoted, and structured data is rendered as JSON. -/// -/// This implementation is derived from the Serilog.Expressions one, sans theming support, and avoiding the -/// extra dependency. In time there should be core Serilog support for this. -static class CleanMessageTemplateFormatter -{ - static readonly JsonValueFormatter SharedJsonValueFormatter = new("$type"); - - public static string Format(MessageTemplate messageTemplate, IReadOnlyDictionary properties, IFormatProvider? formatProvider) - { - var output = new StringWriter(); - - foreach (var token in messageTemplate.Tokens) - { - switch (token) - { - case TextToken tt: - { - output.Write(tt.Text); - break; - } - case PropertyToken pt: - { - RenderPropertyToken(properties, pt, output, formatProvider); - break; - } - default: - { - output.Write(token); - break; - } - } - } - - return output.ToString(); - } - - static void RenderPropertyToken(IReadOnlyDictionary properties, PropertyToken pt, TextWriter output, IFormatProvider? formatProvider) - { - if (!properties.TryGetValue(pt.PropertyName, out var value)) - { - output.Write(pt.ToString()); - return; - } - - if (pt.Alignment is null) - { - RenderPropertyValueUnaligned(value, output, pt.Format, formatProvider); - return; - } - - var buffer = new StringWriter(); - - RenderPropertyValueUnaligned(value, buffer, pt.Format, formatProvider); - - var result = buffer.ToString(); - - if (result.Length >= pt.Alignment.Value.Width) - output.Write(result); - else - Padding.Apply(output, result, pt.Alignment.Value); - } - - static void RenderPropertyValueUnaligned(LogEventPropertyValue propertyValue, TextWriter output, string? format, IFormatProvider? formatProvider) - { - if (propertyValue is not ScalarValue scalar) - { - SharedJsonValueFormatter.Format(propertyValue, output); - return; - } - - var value = scalar.Value; - - if (value == null) - { - output.Write("null"); - return; - } - - if (value is string str) - { - output.Write(str); - return; - } - - if (value is ValueType) - { - if (value is int or uint or long or ulong or decimal or byte or sbyte or short or ushort) - { - output.Write(((IFormattable)value).ToString(format, formatProvider)); - return; - } - - if (value is double d) - { - output.Write(d.ToString(format, formatProvider)); - return; - } - - if (value is float f) - { - output.Write(f.ToString(format, formatProvider)); - return; - } - - if (value is bool b) - { - output.Write(b); - return; - } - } - - if (value is IFormattable formattable) - { - output.Write(formattable.ToString(format, formatProvider)); - return; - } - - output.Write(value); - } -} \ No newline at end of file diff --git a/src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/Padding.cs b/src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/Padding.cs deleted file mode 100644 index c0db3b1..0000000 --- a/src/Serilog.Sinks.Seq/Sinks/Seq/Formatting/Padding.cs +++ /dev/null @@ -1,54 +0,0 @@ -// Copyright © Serilog Contributors -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -using System.IO; -using System.Linq; -using Serilog.Parsing; - -namespace Serilog.Sinks.Seq.Formatting -{ - static class Padding - { - static readonly char[] PaddingChars = Enumerable.Repeat(' ', 80).ToArray(); - - /// - /// Writes the provided value to the output, applying direction-based padding when is provided. - /// - public static void Apply(TextWriter output, string value, Alignment alignment) - { - if (value.Length >= alignment.Width) - { - output.Write(value); - return; - } - - var pad = alignment.Width - value.Length; - - if (alignment.Direction == AlignmentDirection.Left) - output.Write(value); - - if (pad <= PaddingChars.Length) - { - output.Write(PaddingChars, 0, pad); - } - else - { - output.Write(new string(' ', pad)); - } - - if (alignment.Direction == AlignmentDirection.Right) - output.Write(value); - } - } -} \ No newline at end of file diff --git a/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs b/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs index 406891a..22b059f 100644 --- a/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs +++ b/src/Serilog.Sinks.Seq/Sinks/Seq/SeqCompactJsonFormatter.cs @@ -22,8 +22,6 @@ using Serilog.Formatting.Json; using Serilog.Parsing; using Serilog.Sinks.Seq.Conventions; -using Serilog.Sinks.Seq.Formatting; - // ReSharper disable MemberCanBePrivate.Global // ReSharper disable PossibleMultipleEnumeration @@ -39,17 +37,16 @@ public class SeqCompactJsonFormatter: ITextFormatter readonly IDottedPropertyNameConvention _dottedPropertyNameConvention; readonly JsonValueFormatter _valueFormatter; readonly IFormatProvider _formatProvider; - readonly bool _renderMessages; - /// Construct a . + /// + /// Construct a . + /// /// A value formatter for s on the event. /// An that will be used to render log event tokens. public SeqCompactJsonFormatter(IFormatProvider? formatProvider = null, JsonValueFormatter? valueFormatter = null) { var acceptDottedPropertyNames = AppContext.TryGetSwitch("Serilog.Parsing.MessageTemplateParser.AcceptDottedPropertyNames", out var accept) && accept; - _renderMessages = acceptDottedPropertyNames || formatProvider != null && !ReferenceEquals(formatProvider, CultureInfo.InvariantCulture); - _dottedPropertyNameConvention = acceptDottedPropertyNames ? new UnflattenDottedPropertyNames() : new PreserveDottedPropertyNames(); @@ -85,38 +82,26 @@ public void FormatEvent(LogEvent logEvent, TextWriter output) output.Write("\",\"@mt\":"); JsonValueFormatter.WriteQuotedJsonString(logEvent.MessageTemplate.Text, output); - if (_renderMessages) - { - // `@m` is normally created during ingestion, however, it must be sent from the client - // to honour non-default IFormatProviders - output.Write(",\"@m\":"); - JsonValueFormatter.WriteQuotedJsonString( - CleanMessageTemplateFormatter.Format(logEvent.MessageTemplate, logEvent.Properties, _formatProvider), - output); - } - else - { - var tokensWithFormat = logEvent.MessageTemplate.Tokens - .OfType() - .Where(pt => pt.Format != null); + var tokensWithFormat = logEvent.MessageTemplate.Tokens + .OfType() + .Where(pt => pt.Format != null); - // Better not to allocate an array in the 99.9% of cases where this is false - // ReSharper disable once PossibleMultipleEnumeration - if (tokensWithFormat.Any()) + // Better not to allocate an array in the 99.9% of cases where this is false + // ReSharper disable once PossibleMultipleEnumeration + if (tokensWithFormat.Any()) + { + output.Write(",\"@r\":["); + var delim = ""; + foreach (var r in tokensWithFormat) { - output.Write(",\"@r\":["); - var delim = ""; - foreach (var r in tokensWithFormat) - { - output.Write(delim); - delim = ","; - var space = new StringWriter(); - r.Render(logEvent.Properties, space, _formatProvider); - JsonValueFormatter.WriteQuotedJsonString(space.ToString(), output); - } - - output.Write(']'); + output.Write(delim); + delim = ","; + var space = new StringWriter(); + r.Render(logEvent.Properties, space, _formatProvider); + JsonValueFormatter.WriteQuotedJsonString(space.ToString(), output); } + + output.Write(']'); } if (logEvent.Level != LogEventLevel.Information) diff --git a/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs b/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs index fa2b055..8ef87e6 100644 --- a/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs +++ b/test/Serilog.Sinks.Seq.Tests/SeqCompactJsonFormatterTests.cs @@ -5,11 +5,9 @@ using System.Diagnostics; using System.Globalization; using System.IO; -using System.Linq; using Newtonsoft.Json; using Newtonsoft.Json.Linq; using Serilog.Events; -using Serilog.Parsing; using Xunit; // ReSharper disable AccessToDisposedClosure // ReSharper disable ParameterOnlyUsedForPreconditionCheck.Local @@ -18,7 +16,7 @@ namespace Serilog.Sinks.Seq.Tests; public class SeqCompactJsonFormatterTests { - JObject AssertValidJson(Action act, IFormatProvider? formatProvider = null, Action? assert = null) + static JObject AssertValidJson(Action act, IFormatProvider? formatProvider = null, Action? assert = null) { var sw = new StringWriter(); var logger = new LoggerConfiguration() @@ -48,40 +46,21 @@ public void PropertiesFormatCorrectlyForTheFormatProvider(string cultureName) { var cultureInfo = new CultureInfo(cultureName); - var number = Math.PI * 10000; + const double number = Math.PI * 10000; var date = new DateTime(2024, 7, 19, 10, 00, 59); - var currency = 12345.67M; + const decimal currency = 12345.67M; - // Culture-specific formatting differs by .NET version (and possibly OS). - var messageBuilder = new StringWriter(cultureInfo); - messageBuilder.Write("{0:n} {1} {2:C}", number, date, currency); - var expectedMessage = messageBuilder.ToString(); + // Culture-specific formatting differs by .NET version platform. + var expectedNumber = number.ToString("n", cultureInfo); + var expectedCurrency = currency.ToString("C", cultureInfo); AssertValidJson(log => log.Information("{a:n} {b} {c:C}", number, date, currency), cultureInfo, evt => { - Assert.Equal(expectedMessage, evt["@m"]!.Value()); - Assert.Null(evt["@r"]); + Assert.Equal(expectedNumber, evt["@r"]![0]!.Value()); + Assert.Equal(expectedCurrency, evt["@r"]![1]!.Value()); }); } - - [Fact] - public void MessageNotRenderedForDefaultFormatProvider() - { - AssertValidJson(log => log.Information("{a}", 1.234), null, evt => - { - Assert.Null(evt["@m"]); - }); - } - - [Fact] - public void MessageNotRenderedForExplicitInvariantCulture() - { - AssertValidJson(log => log.Information("{a}", 1.234), CultureInfo.InvariantCulture, evt => - { - Assert.Null(evt["@m"]); - }); - } - + [Fact] public void AnEmptyEventIsValidJson() { @@ -150,9 +129,7 @@ public void TraceAndSpanIdsGenerateValidJson() { var traceId = ActivityTraceId.CreateRandom(); var spanId = ActivitySpanId.CreateRandom(); - var evt = new LogEvent(DateTimeOffset.Now, LogEventLevel.Information, null, - new MessageTemplate(Enumerable.Empty()), Enumerable.Empty(), - traceId, spanId); + var evt = new LogEvent(DateTimeOffset.Now, LogEventLevel.Information, null, MessageTemplate.Empty, [], traceId, spanId); var json = AssertValidJson(log => log.Write(evt)); Assert.Equal(traceId.ToHexString(), json["@tr"]); Assert.Equal(spanId.ToHexString(), json["@sp"]);