NLog logs Error twice in same file

Question

I am trying to figure out why NLog logs my error twice.

here is my config file:

<nlog xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <targets>
    <target name="debug" xsi:type="File" FileName="DebugTestFile.log" layout="${message} ${exception:format=tostring}" />
  </targets>
  <rules>
    <logger name="*" level="Debug" writeTo="debug" />
  </rules>
</nlog>

Now when I call NLog.Debug(myException); the output is my exception gets printed twice.

If I call NLog.Debug(myException, "My Test Message String"); then the error gets printed out once along with my test message.

What exactly am I doing wrong? According to https://github.com/NLog/NLog/wiki/How-to-Log-Exceptions my configuration is correct.

I tried changing my layout to the following: layout="${message} and when I ran NLog.Debug(myException); it only printed the error once.

However now when I ran NLog.Debug(myException, "My Test Message String"); it only printed my message without the error that comes from exception.

Could this be a bug with NLog?

Devolution

This seems to be as designed. You are passing a single argument (your exception) which is being used to satisfy both layout renderers. – Overcheck

@Overcheck But then, if I remove the error from config, I don't get the error printed out when I call the exception, string method. That can't be right, there has to be something I am missing or a bug in the system. – Devolution

@Devolution Did you solve this problem? – Gonadotropin

no I have not, I went with a workaround where I call NLog.Debug(myException, myMessage); which doesn't do that, and my message is an empty string. – Devolution

Answer 1

Updated Answer

NLog.Web.AspNetCore v4.8.6 changes registration of NLog Logging Provider, so one is now allowed to call both AddNLog and UseNLog without experiencing double logging.

NLog 5.0 implements validation of incorrect duplicate target configuration, so one will not experience double logging when using incorrect NLog configuration.

Original Answer

If you are using NLog in AspNetCore, then the problem can be caused by calling UseNLog together with AddNLog or ConfigureNLog.

You should only use UseNLog together with NLog.Web.LogBuilder.ConfigureNLog (Stop using AddNLog):

https://github.com/NLog/NLog/wiki/Getting-started-with-ASP.NET-Core-2#4-update-programcs

Reverent

This was the case for me. – Reglet

Note: AddNLog is for ASP.NET Core 1 and UseNLog for ASP.NET Core 2 + 3 – Namangan

The first part of this is the answer, however there are circumstances that UseNLog shouldn't be used, like when you have a custom implementation of Microsoft ILogger (and you use NLog behind the scene). In that scenario, you would be adding your custom logging provider through loggerFactory.AddProvider in the Asp.Net core pipeline – Imbroglio

@MahdiK.Actually think the answer has become obsolete after these pull-requests have been implemented: github.com/NLog/NLog.Web/pull/459 + github.com/NLog/NLog.Web/pull/485 (Released with NLog.Web.AspNetCore ver. 4.9) – Reverent

Answer 2

This is seems to be because of rule in config file, just change writeTo for each logger, in my case I was able to reolve this issue by following same steps:

Example:

Earlier config file which was having issue:

<rules>
  <logger name="*" minlevel="Info" writeTo="console" />
  <logger name="*" minlevel="Error" writeTo="console" />
</rules>

Corrected config file:

<rules>
  <logger name="*" minlevel="Info" writeTo="console" />
  <logger name="*" minlevel="Error" writeTo="console1" />
</rules>

Olmos

Please note that there is only one rule in my config file – Devolution

Answer 3

NLog Logger-method Error<T>(T value) is shorthand for Error("{0}", value).

This means the ${message} output becomes string.Format("{0}", value) or value.ToString(), which is the original behavior.

NLog have over time tried to improve the handling of Exception-object as value:

• NLog 4.1 - Assign NLog LogEventInfo.Exception so ${exception} works
• NLog 4.5.4 - Assign NLog LogEventInfo.Exception so ${exception} works in more cases
• NLog 4.6 - Changed ${message:withException=true} to only output exception once
• NLog 5.0 - Changed ${message} to only output ex.GetType() + ex.Message - Instead of Exception.ToString()
• NLog 5.0 - Changed default Target Layout to use ${mesage:withException=true} - Instead of ${message}

But yes a workaround is calling Logger.Error(ex, ""), then ${message} will output empty-string "".

Alternative with NLog v4.6 (and newer) then one can use ${message:withException=true} instead of ${message} ${exception:format=tostring}

Reverent