Search code examples
.netloggingnlogasp.net-core-logging

NLog replaces parameters out of order when using String.Format style


I'm new to NLog and had some confusing output so I ran a test.

_logger.LogInformation(string.Format("{2} {1} {0}", "broken", "nlog", "is"));
_logger.LogInformation("{2} {1} {0}", "broken", "nlog", "is");

Which resulted in:

is nlog broken
broken nlog is

Is NLog not expected to work just like String.Format when using String.Format style replacements?

It appears to replace the values in order without regard to the number. I did try a test with "{0} {0} {0}" as the format string and it didn't get logged which leads me to believe it does pay some level of attention to the values. It also leads me to believe that NLog doesn't pass off the handling to String.Format because String.Format will happily replace each of those with the first argument.

In case it matters, we are using NLog to write to SQL Server.


Solution

  • As Rolf mentioned, when using Microsoft Extension Logging, the parsing is done by Microsoft Extension Logging. (by default because of performance)

    Microsoft Extension Logging has no support for string-formatted message but only structured message. So {2} {1} and {0} will be parsed as names (from left to right)

    It would be more logical to log this:

    _logger.LogInformation("User {User} orders {OrderId}", username, order.Id);
    

    If you really like string-formatted messages then you could do:

    1. Use NLog directly,

      var logger = LogManager.GetCurrentClassLogger();
      logger.Info("User {1} orders {0}", order.Id, username);
      
    2. Or, enable "ParseMessageTemplates" in NLogProviderOptions, see https://github.com/NLog/NLog.Extensions.Logging/wiki/NLog-LoggerProvider-Options