Rick
Rick

Reputation: 139

Controller using ASP.NET Core 6 with NLog appears not to get the correct logger instance via DI

Having an issue getting the correct logger via DI, at least that is what it seems.

Here is the code in Program.cs:

var logger = NLog.LogManager.Setup().LoadConfigurationFromAppSettings().GetCurrentClassLogger();
logger.Info("Service Init");
logger.Info($"  Log Level - Debug: {logger.IsEnabled(NLog.LogLevel.Debug)} Trace: {logger.IsEnabled(NLog.LogLevel.Trace)}");

try
{
  var builder = WebApplication.CreateBuilder(args);

  builder.Logging.ClearProviders();
  //builder.Logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace);
  builder.Host.UseNLog();

  builder.Services.AddControllersWithViews();

  var app = builder.Build();

  app.UseStaticFiles();
  app.UseRouting();

  app.MapControllerRoute(name: "default", pattern: "{controller=Home}/{action=Index}/{id?}");

  app.Run();
}
catch (Exception exc)
{
  // NLog: catch setup errors
  logger.Error(exc, "Stopped program because of exception");
  throw;
}
finally
{
  NLog.LogManager.Shutdown();
}

When I run the app the initial log information (logged to file) shows the correct values for the log level, for example if I set minlog in NLog.config to "Debug" then the value shows true in the log and similarly if I change it to "Trace" the log shows appropriately.

In a controller when I try and log the same information using the below, they are always false:

  _logger.Info($"Log Level - Debug: {_logger.IsEnabled(NLog.LogLevel.Debug)} Trace: {_logger.IsEnabled(NLog.LogLevel.Trace)}");

Additional notes:

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

And more notes:
I commented out the logger in Program.cs and also made use of this to obtain the configuration from appsettings.config. I've also made use of this when I create the instance of logger in Program.cs and so I know the configuration is correct:

Regardless of creating logger instance in Program.cs, when I do a QuickWatch of the logger instance passed into a controller constructor I see the the below. The provider type looks good, NLog, but where it is picking up a configuration I'm at a loss.

QuickWatch of logger instance in controller

Finally, as per a suggestion from Rolf, I add this in Program.cs to see what NLog was doing, unfortunately it didn't given much detail. No configuration information listed:

  NLog.Common.InternalLogger.LogLevel = NLog.LogLevel.Trace;
  NLog.Common.InternalLogger.LogToConsole = true;
  NLog.Common.InternalLogger.LogFile = @"c:\temp\nlog-debug.txt";

The log output looks like this:

2023-01-08 08:58:50.5328 Debug ScanAssembly('NLog, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c')
2023-01-08 08:58:50.6446 Debug ScanAssembly('NLog.Web.AspNetCore, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c')
2023-01-08 08:58:50.6610 Trace Assembly 'NLog.Web.AspNetCore, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c' will be hidden in callsite stacktrace
2023-01-08 08:58:50.9908 Debug Hide assemblies for callsite
2023-01-08 08:58:50.9914 Debug ScanAssembly('NLog.Extensions.Logging, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c')
2023-01-08 08:58:50.9914 Trace Assembly 'NLog.Extensions.Logging, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c' will be hidden in callsite stacktrace
2023-01-08 08:58:50.9914 Trace Assembly 'Microsoft.Extensions.Logging.Abstractions, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60' will be hidden in callsite stacktrace
2023-01-08 08:58:50.9914 Trace Assembly 'Microsoft.Extensions.Logging, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60' will be hidden in callsite stacktrace
2023-01-08 08:58:51.0219 Trace ParseNLogConfig

Upvotes: 0

Views: 2429

Answers (1)

Rick
Rick

Reputation: 139

So I feel like I should delete this post to keep people from chasing down the wrong path ;)

Nevertheless, the solution was simple, and a very dumb mistake on my part. In nlog.config I had something like this:

  <logger name="<MyNameSpace>.*" maxLevel="Info" final="true" />

...where <MyNameSpace> is simply that, the namespace of the project.

I had something similar in another solution but it was less aggressive <MyNameSpace>.<SubNameSpace>.

Basically I was eliminating from the logs junk I didn't want, but I went to far.

Anyway, lesson is be careful with your rule because you will take the "applicable logger" out of the equation leaving you wondering why your logger isn't looking like or performing like you think it should.

Upvotes: 2

Related Questions