Is it possible to use NLog's structured logging without having templated messages?

Question

Until today we have used NLog version 4.4.12 (without structured logging). However we were using https://www.nuget.org/packages/NLog.StructuredLogging.Json/ for structured logging.

The nice thing about using this extension is that you do NOT need to have templated messages (containing indexes or placeholders for your additional parameters/object(s) to log). The message does not contain any indexes or placeholders for your additional objects (i.e. anonymous type) to log.

Switching to NLog 4.6.5 that supports structured logging out of the box we would like to get rid of that additional NuGet package. However our additional parameters are only logged when using templated messages with actual indexed/named placeholders.

Not having index or placeholders in our message does result in NOT having our additional parameters/objects to be rendered out via JSON.

Is it possible to have non-templated messages however still using NLog's structured logging for our additional parameters that have been passed for them to being added in JSON?

Below is an example (please note that we are using an additional wrapper around nlog)

NLog version: 4.6.5

Platform: .Net 4.5

Current NLog config

// Arrange
var typeUsingLogger = typeof(NLogWrapperTest);
var nLogWrapper = new NLogWrapper(typeof(NLogWrapper));

var level = (LogLevel)Enum.Parse(typeof(LogLevel), nLevel.Name);
var message = $"{Guid.NewGuid()}"; // {{extendedLogProperties}}  {{@extendedLogProperties}} {{@purchase}} {{badplaceholder}}
var innerException = new DivideByZeroException("bla inner exception");
var exception = new ArgumentNullException("bla out exception", innerException);
var extendedLogProperties = new
{
    ClientID = 8,
    MyOtherProp = "abc",
    MySubObject = new
    {
        //nested object although not recommended
        A = 123,
        B = "yep"
    }
};

//log configuration
var logConfig = new LoggingConfiguration();

var memoryTarget = new MemoryTarget("MemoryTarget");
var jsonLayout = new JsonLayout
{
    IncludeAllProperties = true,
    Attributes =
    {
            new JsonAttribute("dateTime", "${date:universalTime=true:format=o}" ),
            new JsonAttribute("level", "${level:uppercase=true}" ),
            new JsonAttribute("logger", "${logger}" ),
            new JsonAttribute("message", "${message}" ),
            new JsonAttribute("callsite", "${callsite:className=true:methodName=true:skipFrame=0}" ),
            new JsonAttribute("exception", "${exception:format=ToString:innerFormat=ToString}" ),
            new JsonAttribute("machinename", "${machinename}" ),
            new JsonAttribute("processid", "${processid}" ),
            new JsonAttribute("threadid", "${threadid}" ),
            new JsonAttribute("threadname", "${threadname}" ),
            new JsonAttribute("application", "${application}" ),
            new JsonAttribute("aspnetSessionId", "${aspnet-sessionid}" ),
            new JsonAttribute("iisSiteName", "${iis-site-name}" ),
            new JsonAttribute("stage", "${stage}" ),
    }
};
memoryTarget.Layout = jsonLayout;
logConfig.AddTarget("memoryTarget", memoryTarget);
var memoryTargetLoggingRule = new LoggingRule("*", nLevel, memoryTarget);
logConfig.LoggingRules.Add(memoryTargetLoggingRule);

LogManager.Configuration = logConfig;

// Act
nLogWrapper.Log(level, message, typeUsingLogger, exception, extendedLogProperties);

var jsonLogMsg = memoryTarget.Logs[0];
Assert.Matches("ClientID", jsonLogMsg);

Why do we need it?

• It would be really nice to have the message unchanged without having any replaced indexes or placeholders so that we can search for the exact same message in our logs. (using new JsonAttribute("message", "${message:raw=true}" is not an option)

• Also this way we do not end up in having the JSON serialized objects once in the log message (replacing the templated message's placeholders/indexes) AND the additional JSON fields for these additional parameters.

Please have a look at its best practices: https://github.com/justeat/NLog.StructuredLogging.Json/blob/master/README.md#best-practices

If you ask: "Why don't you continue using the NuGet NLog extension?" The answer is that NLog's structured logging renders out the additional parameters much nicer when using {@placeholder} in templated messages for nested objects.

Edit 1: I would like to have all the properties of my anonymous object to be rendered in the root of the json. Such as:

{
    ...
    "ClientID": 8,
    "MyOtherProp": "abc",
    "MySubObject": {              
                    "A": 123,
                    "B": "yep"
                },
    ...
}

Mew

I'm a bit confused by your (long) "Current NLog config". It's not a config? I would be helpful if you could show the logger call (single line, not nLogWrapper.Log(level, message, typeUsingLogger, exception, extendedLogProperties)) and desired output. – Samarskite

Answer 1

I think your are looking for logger.WithProperty.

Example:

var extendedLogProperties = new
{
    ClientID = 8,
    MyOtherProp = "abc",
    MySubObject = new
    {
        //nested object although not recommended
        A = 123,
        B = "yep"
    }
};

logger.WithProperty("extendedLogProperties", extendedLogProperties).Info("test message");

and you could serialize that to JSON, XML etc.

Example, JSON with all properties

Render all event properties as JSON

config:

 <target xsi:type="File" name="jsonFile" fileName="c:\temp\nlog-json-nested-${shortdate}.log">
     <layout type="JsonLayout">
         <attribute name="time" layout="${longdate}" />
         <attribute name="level" layout="${level}" />
         <attribute name="message" layout="${message}" />
         <attribute name="eventProperties" encode="false" >
             <layout type='JsonLayout' includeAllProperties="true"  maxRecursionLimit="2"/>
         </attribute>
     </layout>
 </target>

Important is here includeAllProperties="true" and maxRecursionLimit="2" (default is 0). See Json Layout docs

This should render (nicely formatted for demo, but will be one one line):

{
    "time": "2019-06-18 11:09:00.2349",
    "level": "Info",
    "message": "test message",
    "eventProperties": {
        "extendedLogProperties": {
            "ClientID": 8,
            "MyOtherProp": "abc",
            "MySubObject": {
                "A": 123,
                "B": "yep"
            }
        }
    }
}

Notes

So to be clear:

The JSON will be written on one line, so no newlines.

Samarskite

Thanks for your answer! However i would like to avoid creating a new logger (by calling WithProperties all the time) as well as i would like to have all anonymous types' fields at the root of the json (so that i can search for them easily with Kibana (ELK)). Sorry for being unclear here. – Mew

i managed to realize it. Thanks @Samarskite for putting me in the right direction – Mew

How get the JSON will be written on multiple line and indent? – Fetid

@Fetid You typically don't do that when logging. You only care about multi-line / indentation when reading the logs. You'd do that by pulling the logs into a JSON viewer that will handle prettifying your JSON for you. – Dissimilar

Answer 2

In my wrapper i managed to realize it like this:

        private void Log(
            NLog.LogLevel nlogLogLevel,
            Logger nlogLogger,
            Type typeUsingLogger,
            string message,
            Exception exception,
            IDictionary<string, object> additionalProperties = null)
        {
            var logEventInfo = new LogEventInfo(nlogLogLevel, typeUsingLogger.ToString(), null, message, new object[] { }, exception);
            if (additionalProperties != null)
            {
                foreach (var x in additionalProperties)
                {
                    if (!logEventInfo.Properties.ContainsKey(x.Key))
                    {
                        logEventInfo.Properties.Add(x.Key, x.Value);
                    }
                }
            }

            nlogLogger.Log(_logWrapperType, logEventInfo);
        }

and setting includeAllProperties to true as well as setting maxRecursionLimit higher (2)

Mew