Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Save artemious7/c7d9856e128a8b2e9e92d096ca0e69ee to your computer and use it in GitHub Desktop.
Save artemious7/c7d9856e128a8b2e9e92d096ca0e69ee to your computer and use it in GitHub Desktop.
C# Serilog: how to log with String interpolation and keep argument names in message templates
#region MIT License
//Copyright(c) 2020 Artemious
// https://gist.github.com/artemious7/c7d9856e128a8b2e9e92d096ca0e69ee/
// https://stackoverflow.com/questions/61816775/c-sharp-serilog-how-to-log-with-string-interpolation-and-keep-argument-names-in/61816776#61816776
//Permission is hereby granted, free of charge, to any person obtaining a copy
//of this software and associated documentation files (the "Software"), to deal
//in the Software without restriction, including without limitation the rights
//to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
//copies of the Software, and to permit persons to whom the Software is
//furnished to do so, subject to the following conditions:
//The above copyright notice and this permission notice shall be included in all
//copies or substantial portions of the Software.
//THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
//IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
//FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
//AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
//LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
//OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
//SOFTWARE.
#endregion
#nullable enable
using System;
using System.Linq;
using System.Reflection;
using System.Text.RegularExpressions;
using static Serilog.Events.LogEventLevel;
namespace Serilog
{
/*
Usage with format string
------
string name = "John";
// add 'Interpolated' to method name: InformationInterpolated() instead of Information()
// add name of the property after the expression. Name is passed to the logger
logger.InformationInterpolated($"length of name '{name:name}' is {name.Length:Length}");
Usage with anonymous types
------
string name = "John";
// add 'Interpolated' to method name: InformationInterpolated() instead of Information()
// create an anonymous object with 'new { propertyName }'.
// It's much slower because of using Reflection, but allows to write the variable name only once.
logger.InformationInterpolated($"length of name '{new { name }}' is {new { name.Length }}");
// you can also specify other property names
logger.InformationInterpolated($"length of name '{new { userName = name }}' is {new { lengthOfName = name.Length }}");
*/
public static class LoggerStringInterpolatedExtensions
{
public static void VerboseInterpolated(this ILogger logger, FormattableString? message) =>
WriteInterpolated(logger, null, message, Verbose);
public static void VerboseInterpolated(this ILogger logger, Exception? ex, FormattableString? message) =>
WriteInterpolated(logger, ex, message, Verbose);
public static void DebugInterpolated(this ILogger logger, FormattableString? message) =>
WriteInterpolated(logger, null, message, Debug);
public static void DebugInterpolated(this ILogger logger, Exception? ex, FormattableString? message) =>
WriteInterpolated(logger, ex, message, Debug);
public static void InformationInterpolated(this ILogger logger, FormattableString? message) =>
WriteInterpolated(logger, null, message, Information);
public static void InformationInterpolated(this ILogger logger, Exception? ex, FormattableString? message) =>
WriteInterpolated(logger, ex, message, Information);
public static void WarningInterpolated(this ILogger logger, FormattableString? message) =>
WriteInterpolated(logger, null, message, Warning);
public static void WarningInterpolated(this ILogger logger, Exception? ex, FormattableString? message) =>
WriteInterpolated(logger, ex, message, Warning);
public static void ErrorInterpolated(this ILogger logger, FormattableString? message) =>
WriteInterpolated(logger, null, message, Error);
public static void ErrorInterpolated(this ILogger logger, Exception? ex, FormattableString? message = null) =>
WriteInterpolated(logger, ex, message, Error);
public static void FatalInterpolated(this ILogger logger, FormattableString? message) =>
WriteInterpolated(logger, null, message, Fatal);
public static void FatalInterpolated(this ILogger logger, Exception? ex, FormattableString? message = null) =>
WriteInterpolated(logger, ex, message, Fatal);
public static void WriteInterpolated(this ILogger logger, Exception? ex, FormattableString? message, Events.LogEventLevel logEventLevel)
{
if (logger is null)
throw new ArgumentNullException(nameof(logger));
if (message is null)
{
logger.Write(logEventLevel, ex, "");
}
else
{
string messageFormat = message.Format;
var matches = Regex.Matches(messageFormat, @"(?<!{){(?<number>\d+)(?<columnFormat>:(?<format>[^}]+))?}(?!})");
Argument[] args = matches.Cast<Match>().Select(match =>
{
int number = int.Parse(match.Groups["number"].Value);
Group formatGroup = match.Groups["format"];
object? propertyValue = message.GetArgument(number);
object? propValue = formatGroup.Success ? propertyValue : ToPropertyValueOrArgument(propertyValue);
string propertyName = formatGroup.Value;
// if argument is anonymous type, take name and value from it's single property
if (propValue is PropertyValue formattableLogPropValue)
{
propertyName = formatGroup.Success ? propertyName : formattableLogPropValue.Name;
propertyValue = formattableLogPropValue.Value;
}
if (propertyName != "")
{
Group columnFormatGroup = match.Groups["columnFormat"];
return new Argument(new PropertyValue(propertyName.TrimStart(), propertyValue), columnFormatGroup.Index, columnFormatGroup.Length);
}
else // no property name specified - return the value itself
{
return new Argument(propValue);
}
})
.ToArray();
for (int i = args.Length - 1; i >= 0; i--)
{
Argument item = args[i];
if (item.RemoveLength > 0)
{
messageFormat = messageFormat.Remove(item.RemoveStart, item.RemoveLength);
}
}
var loggables = args.Select(r => r.Value).ToArray();
messageFormat = messageFormat.Replace("{{", "{{{{").Replace("}}", "}}}}");
string messageTemplate = string.Format(messageFormat, args: loggables);
object?[] propertyValues = loggables.OfType<PropertyValue>()
.Select(pv => pv.Value)
.ToArray();
logger.Write(logEventLevel, ex, messageTemplate, propertyValues: propertyValues);
}
}
private static object? ToPropertyValueOrArgument(object? arg)
{
ToPropertyValueOrArgument(arg, out bool isPropertyValue, out PropertyValue propertyValue);
return isPropertyValue ? propertyValue : arg;
}
private static void ToPropertyValueOrArgument(object? argument, out bool isPropertyValue, out PropertyValue propertyValue)
{
if (argument is null)
{
isPropertyValue = false;
propertyValue = default;
return;
}
Type argumentType = argument.GetType();
if (!argumentType.Name.StartsWith("<>f__AnonymousType"))
{
isPropertyValue = false;
propertyValue = default;
return;
}
var propertyInfos = argumentType.GetTypeInfo().DeclaredProperties.ToArray();
if (propertyInfos.Length != 1)
{
throw new ArgumentException($"Anonymous type properties must have only one property. To make Serilog serialize this anonymous object, specify it's name as format string, e.g.: Log.{nameof(InformationInterpolated)}($\"user name is {{new {{ FirstName = \"John\", LastName = \"Johnson\" }}:userName}}\")");
}
PropertyInfo property = propertyInfos[0];
object? value = property.GetValue(argument);
isPropertyValue = true;
propertyValue = new PropertyValue(property.Name, value);
}
private readonly struct Argument
{
public Argument(object? value, int removeStart = 0, int removeLength = 0) =>
(Value, RemoveStart, RemoveLength) = (value, removeStart, removeLength);
public int RemoveStart { get; }
public int RemoveLength { get; }
public object? Value { get; }
}
private readonly struct PropertyValue : IFormattable
{
public PropertyValue(in string name, object? value) =>
(Name, Value, valueIsObject) = (name, value, Convert.GetTypeCode(value) == TypeCode.Object);
private readonly bool valueIsObject;
public string Name { get; }
public object? Value { get; }
public override string ToString() => ToString(null, null);
public string ToString(string? format, IFormatProvider? formatProvider) =>
$"{{{(valueIsObject ? "@" : "")}{Name}{(string.IsNullOrEmpty(format) ? "" : ":")}{format}}}";
}
}
}
#region MIT License
//Copyright(c) 2020 Artemious
// https://gist.github.com/artemious7/c7d9856e128a8b2e9e92d096ca0e69ee/
// https://stackoverflow.com/questions/61816775/c-sharp-serilog-how-to-log-with-string-interpolation-and-keep-argument-names-in/61816776#61816776
//Permission is hereby granted, free of charge, to any person obtaining a copy
//of this software and associated documentation files (the "Software"), to deal
//in the Software without restriction, including without limitation the rights
//to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
//copies of the Software, and to permit persons to whom the Software is
//furnished to do so, subject to the following conditions:
//The above copyright notice and this permission notice shall be included in all
//copies or substantial portions of the Software.
//THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
//IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
//FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
//AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
//LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
//OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
//SOFTWARE.
#endregion
using Serilog;
using FluentAssertions;
using System;
using Xunit;
using Serilog.Sinks.TestCorrelator;
namespace UnitTests
{
public sealed class LoggerStringInterpolatedTests
{
[Fact]
public void LoggerTest_TestFrameworkMethod()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.Information("My log message!");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("My log message!");
}
}
[Fact]
public void LoggerTest_TestFrameworkMethod_WithCurlyBrackets()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.Information("{{My}} log message!");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("{{My}} log message!");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("{My} log message!");
}
}
[Fact]
public void LoggerTest_TestFrameworkMethod_AnonymousType_1Property()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.Information("value1 = {value1}", new { property1 = "some_value1" });
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be(@"value1 = ""{ property1 = some_value1 }""");
}
}
[Fact]
public void LoggerTest_TestFrameworkMethod_AnonymousType_2Properties()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.Information("value1 = {@value1}", new { property1 = "some_value1", property2 = "some_value2" });
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {@value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be(@"value1 = { property1: ""some_value1"", property2: ""some_value2"" }");
}
}
[Fact]
public void LoggerTest_NoArgs()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"My log message!");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("My log message!");
}
}
[Fact]
public void LoggerTest_IntArg()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {1914:value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = 1914");
}
}
[Fact]
public void LoggerTest_IntArg_TrimStartPropertyName()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {1914: \nvalue1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = 1914");
}
}
[Fact]
public void LoggerTest_IntArg_CurlyBrackets()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"{{1:something}} = {1914:value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("{{1:something}} = {value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("{1:something} = 1914");
}
}
[Fact]
public void LoggerTest_IntArgWithFormat()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {1914:value1:d5}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1:d5}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = 01914");
}
}
[Fact]
public void LoggerTest_IntArgWithFormat2()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {1914:value1:d5:e}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1:d5:e}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = d5:e");
}
}
[Fact]
public void LoggerTest_AnonymousTypeArgs()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
string value1 = "some_value1";
logger.InformationInterpolated($"value1 = {new { value1 }}; value2 = {new { value2 = "some_value2" }}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1}; value2 = {value2}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be(@"value1 = ""some_value1""; value2 = ""some_value2""");
}
}
[Fact]
public void LoggerTest_AnonymousTypeArgs_With2Properties_Throws()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
string value1 = "some_value1";
Assert.Throws<ArgumentException>(() => logger.InformationInterpolated($"value1 = {new { value1, value2 = 1914 }}"));
}
}
[Fact]
public void LoggerTest_PlainValue()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
string value1 = "plain value";
logger.InformationInterpolated($"value1 = {value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = plain value");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = plain value");
}
}
[Fact]
public void LoggerTest_PlainValue_And_AnonymousTypeArg_And_FormatArg()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
string value1 = "plain value";
logger.InformationInterpolated($"value1 = {value1}; value2 = {new { value2 = "some_value2" }}; value3 = {3:value3}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = plain value; value2 = {value2}; value3 = {value3}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be(@"value1 = plain value; value2 = ""some_value2""; value3 = 3");
}
}
[Fact]
public void LoggerTest_PlainValue_Null()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {null}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = ");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = ");
}
}
[Fact]
public void LoggerTest_FormatArg_Null()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {null:value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {value1}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be("value1 = null");
}
}
[Fact]
public void LoggerTest_AnonymousType_NameComesFromFormat_1Property()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {new { value2 = "some_value2" }:otherNameForValue2}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {@otherNameForValue2}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be(@"value1 = { value2: ""some_value2"" }");
}
}
[Fact]
public void LoggerTest_AnonymousType_NameComesFromFormat_2Properties()
{
var logger = Build();
using (TestCorrelator.CreateContext())
{
logger.InformationInterpolated($"value1 = {new { value2 = "some_value2", value3 = "some_value3" }:otherNameForValue2}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.MessageTemplate.Text
.Should().Be("value1 = {@otherNameForValue2}");
TestCorrelator.GetLogEventsFromCurrentContext()
.Should().ContainSingle()
.Which.RenderMessage()
.Should().Be(@"value1 = { value2: ""some_value2"", value3: ""some_value3"" }");
}
}
private ILogger Build()
{
return Log.Logger = new LoggerConfiguration().WriteTo.Sink(new TestCorrelatorSink()).CreateLogger();
}
}
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment