nreco / logging

Generic file logger for .NET Core (FileLoggerProvider) with minimal dependencies
MIT License
285 stars 56 forks source link

LogDebug does not work #17

Closed evomation closed 2 years ago

evomation commented 3 years ago

Hi,

unfortunately LogDebug does not work.

My configuration:

// appsettings.json
{
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "System": "Debug",
      "Microsoft": "Error"
    },
    "File": {
      "Path": "app.log",
      "Append": "True",
      "FileSizeLimitBytes": 10485760, // 10 * 1024 * 1024 => 10MB
      "MaxRollingFiles": 3 // use to specify max number of log files
    }
  },
  "AllowedHosts": "*"
}
// Startup.cs
services.AddLogging(loggingBuilder => {                
  var loggingSection = Configuration.GetSection("Logging");
  loggingBuilder.AddFile(loggingSection);
});

The calls:

_logger.LogInformation("INFORMATION");
_logger.LogDebug("DEBUG");
_logger.LogWarning("WARN");
_logger.LogCritical("CRIT");
_logger.LogError("ERROR");

The result:

2020-11-27T12:31:36.2114667+01:00   INFO    [My.Controllers.MyController]   [0] INFORMATION
2020-11-27T12:31:36.2345011+01:00   WARN    [My.Controllers.MyController]   [0] WARN
2020-11-27T12:31:36.2375962+01:00   CRIT    [My.Controllers.MyController]   [0] CRIT
2020-11-27T12:31:36.2403344+01:00   FAIL    [My.Controllers.MyController]   [0] ERROR

Does anyone have an idea what I am doing wrong?

VitaliyMF commented 3 years ago

LogDebug definitely works, however it looks like "Default":"Debug" doesn't set default logging level for some reason.

Could you confirm that you see "DEBUG" log message in the console but it is missed in the file?

evomation commented 3 years ago

Hi Vitaliy,

unfortunately, the debug message does not appear in the console. When I use Console.WriteLine("MSG"); the messasge appears in the console.

Some info about my environment:

Even in a new project the debug messaging does not work. Am I missing some settings?

VitaliyMF commented 3 years ago

I mean standard "Console" logging provider here that is added with

loggingBuilder.AddConsole();

Why I'm asking about that: log messages filtering is performed outside concrete logging providers (by the Microsoft.Extensions.Logging infrastructure), and this is out of logging provider control.

However, each logging provider may have it's own 'minimal level'. In case of FileLoggerProvider it is controlled with FileLoggerProvider.MinLevel (default value is 'Information'); also it can be set in 'appsettings.json' with

"File": {
      "LogLevel": "Debug",
      "Path": "app.log",
      "Append": "True",
      "FileSizeLimitBytes": 10485760, // 10 * 1024 * 1024 => 10MB
      "MaxRollingFiles": 3 // use to specify max number of log files
 }
evomation commented 3 years ago

It seems to be a deeper problem, because I don't see debug messages even without your LogProvider. I'm on it and grateful for any help.

evomation commented 3 years ago

I managed to see the messages in output-window (debug-tab):

WebApplication1.Controllers.WeatherForecastController: Information: INFORMATION
WebApplication1.Controllers.WeatherForecastController: Debug: DEBUG
WebApplication1.Controllers.WeatherForecastController: Warning: WARN
WebApplication1.Controllers.WeatherForecastController: Critical: CRIT
WebApplication1.Controllers.WeatherForecastController: Error: ERROR

But there are still missing the log file.

2020-11-30T10:44:05.3937768+01:00   INFO    [WebApplication1.Controllers.WeatherForecastController] [0] INFORMATION
2020-11-30T10:44:05.4020788+01:00   WARN    [WebApplication1.Controllers.WeatherForecastController] [0] WARN
2020-11-30T10:44:05.4046834+01:00   CRIT    [WebApplication1.Controllers.WeatherForecastController] [0] CRIT
2020-11-30T10:44:05.4078748+01:00   FAIL    [WebApplication1.Controllers.WeatherForecastController] [0] ERROR

I changed my appsetting.json to

{
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "Microsoft": "Debug",
      "Microsoft.Hosting.Lifetime": "Debug"
    },
    "Debug": {
      "LogLevel": {
        "Default": "Debug",
        "System": "Debug",
        "Microsoft": "Information"
      }
    },
    "Console": {
      "LogLevel": {
        "Default": "Debug",
        "System": "Debug",
        "Microsoft": "Information"
      }
    },
    "File": {
      "LogLevel": "Debug",
      "Path": "app.log",
      "Append": "True",
      "FileSizeLimitBytes": 10485760, // 10 * 1024 * 1024 => 10MB
      "MaxRollingFiles": 3 // use to specify max number of log files
    }
  },
  "AllowedHosts": "*"
}
VitaliyMF commented 3 years ago

I've just checked the code and it looks like

    "File": {
      "LogLevel": "Debug",
    }

was only for .NET Core 1.x, and in case of .NET Core 2.x and 3.x no way to change a FileLoggerProvider.MinLevel (which is actually 'DEBUG' by default - see https://github.com/nreco/logging/blob/master/src/NReco.Logging.File/FileLoggerProvider.cs).

This means that messages filtering is performed on the infrastructure side. I've just checked this configuration:

services.AddLogging(loggingBuilder => {
  var loggingSection = Configuration.GetSection("Logging");
  loggingBuilder.AddConfiguration(loggingSection);
  loggingBuilder.AddConsole();
  loggingBuilder.AddFile(loggingSection, fileLoggerOpts => {
  });
});
  "Logging": {
    "IncludeScopes": false,
    "LogLevel": {
      "Default": "Debug",
      "System": "Information",
      "Microsoft": "Error"
    },
    "File": {"Path":"app.log"}
  },

and I see debug messages in the file, so I cannot reproduce the issue.

VitaliyMF commented 3 years ago

Sorry, but I don't understand what is the purpose of setting provider.MinValue? Its default value is LogLevel.Debug: https://github.com/nreco/logging/blob/master/src/NReco.Logging.File/FileLoggerProvider.cs so FilterLoggerProvider doesn't filter anything on its side - and normally filtering is performed by the logging infrastructure that takes into account "Logging":"LogLevel" config section (it is NOT intended for reading by the logging provider implementations).

filipemagomes commented 3 years ago

Sorry, but I don't understand what is the purpose of setting provider.MinValue? Its default value is LogLevel.Debug: https://github.com/nreco/logging/blob/master/src/NReco.Logging.File/FileLoggerProvider.cs so FilterLoggerProvider doesn't filter anything on its side - and normally filtering is performed by the logging infrastructure that takes into account "Logging":"LogLevel" config section (it is NOT intended for reading by the logging provider implementations).

You are absolutely right.

I was reading the default value from appsettings.json because the "Trace" level don´t logs anything on file.

Now i change the default value to LogLevel.Trace on FileLoggerProvider, and it's working.