Skip to content

NLog properties with Microsoft Extension Logging

Rolf Kristensen edited this page Jan 24, 2022 · 35 revisions

The official extension methods in Microsoft Extension Logging does not provide any obvious way to provide custom NLog properties.

But there are still different options available:

Message Templates

NLog 4.5 supports properties captured from structured logging message templates:

_logger.LogDebug("Logon from {userid}", request.UserId);

These properties can then be extracted using the ${event-properties} renderer. Or using the available JsonLayout, XmlLayout or Log4jLayout

BeginScope

NLog.Extensions.Logging ver. 1.0 supports async properties captured from the BeginScope input parameter:

using (_logger.BeginScope(new[] { new KeyValuePair<string, object>("userid", request.UserId) }))
{
   _logger.LogDebug("Logon from {0}", request.UserId);
}

These async properties can then be extracted using the ${mdlc} renderer

Notice with BeginScope then ${ndlctiming} can be used to extract the timespan from scope was started and logevent was made. This can be used for showing current duration of the active request.

Notice with .NET5 then Microsoft have started using System.Diagnostics.Activity.Current for context-state instead of BeginScope. If you have legacy code that depend on the old way, then NLog can simulate it by setting NLogProviderOptions.IncludeActivityIdsWithBeginScope to true.

Log<TState> Simple

Microsoft Extension Logging can log any kind of TState-object, when using the direct Log-method instead of the extension methods.

NLog.Extensions.Logging ver. 1.0 will attempt to cast the TState-object into IEnumerable<KeyValuePair<string, object>>, and if successful then include them as NLog LogEventInfo.Properties.

This can be used to create a custom logevent object that contains both a message and properties.

class MyLogEvent : IEnumerable<KeyValuePair<string, object>>
{
    List<KeyValuePair<string, object>> _properties = new List<KeyValuePair<string, object>>();

    public string Message { get; }
                
    public MyLogEvent(string message)
    {
        Message = message;
    }

    public IEnumerator<KeyValuePair<string, object>> GetEnumerator()
    {
        return _properties.GetEnumerator();
    }

    IEnumerator IEnumerable.GetEnumerator() { return GetEnumerator(); }

    public MyLogEvent WithProperty(string name, object value)
    {
        _properties.Add(new KeyValuePair<string, object>(name, value));
        return this;
    }

    public static Func<MyLogEvent, Exception, string> Formatter { get; } = (l, e) => l.Message;
}

_logger.Log( Microsoft.Extensions.Logging.LogLevel.Debug,
             default(EventId),
             new MyLogEvent($"Logon from {request.UserId}").WithProperty("userid", request.UserId),
             (Exception)null,
             MyLogEvent.Formatter );

These properties can then be extracted using the ${event-properties} renderer.

Log<TState> Advanced

Combines structured logging message template with additional properties. It wraps the message formatter from Microsoft Extension Logging, and allows injection of extra properties:

public class MyLogEvent2 : Microsoft.Extensions.Logging.ILogger, IReadOnlyList<KeyValuePair<string, object>>
{
    readonly string _format;
    readonly object[] _parameters;
    IReadOnlyList<KeyValuePair<string, object>> _logValues;
    List<KeyValuePair<string, object>> _extraProperties;

    public MyLogEvent2(string format, params object[] values)
    {
        _format = format;
        _parameters = values;
    }

    public MyLogEvent2 WithProperty(string name, object value)
    {
        var properties = _extraProperties ?? (_extraProperties = new List<KeyValuePair<string, object>>());
        properties.Add(new KeyValuePair<string, object>(name, value));
        return this;
    }

    public IEnumerator<KeyValuePair<string, object>> GetEnumerator()
    {
        if (MessagePropertyCount == 0)
        {
            if (ExtraPropertyCount > 0)
                return _extraProperties.GetEnumerator();
            else
                return System.Linq.Enumerable.Empty<KeyValuePair<string, object>>().GetEnumerator();
        }
        else
        {
            if (ExtraPropertyCount > 0)
                return System.Linq.Enumerable.Concat(_extraProperties, LogValues).GetEnumerator();
            else
                return LogValues.GetEnumerator();
        }
    }

    IEnumerator IEnumerable.GetEnumerator()
    {
        return GetEnumerator();
    }

    public KeyValuePair<string, object> this[int index]
    {
        get
        {
            int extraCount = ExtraPropertyCount;
            if (index < extraCount)
            {
                return _extraProperties[index];
            }
            else
            {
                return LogValues[index - extraCount];
            }
        }
    }

    public int Count => MessagePropertyCount + ExtraPropertyCount;

    public override string ToString() => LogValues.ToString();

    private IReadOnlyList<KeyValuePair<string, object>> LogValues
    {
        get
        {
            if (_logValues == null)
                Microsoft.Extensions.Logging.LoggerExtensions.LogDebug(this, _format, _parameters);
            return _logValues;
        }
    }

    private int ExtraPropertyCount => _extraProperties?.Count ?? 0;

    private int MessagePropertyCount
    {
        get
        {
            if (LogValues.Count > 1 && !string.IsNullOrEmpty(LogValues[0].Key) && !char.IsDigit(LogValues[0].Key[0]))
                return LogValues.Count;
            else
                return 0;
        }
    }

    void Microsoft.Extensions.Logging.ILogger.Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
    {
        _logValues = state as IReadOnlyList<KeyValuePair<string, object>> ?? Array.Empty<KeyValuePair<string, object>>();
    }

    bool Microsoft.Extensions.Logging.ILogger.IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel)
    {
        return true;
    }

    IDisposable Microsoft.Extensions.Logging.ILogger.BeginScope<TState>(TState state)
    {
        throw new NotSupportedException();
    }

    public static Func<MyLogEvent2, Exception, string> Formatter { get; } = (l, e) => l.LogValues.ToString();
}

_logger.Log( Microsoft.Extensions.Logging.LogLevel.Debug,
             default(EventId),
             new MyLogEvent2("Logon from {userid}", request.UserId).WithProperty("ipaddress", request.IpAddress),
             (Exception)null,
             MyLogEvent2.Formatter );

The properties can then be extracted using the ${event-properties} renderer.

Clone this wiki locally