Nlog ${event-context:item=xxxx} not writing in logging database

Question

I have a Nlog configuration that is basically this:

<target type="Database" name="database" connectionstring="<working connection string>">
  <commandText>insert into LogEntries ([Username], [Process], [TransactionCode], [WorkplaceId], [CreateDate], [Origin], [LogLevel], [Message], [Exception], [StackTrace]) values (@username, @process, @transactionCode, @workplaceId, @createDate, @origin, @logLevel, @message, @exception, @stackTrace);</commandText>

  <parameter name="@username" layout="${event-context:item=username}"/>
  <parameter name="@process" layout="${event-context:item=process}"/>
  <parameter name="@transactionCode" layout="${event-context:item=transactionCode}"/>
  <parameter name="@workplaceId" layout="${event-context:item=workplaceId}"/>
  <parameter name="@createDate" layout="${date}"/>
  <parameter name="@origin" layout="${callsite}"/>
  <parameter name="@logLevel" layout="${level}"/>
  <parameter name="@message" layout="${message}"/>
  <parameter name="@exception" layout="${exception:format=message}"/>
  <parameter name="@stackTrace" layout="${onexception: ${stacktrace}}"/>
</target>

The logging basically works, and the standard Nlog items are successfully written to the database, but the event-context items are written like empty string in the database.

I already checked the Properties item on the eventInfo object and it is filled correctly.

Anyone an idea on what I am missing? I am out of ideas of what it could be.

Answer 1

As it turned out, it was a bug (or a feature) in NLog. When writing to a 'target' in NLog asynchronously the original LogEventInfo that is written is added to the Parameters collection of a new LogEventInfo, thus the Properties collection where the {event-context} gets its values from is empty (because it is a new object). Resulting in the empty strings written to the database.

So, in order to solve this I added this function to << NLog 2.1 Source >>\Targets\Target.cs:

    private void MergeEventProperties(LogEventInfo logEvent)
    {
        foreach (var item in logEvent.Parameters)
        {
            if (item.GetType() == typeof(LogEventInfo))
            {

                foreach (var propertyItem in ((LogEventInfo)item).Properties)
                {
                    logEvent.Properties.Remove(propertyItem.Key);
                    logEvent.Properties.Add(propertyItem);
                }
            }
        }
    }

Then in the function protected virtual void Write(AsyncLogEventInfo logEvent) I changed this code

        try
        {
            this.Write(logEvent.LogEvent);
            logEvent.Continuation(null);
        }

into this:

        try
        {
            MergeEventProperties(logEvent.LogEvent);

            this.Write(logEvent.LogEvent);
            logEvent.Continuation(null);
        }

After that, my values were written to the database.

I hope it helps other people who are having this issue.

Answer 2

You have to fill in the LogEvent.Properties manually, or else all event-context items will render ''. These are not auto generated

https://github.com/nlog/nlog/wiki/EventProperties-Layout-Renderer

event-context has been changed to event-properties in the NLog documentation

Answer 3

Thanks for the fix. This issue has evolved slightly since your original positing.

After chasing down all the github patches (334, 331, 371) related to this problem and checking that they haven't been reversed, I've discovered that ${event-context:item=x} doesn't seem to work properly anymore but ${event-properties:item=x} does. To be fair they did mention that context is deprecated. So change your NLog.config to use event-properties is my advice.

Oh and I'm on NLog v4.1.0 and NLog.Extended v4.0.0.1 in case this crops up in the future.