C# Serilog: how to log with String interpolation and keep argument names in message templates?

Question

How to replace this code:

string name = "John";
logger.Information("length of name '{name}' is {nameLength}", name, name.Length);

with C# String interpolation like this or similar

string name = "John";
// :-( lost benefit of structured logging: property names not passed to logger
logger.Information($"length of name '{name}' is {name.Length}");

but keep the property names for structured logging to work?

Benefits would be:

1. Increased readability
2. You'll never forget an argument in arguments list or a property name in message template, especially when you make changes to your logging code
3. You always know what this property name will print to your log

Significancy

Answer 1

Add this file to your project. It has ILogger extension methods VerboseInterpolated(), DebugInterpolated() and so on. There are also unit tests here.

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}");

But be careful: it's all too easy to use the wrong method. If you accidentally use the Serilog's method, for example logger.Debug($"length = {length:propertyNameForLogger}"), it will log length = propertyNameForLogger, so no argument value will be logged. This is due to propertyNameForLogger is format for your value.

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 }}");

Significancy

This makes errors even easier - it's all too easy to use the wrong extension method now. EF Core had the same problem with FromSql - it was all too easy to run an un-parameterized query, allowing SQL injection. That's why EF Core 3.1 replaced this with FromSqlRaw, FromSqlInterpolated and added the Obsolete attribute to the old method – Condition

@PanagiotisKanavos thanks, that's a valid point. I changed the method names to InformationInterpolated, though I can't add the Obsolete attribute. – Significancy

Good idea, I like this one. Did you try to suggest Serilog to implement it into it's core? – Disadvantaged

no, I didn't. Doesn't look like they want to go in this direction @Vočko – Significancy

I don’t understand what is the essential benefit to specify name inside {} $”{name.Length:Length} " compare to manually specifying $” Length:i{name.Length}". Idea to write the variable name only once using anonymous types is attractive, but {new { name.Length }} is too verbose. – Mascon

Instead of using reflection and explicit AnonymousType you can consider LinqExpressions as in my function PropertyNameAndValue github.com/MNF/CommonDotNetHelpers/blob/… – Mascon

I've just published a library (with extension methods to Serilog, NLog, and Microsoft ILogger) that allows writing log messages using interpolated strings and yet defining the property names (based on this same idea of defining names using anonymous objects). Would love to hear some feedback: github.com/Drizin/InterpolatedLogging – Diondione

FWIW, using Expressions to automatically determine the name of a property/variable is much much slower than the other approaches (including the anonymous objects). In my library I've made some benchmarks, if I remember the numbers it looks like expressions were more than 50x slower – Diondione

Answer 2

Thanks for a great idea. I've seen one drawback and that is no support for the generic logger when used with DI. I've extended the @Artemious solution. Please let me know if this is not the correct way to do it.

public static void LogInformationInterpolated<T>(this ILogger<T> logger, FormattableString? message) =>
            WriteInterpolated<T>(logger, null, message, Information);

public static void LogInformationInterpolated<T>(this ILogger<T> logger, Exception? ex, FormattableString? message) =>
            WriteInterpolated<T>(logger, ex, message, Information);

public static void WriteInterpolated<T>(this ILogger<T> logger, Exception? ex, FormattableString? message, Serilog.Events.LogEventLevel logEventLevel)
{
    var contextedLogger = Log.ForContext<T>();
    WriteInterpolated(contextedLogger, ex, message, logEventLevel);
}

The ILogger comes from Microsoft.Extensions.Logging namespace, Serilog doesn't seem to have one. But I'm not an expert in this and thus open to suggestions.

Sublett