5

Objective: To dynamically select which HTTP request I want verbose logging (different log level).

Overview: I have a ASP.Net core 2.1 web server running and once in production, if I need to debug an issue I want to be able to change the log level. I have found how to globally change the log level; however, changing the log level is persistent... aka, does not reset after each call to my controller.

    [HttpGet]
    public async Task<IEnumerable<string>> Get()
    {
        this.Logger.LogTrace("This should NOT get logged");
        SetMinLogLevel(LogLevel.Trace);
        this.Logger.LogTrace("This should be logged");

        return new string[] { "value1", "value2" };
    }

   public static void SetMinLogLevel(LogLevel NewLogLevel)
    {
        foreach (var rule in LogManager.Configuration.LoggingRules)
        {
            rule.EnableLoggingForLevel(NewLogLevel);
        }

        //Call to update existing Loggers created with GetLogger() or 
        //GetCurrentClassLogger()
        LogManager.ReconfigExistingLoggers();
    }

I want the requester to be able set a flag in their HTTP request (header or cookie) to enable a more verbose level of logging per request. That way I do not flood my logs with detailed logs from their requester.

Question: How to I dynamically set the Log Level per logger instance? (I believe that is the correct wording)

I am currently using NLog package 4.5.

MATTHEW
  • 131
  • 1
  • 3
  • 7
  • There is nothing that will make that work out of the box, and the logging system is not really built in a way that you can make this work easily. You could maybe roll your own logger implementation, but that will be quite some work. – poke Aug 08 '18 at 21:40
  • ok, thanks! I was searching to web and had a hard time finding anything – MATTHEW Aug 09 '18 at 12:13
  • This is not easy to do. You will have to wrap all logger instances with a wrapper which knows how to figure out the request's logging level, because within the scope of your request, multiple loggers can be used in different parts of your app. Among those, you usually have singleton parts so you will be looking at accessing scoped data from static context, which usually involves manipulating async context/HTTP context etc. What are the problems you try to solve? It feels like the logging level isn't the real problem here. – weichch Nov 27 '20 at 03:48

4 Answers4

1

We know NLog 4.6.7 added support for using NLog Layout like ${gdc:globalLevel} to dynamically change level attributes at runtime. And the Better solution is to upgrade your NLog if it is possible.

Update: New solution I tried this code on version 4.5 and it works fine. It seems you don't need to upgrade your NLog version. In this case, all the configurations set programmatically. You can send your desired level in the header as loglevel. If you send loglevel in the header, it will be used. Otherwise, logLevel will be Error. See here, please.

Notice: Just use using NLog;. You don't need using Microsoft.Extensions.Logging;

[Route("api/[controller]/[action]")]
    [ApiController]
    public class HomeController : ControllerBase
    {
        private readonly Logger _log = LogManager.GetCurrentClassLogger();

        [HttpGet]
        public async Task<IEnumerable<string>> Get()
        {
            var requestLogLevel = Request.Headers.SingleOrDefault(x => x.Key == "loglevel");
            LogLevel logLevel = LogLevel.Error;
            switch (requestLogLevel.Value.ToString().ToLower())
            {
                case "trace":
                    logLevel = LogLevel.Trace;
                    break;
                case "debug":
                    logLevel = LogLevel.Debug;
                    break;
                case "info":
                    logLevel = LogLevel.Info;
                    break;
                case "warn":
                case "warning":
                    logLevel = LogLevel.Warn;
                    break;
                case "error":
                    logLevel = LogLevel.Error;
                    break;
                case "fatal":
                    logLevel = LogLevel.Fatal;
                    break;
            }

            var config = new NLog.Config.LoggingConfiguration();
            var defaultMode = new NLog.Targets.FileTarget("defaultlog") { FileName = "log.txt" };
            config.AddRule(logLevel, LogLevel.Fatal, defaultMode);
            NLog.LogManager.Configuration = config;

            _log.Trace("Some logs");

            return new string[] { "value1", "value2" };
        }
    }

Solution 1) Upgrade NLog to 4.6.7 or later:

var config = new NLog.Config.LoggingConfiguration();

// Targets where to log to: File and Console
var logfile = new NLog.Targets.FileTarget("logfile") { FileName = "file.txt" };
var logconsole = new NLog.Targets.ConsoleTarget("logconsole");
            
// Rules for mapping loggers to targets            
config.AddRule(LogLevel.Info, LogLevel.Fatal, logconsole);
config.AddRule(LogLevel.Debug, LogLevel.Fatal, logfile);
            
// Apply config           
NLog.LogManager.Configuration = config;

Solution 2) Change the configuration file programmatically: Because your version of NLog doesn't support change configuration automatically, we are going to change it programmatically:

[Route("api/[controller]/[action]")]
[ApiController]
public class HomeController : ControllerBase
{
    private readonly Logger _log = LogManager.GetCurrentClassLogger();

    // Special Authorization needed
    public bool ChangeToDebugMode()
    {
        try
        {
            XmlDocument doc = new XmlDocument();
            doc.Load(AppDomain.CurrentDomain.BaseDirectory +  "nlog.config");
            XmlNode root = doc.DocumentElement;
            XmlNode myNode = root["include"].Attributes["file"];
            myNode.Value = "debugmode.config";
            doc.Save(AppDomain.CurrentDomain.BaseDirectory + "nlog.config");
        }
        catch (Exception)
        {
            return false;
        }

        return true;
    }

    // Special Authorization needed
    public bool RestToDefault()
    {
        try
        {
            XmlDocument doc = new XmlDocument();
            doc.Load(AppDomain.CurrentDomain.BaseDirectory + "nlog.config");
            XmlNode root = doc.DocumentElement;
            XmlNode myNode = root["include"].Attributes["file"];
            myNode.Value = "defaultmode.config";
            doc.Save(AppDomain.CurrentDomain.BaseDirectory + "nlog.config");
        }
        catch (Exception)
        {
            return false;
        }

        return true;
    }

    [HttpGet]
    public async Task<IEnumerable<string>> Get()
    {
        _log.Trace("Some logs");

        return new string[] { "value1", "value2" };
    }
}

In this case, you need some change in your config file. You need to add autoReload=true to configuration. Now, when any configuration change, NLog automatically reload the configuration and you don't need to restart the application. You need to take a look at autoReload and include here

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">
  <include file="defaultmode.config" />
</nlog>

defaultmode.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">

  <targets>
    <target name="logfile" xsi:type="File" fileName="file.txt" />
  </targets>

  <rules>
    <logger name="*" minlevel="Debug" writeTo="logfile" />
  </rules>
  <!-- ... -->
</nlog>

debugmode.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">

  <targets>
    <target name="logfile" xsi:type="File" fileName="file.txt" />
  </targets>

  <rules>
    <logger name="*" minlevel="Trace" writeTo="logfile" />
  </rules>
  <!-- ... -->
</nlog>

I made two other config files. debugmode.config and defaultmode.config. By default in nlog.config file, deafultmode.config is included. When ChangeToDebugMode is called, it changes to debugmode.config and when RestToDefault is called, it changes to defaultmode.config. I used include and separate configuration into two files just for simlicity.

Solution 3) Based on your question: In this case, I used the code that you provided in your question. If you send the log level in your request header, it will be considered. If you don't send, it will use the default value that you set in the configuration. Thus, you don't need to change your application on the client-side. It works fine. Just send your desired log level when you are debugging.

[Route("api/[controller]/[action]")]
[ApiController]
public class HomeController : ControllerBase
{
    private readonly Logger _log = LogManager.GetCurrentClassLogger();

    [HttpGet]
    public async Task<IEnumerable<string>> Get()
    {
        var requestLogLevel = Request.Headers.SingleOrDefault(x => x.Key == "loglevel");
        LogLevel logLevel = LogLevel.Error;
        switch (requestLogLevel.Value.ToString().ToLower())
        {
            case "trace":
                logLevel = LogLevel.Trace;
                break;
            case "debug":
                logLevel = LogLevel.Debug;
                break;
            case "info":
                logLevel = LogLevel.Info;
                break;
            case "warn":
            case "warning":
                logLevel = LogLevel.Warn;
                break;
            case "error":
                logLevel = LogLevel.Error;
                break;
            case "fatal":
                logLevel = LogLevel.Fatal;
                break;
        }
        SetMinLogLevel(logLevel);               

        _log.Trace("Some logs.");

        return new string[] { "value1", "value2" };
    }

    public static void SetMinLogLevel(LogLevel NewLogLevel)
    {
        foreach (var rule in LogManager.Configuration.LoggingRules)
        {
            rule.EnableLoggingForLevel(NewLogLevel);
        }

        //Call to update existing Loggers created with GetLogger() or 
        //GetCurrentClassLogger()
        LogManager.ReconfigExistingLoggers();
    }
}

The problem is, this situation needs to send the log level every time. In these screenshots, you see how to send log level in debugging mode. The Postman result

output text file

Saeid Amini
  • 1,313
  • 5
  • 16
  • 26
0

NLog 4.6.7 allows you to use Layouts in loggingrules filters for minLevel / maxLevel

You can have a NLog-Config-Variable with default loglevel, and then create a hidden method on your web-app that modifies the NLog-Config-Variable and calls ReconfigExistingLoggers().

Then setup a Timer that restores that NLog-Config-Variable to its orignal value after 30 secs. And also calls ReconfigExistingLoggers().

See also: https://github.com/NLog/NLog/wiki/Filtering-log-messages#semi-dynamic-routing-rules

See also: https://github.com/NLog/NLog/wiki/Environment-specific-NLog-Logging-Configuration

Rolf Kristensen
  • 17,785
  • 1
  • 51
  • 70
  • This doesn't seem to be per logger instance though, I wouldn't want to set the log for all users of my API just one. – wonea Nov 24 '20 at 17:33
0

Maybe you could use a session-cookie to control whether debug-mode is enabled:

<targets>
    <target type="file" name="logfile" filename="applog.txt" />
</targets>
<rules>
    <logger name="*" minlevel="Off" writeTo="logfile" ruleName="debugCookieRule">
      <filters defaultAction="Log">
         <when condition="'${aspnet-session:EnableDebugMode}' == ''" action="Ignore" />
      </filters>
    </logger>
</rules>

Then activate the session-cookie like this:

public void SetMinLogLevel(LogLevel NewLogLevel)
{
    var cookieRule = LogManager.Configuration.FindRuleByName("debugCookieRule");
    if (cookieRule != null)
    {
        cookieRule.MinLevel = NewLogLevel;

        // Schedule disabling of logging-rule again in 60 secs.
        Task.Run(async () => { await Task.Delay(60000).ConfigureAwait(false); cookieRule.MinLevel = LogLevel.Off; LogManager.ReconfigExistingLoggers(); });

        // Activate EnableDebugMode for this session
        HttpContext.Session.SetString("EnableDebugMode", "Doctor has arrived");
    }

    LogManager.ReconfigExistingLoggers();  // Refresh loggers
}

If session-cookies and ${aspnet-session} is not wanted, then NLog.Web.AspNetCore have other options for extracting HttpContext-details. See also: https://nlog-project.org/config/?tab=layout-renderers&search=package:nlog.web.aspnetcore

Rolf Kristensen
  • 17,785
  • 1
  • 51
  • 70
0

Rather than trying to customize the NLog logging levels (which will affect the entire process), I think you should go for a solution that modifies the log levels of the log statements themselves.

To make this work, you'll need the following:

  1. A mechanism by which to identify requests for which you want debug logging
  2. A wrapper for the logger so that you can dynamically override the log level

The first requirement is simple enough - either set a cookie or a custom HTTP header, and check for the presence of either. You'll need to make this result of this check available to your LogWrapper instance, so that it knows when it should do something special.

The LogWrapper must be instantiated per request, so that the instance isn't shared across requests. The simplest way to do this is to create it on-demand in the constructor of your controller (but you could also wire it up to the DI container for automatic injection).

This would look something like this:

public class HomeController : Controller
{
    private readonly LogWrapper _logger;

    public HomeController(ILogger<HomeController> logger)
    {
        var isDebugRequest = ...;
        _logger = new LogWrapper<HomeController>(logger, isDebugRequest);
    }    

    ...
}

The basics of creating a log wrapper for NLog is explained here, but it looks like you're already using the wrapper created for Microsoft.Extensions.Logging, so you'd need to wrap that interface instead:

public class LogWrapper<T> : Microsoft.Extensions.Logging.ILogger
{
    private readonly ILogger<T> _logger;
    private readonly bool _debug;

    public LogWrapper(ILogger<T> logger, bool isDebug)
    {
        _logger = logger;
        _debug = isDebug;
    }    

    public void Log<TState>(LogLevel logLevel,
                            EventId eventId,
                            TState state,
                            Exception exception,
                            Func<TState, Exception, string> formatter)
    {
        if (_debug) 
        {
            // override log level here
            _logger.Log(LogLevel.Warning, eventId, state, exception, formatter); 
        }
        else 
        {
            _logger.Log(logLevel, eventId, state, exception, formatter);
        }
    }

    // ILogger has two other methods you'll need to implement
}    

The downside to this approach is that log statements won't have their original log level, which may or may not be important for your use case.

Morten Mertner
  • 9,414
  • 4
  • 39
  • 56