Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

ILogger not writing TRACE and DEBUG messages to target

I'm working on setting up some logging in our ASP.NET Core 3 application, using ILogger (Microsoft.Extensions.Logging) with NLog to enable writing to text files.

The problem is, that the ILogger does not write TRACE and DEBUG level messages. Either to the text file nor the Visual Studio Output window. Using the NLog.Logger works with all levels. This issue also exists in a default ASP.NET Core 3 Web API application with NLog set up from their official tutorial. Following is the relevant code I have.

Program.cs

public static void Main(string[] args)
{
    var logger = NLog.Web.NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger();
    try
    {
        logger.Trace("NLog Trace from Main()");
        logger.Debug("NLog Debug from Main()");
        logger.Info("NLog Info from Main()");
        logger.Warn("NLog Warn from Main()");
        logger.Error("NLog Error from Main()");
        logger.Fatal("NLog Fatal from Main()");
        CreateHostBuilder(args).Build().Run();
    }
    catch (Exception exception)
    {
        //NLog: catch setup errors
        logger.Error(exception, "Stopped program because of exception");
        throw;
    }
    finally
    {
        // Ensure to flush and stop internal timers/threads before application-exit (Avoid segmentation fault on Linux)
        NLog.LogManager.Shutdown();
    }
}

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
        })
        .ConfigureLogging(options =>
        {
            options.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace);
        }).UseNLog();

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="Info"
      internalLogFile="c:\temp\internal-nlog.txt">

  <!-- enable asp.net core layout renderers -->
  <extensions>
    <add assembly="NLog.Web.AspNetCore"/>
  </extensions>

  <!-- the targets to write to -->
  <targets>
    <!-- write logs to file  -->
    <target xsi:type="File" name="allfile" fileName="c:\temp\nlog-all-${shortdate}.log"
            layout="${longdate}|${event-properties:item=EventId_Id}|${uppercase:${level}}|${logger}|${message} ${exception:format=tostring}" />

    <!-- another file log, only own logs. Uses some ASP.NET core renderers -->
    <target xsi:type="File" name="ownFile-web" fileName="c:\temp\nlog-own-${shortdate}.log"
            layout="${longdate}|${event-properties:item=EventId_Id}|${uppercase:${level}}|${logger}|${message} ${exception:format=tostring}|url: ${aspnet-request-url}|action: ${aspnet-mvc-action}" />
  </targets>

  <!-- rules to map from logger name to target -->
  <rules>
    <!--All logs, including from Microsoft-->
    <logger name="*" minlevel="Trace" writeTo="allfile" />

    <!--Skip non-critical Microsoft logs and so log only own logs-->
    <logger name="Microsoft.*" maxlevel="Info" final="true" /> <!-- BlackHole without writeTo -->
    <logger name="*" minlevel="Trace" writeTo="ownFile-web" />
  </rules>
</nlog>

appsettings.json

{
  "Logging": {
    "LogLevel": {
      "Default": "Trace",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  },
  "AllowedHosts": "*"
}

WeatherForecastController.cs

private readonly ILogger<WeatherForecastController> _logger;

public WeatherForecastController(ILogger<WeatherForecastController> logger)
{
    _logger = logger;
}

[HttpGet]
public IEnumerable<WeatherForecast> Get()
{
    _logger.LogTrace("ILogger LogTrace from WeatherForecastController.");
    _logger.LogDebug("ILogger LogDebug from WeatherForecastController.");
    _logger.LogInformation("ILogger LogInformation from WeatherForecastController.");
    _logger.LogWarning("ILogger LogWarning from WeatherForecastController.");
    _logger.LogError("ILogger LogError from WeatherForecastController.");
    _logger.LogCritical("ILogger LogCritical from WeatherForecastController.");
    var rng = new Random();
    return Enumerable.Range(1, 5).Select(index => new WeatherForecast
    {
        Date = DateTime.Now.AddDays(index),
        TemperatureC = rng.Next(-20, 55),
        Summary = Summaries[rng.Next(Summaries.Length)]
    })
    .ToArray();
}

Output in log file

2020-05-26 09:48:41.2752||TRACE|NLogTest.Program|NLog Trace from Main() |url: |action: 
2020-05-26 09:48:41.3081||DEBUG|NLogTest.Program|NLog Debug from Main() |url: |action: 
2020-05-26 09:48:41.3081||INFO|NLogTest.Program|NLog Info from Main() |url: |action: 
2020-05-26 09:48:41.3081||WARN|NLogTest.Program|NLog Warn from Main() |url: |action: 
2020-05-26 09:48:41.3081||ERROR|NLogTest.Program|NLog Error from Main() |url: |action: 
2020-05-26 09:48:41.3081||FATAL|NLogTest.Program|NLog Fatal from Main() |url: |action: 
2020-05-26 09:48:41.9009||INFO|NLogTest.Controllers.WeatherForecastController|ILogger LogInformation from WeatherForecastController. |url: https://localhost/weatherforecast|action: Get
2020-05-26 09:48:41.9162||WARN|NLogTest.Controllers.WeatherForecastController|ILogger LogWarning from WeatherForecastController. |url: https://localhost/weatherforecast|action: Get
2020-05-26 09:48:41.9162||ERROR|NLogTest.Controllers.WeatherForecastController|ILogger LogError from WeatherForecastController. |url: https://localhost/weatherforecast|action: Get
2020-05-26 09:48:41.9219||FATAL|NLogTest.Controllers.WeatherForecastController|ILogger LogCritical from WeatherForecastController. |url: https://localhost/weatherforecast|action: Get

Now can someone tell me why ILogger isn't writing TRACE and DEBUG messages? I have been Googling this for hours, and as far as I can see everything should be set up properly(?).

Thank you!

like image 943
RonRonDK Avatar asked May 26 '20 08:05

RonRonDK


People also ask

Where does ILogger write to?

ILogger offers provider-based functionality to write to the console, the debug window, the Windows Event Log, to Microsoft Azure Ap Services diagnostics and logs, as well as to the TraceSource and the EventSource.

Does Serilog use ILogger?

NET 6 as a logging provider. Let's set up Serilog as Logging Provider in the native logging system in . NET so you can use the Microsoft ILogger interface.

What is the difference between the ILogger and ILogger T interfaces?

ILogger<T> is derived from ILogger and adds no new functionality. If you're using dependency injection, an instance of ILogger<T> is usually injected into your type T . So, each time you have a constructor that takes an ILogger<T> , you are defining a “component” for your application.

Where does the log file get written to in .NET Core logging?

For example, the Console ILoggerProvider writes the logs to the console. This interface is used to create a custom instance of an ILogger . ILoggerFactory : This interface registers one or more ILoggerProvider instances and provides the CreateLogger() method used to create an instance of ILogger .


1 Answers

As rolf says, if you just debug the asp.net core application by using Visual studio IIS express, you should use appsettings.development.json instead of appsettings.json, since the ASPNETCORE_ENVIRONMENT environment Variables has changed to the Development.

You could find below settings in the launchSettings.json:

  "profiles": {
    "IIS Express": {
      "commandName": "IISExpress",
      "launchBrowser": true,
      "launchUrl": "weatherforecast",
      "environmentVariables": {
        "ASPNETCORE_ENVIRONMENT": "Development"
      }
    },
    "CoreWebAPIIssue": {
      "commandName": "Project",
      "launchBrowser": true,
      "launchUrl": "weatherforecast",
      "applicationUrl": "https://localhost:5001;http://localhost:5000",
      "environmentVariables": {
        "ASPNETCORE_ENVIRONMENT": "Development"
      }
    }
  }

You should modify the appsettings.development.json as below:

{
  "Logging": {
    "LogLevel": {
      "Default": "Trace",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }
}

The result:

enter image description here

like image 144
Brando Zhang Avatar answered Oct 19 '22 11:10

Brando Zhang