From cbcd22bc92f82daafb24a87256ac6f59ce64c1df Mon Sep 17 00:00:00 2001 From: Manuel Rinnhofer Date: Tue, 3 Dec 2024 09:59:10 +0100 Subject: [PATCH 1/6] Add unit tests for OutputTemplateRenderer for new UtcTimestamp token (TDD) Addresses #164 --- .../Output/OutputTemplateRendererTests.cs | 24 +++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs b/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs index 8e5f731..1a07ac0 100644 --- a/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs +++ b/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs @@ -400,4 +400,28 @@ public void TraceAndSpanAreIncludedWhenPresent() formatter.Format(evt, sw); Assert.Equal($"{traceId}/{spanId}", sw.ToString()); } + + [Fact] + public void TimestampTokenRendersLocalTime() + { + var logTimestampWithTimeZoneOffset = DateTimeOffset.Parse("2024-09-03T14:15:16.079+02:00", CultureInfo.InvariantCulture); + var formatter = new OutputTemplateRenderer(ConsoleTheme.None, "{Timestamp:yyyy-MM-dd HH:mm:ss}", CultureInfo.InvariantCulture); + var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Information, null, MessageTemplate.Empty, Array.Empty()); + var sw = new StringWriter(); + formatter.Format(evt, sw); + // expect time in local time, unchanged from the input, the +02:00 offset should not affect the output + Assert.Equal("2024-09-03 14:15:16", sw.ToString()); + } + + [Fact] + public void UtcTimestampTokenRendersUtcTime() + { + var logTimestampWithTimeZoneOffset = DateTimeOffset.Parse("2024-09-03T14:15:16.079+02:00", CultureInfo.InvariantCulture); + var formatter = new OutputTemplateRenderer(ConsoleTheme.None, "{UtcTimestamp:yyyy-MM-dd HH:mm:ss}", CultureInfo.InvariantCulture); + var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Information, null, MessageTemplate.Empty, Array.Empty()); + var sw = new StringWriter(); + formatter.Format(evt, sw); + // expect time in UTC, the +02:00 offset must be applied to adjust the hour + Assert.Equal("2024-09-03 12:15:16", sw.ToString()); + } } \ No newline at end of file From 2c127720d421f8abeb03ce2e50582873659b5b7d Mon Sep 17 00:00:00 2001 From: Manuel Rinnhofer Date: Tue, 3 Dec 2024 10:02:13 +0100 Subject: [PATCH 2/6] Add support for Serilog 4.0 built-in UtcTimestamp token in output template (OutputTemplateRenderer) Implements #164 --- .../SystemConsole/Output/OutputTemplateRenderer.cs | 6 +++++- .../SystemConsole/Output/TimestampTokenRenderer.cs | 11 ++++++++--- 2 files changed, 13 insertions(+), 4 deletions(-) diff --git a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/OutputTemplateRenderer.cs b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/OutputTemplateRenderer.cs index 2f8c743..6e4f561 100644 --- a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/OutputTemplateRenderer.cs +++ b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/OutputTemplateRenderer.cs @@ -68,7 +68,11 @@ public OutputTemplateRenderer(ConsoleTheme theme, string outputTemplate, IFormat } else if (pt.PropertyName == OutputProperties.TimestampPropertyName) { - renderers.Add(new TimestampTokenRenderer(theme, pt, formatProvider)); + renderers.Add(new TimestampTokenRenderer(theme, pt, formatProvider, convertToUtc: false)); + } + else if (pt.PropertyName == OutputProperties.UtcTimestampPropertyName) + { + renderers.Add(new TimestampTokenRenderer(theme, pt, formatProvider, convertToUtc: true)); } else if (pt.PropertyName == OutputProperties.PropertiesPropertyName) { diff --git a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs index 7c4de83..390a337 100644 --- a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs +++ b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs @@ -27,17 +27,22 @@ class TimestampTokenRenderer : OutputTemplateTokenRenderer readonly ConsoleTheme _theme; readonly PropertyToken _token; readonly IFormatProvider? _formatProvider; + readonly bool _convertToUtc; - public TimestampTokenRenderer(ConsoleTheme theme, PropertyToken token, IFormatProvider? formatProvider) + public TimestampTokenRenderer(ConsoleTheme theme, PropertyToken token, IFormatProvider? formatProvider, bool convertToUtc) { _theme = theme; _token = token; _formatProvider = formatProvider; - } + _convertToUtc = convertToUtc; + } public override void Render(LogEvent logEvent, TextWriter output) { - var sv = new DateTimeOffsetValue(logEvent.Timestamp); + var timestamp = _convertToUtc + ? logEvent.Timestamp.ToUniversalTime() + : logEvent.Timestamp; + var sv = new DateTimeOffsetValue(timestamp); var _ = 0; using (_theme.Apply(output, ConsoleThemeStyle.SecondaryText, ref _)) From 5a730233d1963441c522c2ff196b2fee799dad33 Mon Sep 17 00:00:00 2001 From: Manuel Rinnhofer Date: Wed, 4 Dec 2024 22:23:39 +0100 Subject: [PATCH 3/6] Unit test setup streamlined with earlier existing similar test setup --- .../Output/OutputTemplateRendererTests.cs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs b/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs index 1a07ac0..86cead5 100644 --- a/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs +++ b/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs @@ -406,7 +406,8 @@ public void TimestampTokenRendersLocalTime() { var logTimestampWithTimeZoneOffset = DateTimeOffset.Parse("2024-09-03T14:15:16.079+02:00", CultureInfo.InvariantCulture); var formatter = new OutputTemplateRenderer(ConsoleTheme.None, "{Timestamp:yyyy-MM-dd HH:mm:ss}", CultureInfo.InvariantCulture); - var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Information, null, MessageTemplate.Empty, Array.Empty()); + var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Debug, null, + new MessageTemplate(Enumerable.Empty()), Enumerable.Empty()); var sw = new StringWriter(); formatter.Format(evt, sw); // expect time in local time, unchanged from the input, the +02:00 offset should not affect the output @@ -418,7 +419,8 @@ public void UtcTimestampTokenRendersUtcTime() { var logTimestampWithTimeZoneOffset = DateTimeOffset.Parse("2024-09-03T14:15:16.079+02:00", CultureInfo.InvariantCulture); var formatter = new OutputTemplateRenderer(ConsoleTheme.None, "{UtcTimestamp:yyyy-MM-dd HH:mm:ss}", CultureInfo.InvariantCulture); - var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Information, null, MessageTemplate.Empty, Array.Empty()); + var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Debug, null, + new MessageTemplate(Enumerable.Empty()), Enumerable.Empty()); var sw = new StringWriter(); formatter.Format(evt, sw); // expect time in UTC, the +02:00 offset must be applied to adjust the hour From 513456038880ee5f863ad4916192feb7f2d2ebdd Mon Sep 17 00:00:00 2001 From: Manuel Rinnhofer Date: Thu, 5 Dec 2024 00:06:14 +0100 Subject: [PATCH 4/6] Unit tests for OutputTemplateRenderer for UtcTimestamp token enhanced - assert that UtcTimestamp in default format (no custom format string) renders without the +00:00 time-zone suffix. Relates to #164 --- .../Output/OutputTemplateRendererTests.cs | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs b/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs index 86cead5..3297787 100644 --- a/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs +++ b/test/Serilog.Sinks.Console.Tests/Output/OutputTemplateRendererTests.cs @@ -405,25 +405,29 @@ public void TraceAndSpanAreIncludedWhenPresent() public void TimestampTokenRendersLocalTime() { var logTimestampWithTimeZoneOffset = DateTimeOffset.Parse("2024-09-03T14:15:16.079+02:00", CultureInfo.InvariantCulture); - var formatter = new OutputTemplateRenderer(ConsoleTheme.None, "{Timestamp:yyyy-MM-dd HH:mm:ss}", CultureInfo.InvariantCulture); + var formatter = new OutputTemplateRenderer(ConsoleTheme.None, + "Default Format: {Timestamp} / Custom Format String: {Timestamp:yyyy-MM-dd HH:mm:ss}", + CultureInfo.InvariantCulture); var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Debug, null, new MessageTemplate(Enumerable.Empty()), Enumerable.Empty()); var sw = new StringWriter(); formatter.Format(evt, sw); // expect time in local time, unchanged from the input, the +02:00 offset should not affect the output - Assert.Equal("2024-09-03 14:15:16", sw.ToString()); + Assert.Equal("Default Format: 09/03/2024 14:15:16 +02:00 / Custom Format String: 2024-09-03 14:15:16", sw.ToString()); } [Fact] public void UtcTimestampTokenRendersUtcTime() { var logTimestampWithTimeZoneOffset = DateTimeOffset.Parse("2024-09-03T14:15:16.079+02:00", CultureInfo.InvariantCulture); - var formatter = new OutputTemplateRenderer(ConsoleTheme.None, "{UtcTimestamp:yyyy-MM-dd HH:mm:ss}", CultureInfo.InvariantCulture); + var formatter = new OutputTemplateRenderer(ConsoleTheme.None, + "Default Format: {UtcTimestamp} / Custom Format String: {UtcTimestamp:yyyy-MM-dd HH:mm:ss}", + CultureInfo.InvariantCulture); var evt = new LogEvent(logTimestampWithTimeZoneOffset, LogEventLevel.Debug, null, new MessageTemplate(Enumerable.Empty()), Enumerable.Empty()); var sw = new StringWriter(); formatter.Format(evt, sw); // expect time in UTC, the +02:00 offset must be applied to adjust the hour - Assert.Equal("2024-09-03 12:15:16", sw.ToString()); + Assert.Equal("Default Format: 09/03/2024 12:15:16 / Custom Format String: 2024-09-03 12:15:16", sw.ToString()); } } \ No newline at end of file From 4c0dc6f66ca50ba491b8cb5e5c5d044284f0acc0 Mon Sep 17 00:00:00 2001 From: Manuel Rinnhofer Date: Wed, 4 Dec 2024 23:21:05 +0100 Subject: [PATCH 5/6] TimestampTokenRenderer indentation fixed --- .../Output/TimestampTokenRenderer.cs | 48 +++++++++---------- 1 file changed, 24 insertions(+), 24 deletions(-) diff --git a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs index 390a337..599e868 100644 --- a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs +++ b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs @@ -31,10 +31,10 @@ class TimestampTokenRenderer : OutputTemplateTokenRenderer public TimestampTokenRenderer(ConsoleTheme theme, PropertyToken token, IFormatProvider? formatProvider, bool convertToUtc) { - _theme = theme; - _token = token; - _formatProvider = formatProvider; - _convertToUtc = convertToUtc; + _theme = theme; + _token = token; + _formatProvider = formatProvider; + _convertToUtc = convertToUtc; } public override void Render(LogEvent logEvent, TextWriter output) @@ -44,29 +44,29 @@ public override void Render(LogEvent logEvent, TextWriter output) : logEvent.Timestamp; var sv = new DateTimeOffsetValue(timestamp); - var _ = 0; - using (_theme.Apply(output, ConsoleThemeStyle.SecondaryText, ref _)) + var _ = 0; + using (_theme.Apply(output, ConsoleThemeStyle.SecondaryText, ref _)) + { + if (_token.Alignment is null) + { + sv.Render(output, _token.Format, _formatProvider); + } + else { - if (_token.Alignment is null) - { - sv.Render(output, _token.Format, _formatProvider); - } - else - { - var buffer = new StringWriter(); - sv.Render(buffer, _token.Format, _formatProvider); - var str = buffer.ToString(); - Padding.Apply(output, str, _token.Alignment); - } + var buffer = new StringWriter(); + sv.Render(buffer, _token.Format, _formatProvider); + var str = buffer.ToString(); + Padding.Apply(output, str, _token.Alignment); } } + } readonly struct DateTimeOffsetValue { public DateTimeOffsetValue(DateTimeOffset value) { - Value = value; - } + Value = value; + } public DateTimeOffset Value { get; } @@ -80,11 +80,11 @@ public void Render(TextWriter output, string? format = null, IFormatProvider? fo } #if FEATURE_SPAN - Span buffer = stackalloc char[32]; - if (Value.TryFormat(buffer, out int written, format, formatProvider ?? CultureInfo.InvariantCulture)) - output.Write(buffer.Slice(0, written)); - else - output.Write(Value.ToString(format, formatProvider ?? CultureInfo.InvariantCulture)); + Span buffer = stackalloc char[32]; + if (Value.TryFormat(buffer, out int written, format, formatProvider ?? CultureInfo.InvariantCulture)) + output.Write(buffer.Slice(0, written)); + else + output.Write(Value.ToString(format, formatProvider ?? CultureInfo.InvariantCulture)); #else output.Write(Value.ToString(format, formatProvider ?? CultureInfo.InvariantCulture)); #endif From e9c53a775b814ba4552e0b772b8448dca564f00b Mon Sep 17 00:00:00 2001 From: Manuel Rinnhofer Date: Thu, 5 Dec 2024 00:04:09 +0100 Subject: [PATCH 6/6] TimestampTokenRenderer simplified and UtcTimestamp support fixed for standard formating - keep render performance in mind / i.e. keep optimizations from #134 - ensure UtcTimestamp without format string is rendered without " +00:00" suffix by rendering as DateTime (same behavior as Serilog's MessageTemplateTextFormatter) Relates to #164 --- .../Output/TimestampTokenRenderer.cs | 69 ++++++++++++------- 1 file changed, 43 insertions(+), 26 deletions(-) diff --git a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs index 599e868..66bdf4d 100644 --- a/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs +++ b/src/Serilog.Sinks.Console/Sinks/SystemConsole/Output/TimestampTokenRenderer.cs @@ -26,6 +26,7 @@ class TimestampTokenRenderer : OutputTemplateTokenRenderer { readonly ConsoleTheme _theme; readonly PropertyToken _token; + readonly string? _format; readonly IFormatProvider? _formatProvider; readonly bool _convertToUtc; @@ -33,61 +34,77 @@ public TimestampTokenRenderer(ConsoleTheme theme, PropertyToken token, IFormatPr { _theme = theme; _token = token; + _format = token.Format; _formatProvider = formatProvider; _convertToUtc = convertToUtc; } public override void Render(LogEvent logEvent, TextWriter output) { - var timestamp = _convertToUtc - ? logEvent.Timestamp.ToUniversalTime() - : logEvent.Timestamp; - var sv = new DateTimeOffsetValue(timestamp); - var _ = 0; using (_theme.Apply(output, ConsoleThemeStyle.SecondaryText, ref _)) { if (_token.Alignment is null) { - sv.Render(output, _token.Format, _formatProvider); + Render(output, logEvent.Timestamp); } else { var buffer = new StringWriter(); - sv.Render(buffer, _token.Format, _formatProvider); + Render(buffer, logEvent.Timestamp); var str = buffer.ToString(); Padding.Apply(output, str, _token.Alignment); } } } - readonly struct DateTimeOffsetValue + private void Render(TextWriter output, DateTimeOffset timestamp) { - public DateTimeOffsetValue(DateTimeOffset value) + // When a DateTimeOffset is converted to a string, the default format automatically adds the "+00:00" explicit offset to the output string. + // As the TimestampTokenRenderer is also used for rendering the UtcTimestamp which is always in UTC by definition, the +00:00 suffix should be avoided. + // This is done using the same approach as Serilog's MessageTemplateTextFormatter. In case output should be converted to UTC, in order to avoid a zone specifier, + // the DateTimeOffset is converted to a DateTime which then renders as expected. + + var custom = (ICustomFormatter?)_formatProvider?.GetFormat(typeof(ICustomFormatter)); + if (custom != null) { - Value = value; + output.Write(custom.Format(_format, _convertToUtc ? timestamp.UtcDateTime : timestamp, _formatProvider)); + return; } - public DateTimeOffset Value { get; } - - public void Render(TextWriter output, string? format = null, IFormatProvider? formatProvider = null) + if (_convertToUtc) { - var custom = (ICustomFormatter?)formatProvider?.GetFormat(typeof(ICustomFormatter)); - if (custom != null) - { - output.Write(custom.Format(format, Value, formatProvider)); - return; - } + RenderDateTime(output, timestamp.UtcDateTime); + } + else + { + RenderDateTimeOffset(output, timestamp); + } + } + private void RenderDateTimeOffset(TextWriter output, DateTimeOffset timestamp) + { #if FEATURE_SPAN - Span buffer = stackalloc char[32]; - if (Value.TryFormat(buffer, out int written, format, formatProvider ?? CultureInfo.InvariantCulture)) - output.Write(buffer.Slice(0, written)); - else - output.Write(Value.ToString(format, formatProvider ?? CultureInfo.InvariantCulture)); + Span buffer = stackalloc char[32]; + if (timestamp.TryFormat(buffer, out int written, _format, _formatProvider ?? CultureInfo.InvariantCulture)) + output.Write(buffer.Slice(0, written)); + else + output.Write(timestamp.ToString(_format, _formatProvider ?? CultureInfo.InvariantCulture)); #else - output.Write(Value.ToString(format, formatProvider ?? CultureInfo.InvariantCulture)); + output.Write(timestamp.ToString(_format, _formatProvider ?? CultureInfo.InvariantCulture)); +#endif + } + + private void RenderDateTime(TextWriter output, DateTime utcTimestamp) + { +#if FEATURE_SPAN + Span buffer = stackalloc char[32]; + if (utcTimestamp.TryFormat(buffer, out int written, _format, _formatProvider ?? CultureInfo.InvariantCulture)) + output.Write(buffer.Slice(0, written)); + else + output.Write(utcTimestamp.ToString(_format, _formatProvider ?? CultureInfo.InvariantCulture)); +#else + output.Write(utcTimestamp.ToString(_format, _formatProvider ?? CultureInfo.InvariantCulture)); #endif - } } } \ No newline at end of file