Search code examples
c#asp.netasp.net-corenlog

How to make NLog stop writing redundant information?

My Programm.cs:

var logger = LogManager.Setup()
    .RegisterNLogWeb()
    .LoadConfigurationFromFile("nlog.config")
    .GetCurrentClassLogger();

try
{
    var builder = WebApplication.CreateBuilder(args);
    builder.Services.AddControllers(options => { options.Filters.Add<LogResponseFilterAttribute>(); 
    });
    
    builder.Services.AddScoped<LogResponseFilterAttribute>();

    builder.Logging.ClearProviders();
    builder.Logging.SetMinimumLevel(LogLevel.Information);

    builder.Host.UseNLog();

    var app = builder.Build();

    app.UseHttpsRedirection();

    app.UseAuthorization();

    app.MapControllers();

    app.Run();
}
catch (Exception e)
{
    logger.Error(e, "Stopped program because of exception");
    throw;
}
finally
{
    LogManager.Shutdown();
}

My nlog.config:

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      autoReload="true"
      internalLogLevel="Error"
      throwExceptions="false"
      internalLogFile="c:\logs\internal-log.txt">

    <variable name="iis_sitename" value="${gdc:item=iis_sitename}"/>
    <variable name="logDirectory" value="c:/logs/${iis_sitename}"/>
    <variable name="logSourceName" value="dpc"/>

    <targets async="true">
        <target xsi:type="File"
                name="jsonFile"
                fileName="${logDirectory}/${logSourceName}-${lowercase:${level}}.jsonl"
                archiveFileName="${logDirectory}/archives/${logSourceName}-${lowercase:${level}}_${date:format=yyyy-MM-dd}.jsonl"
                archiveAboveSize="1000240"
                archiveNumbering="Sequence"
                archiveEvery="Day"
                concurrentWrites="true"
                keepFileOpen="true"
                maxArchiveFiles="1"
                encoding="UTF-8">
            <layout xsi:type="JsonLayout"
                    includeAllProperties="true"
                    maxRecursionLimit="2"
                    suppressSpaces="true">
                <attribute name="timestamp" layout="${longdate}"/>
                <attribute name="message" layout="${message}"/>
            </layout>
        </target>
    </targets>

    <rules>
        <logger name="*" minlevel="Info" writeTo="jsonFile" />
    </rules>
</nlog>

How do I call it in an action:

[HttpGet("products")]
    public Task<object?> Get(CancellationToken cancellationToken, [FromQuery] Filter filter)
    {
        _logger.LogInformation("Hello world!");
         ... other stuff
    }

And what I get:

enter image description here

And I'm confused! What is this? Can I have just my "Hello world"? All this smart stuff looks very cool and probably may be used for a new season of "Mr. Robot", but I do not need it! I need just my "Hello world"!

Solution

  • A fundamental concept across all logging libraries is that the Log Severity Level is the primary filter criteria when you specify the verbosity of the logs that you wish to capture.

    In your nlog.config the primary filter for the internal log file is defined by the minlevel attribute, this is the minimal log level to log. In your case you have specified Info, which corresponds to all Information that highlights progress or application lifetime events.

    • As you can see in the log output, there is a lot of smart stuff from the runtime that relates specifically to the lifetime of your http action endpoint.

    This first mechanism you should use to differentiate your logs from standard Info log messages is to use _logger.LogWarning instead of LogInformation in your code. Think of warning to mean, "more important than the standard Information, but less than an Error". Instead of the dictionary interpretation to mean that something might be wrong or you are close to some sort of error threshold or state.

    • Some logging frameworks define a Notice level that is higher than Info but less than Warning that might seem more appropriate but neither MS Logging Extensions nor NLog explicitly support this.

    So knowing that the framework and other system tools will report lifetime events using Info, by default in your application logic you should use LogWarning() to easily differentiate your important messages that are neither Critical nor Error

     _logger.LogWarning("Hello world!");

    Then in your config rules you can specify Warn as the log verbosity:

    <rules>
    <logger name="*" minlevel="Warn" writeTo="jsonFile" />
</rules>

    You can also use Rules that target specific loggers that might be active in your runtime, if you know them. By Convention, internal .Net loggers use the fully qualified class name as the logger name. Knowing this you

    You don't have to guess at the logger name that looks cool, but you think is redundant if you include it as an attribute in your layout

      <layout xsi:type="JsonLayout"
          includeAllProperties="true"
          maxRecursionLimit="2"
          suppressSpaces="true">
      <attribute name="timestamp" layout="${longdate}"/>
      <attribute name="logger" layout="${logger}"/>
      <attribute name="message" layout="${message}"/>
  </layout>

    Then you can specify a different minLevel for loggers that match your name pattern criteria. Since NLog5 we can use finalMinLevel to simplify the syntax for combining logging rules, the following example will only log Warn or higher for common System and Microsoft framework loggers, but still allow Info messages from our application runtime to be captured in the log output.

    <rules>
    <logger name="System.*" finalMinLevel="Warn" />
    <logger name="Microsoft.*" finalMinLevel="Warn" />
    <logger name="Microsoft.Hosting.Lifetime*" finalMinLevel="Warn" />
    <logger name="*" minlevel="Info" writeTo="jsonFile" />
</rules>

    NOTE:
    It is often tempting to silence logs from outside of our application logic using finalMinLevel="None" but this could lead to you missing critical information if your application fails due to external hosting or environmental events. finalMinLevel="Warn" is a conventional standard that means the standard lifetime events will be excluded but any more important information will still be logged.