Why do trace and debug level logs give small size "Allocated" and "Mean" result in dotnetBenchMark?

158 Views Asked by At

I am working on log severities with dotnet 7. I tried the test dotNetBenchMark library. I have questions about that result. As far as i know, debug and trace level logs have more info than other levels. if this true, i expect they should use more "allocated" than others. And why are they more faster "mean" than others? Or am i think wrong? I'll be glad if you help.

Thanks in advance.

I used nlog library. here is my nlog.config file:

<?xml version="1.0" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
    <targets async = "true">
         <target name="console" xsi:type="Console" layout="${date:format=HH\:MM\:ss} ${logger} ${message}" />
    </targets>
    <rules>
       <logger enabled = "true" name="*"  minlevel="trace"  writeTo="console" />
   </rules>
</nlog>

And i have very very simple test case. "add 2 number and give result info". The code is below like that for all levels:

[Benchmark]
public void DoLogTrace()
{
    var number1 = 30;
    var number2 = 40;
    var number3 = number1 * number2;
    _logger.LogTrace("Method run is completed. The Result is {0}",number3);
}

[Benchmark]
public void DoLogDebug()
{
    var number1 = 30;
    var number2 = 40;
    var number3 = number1 * number2;
    _logger.LogDebug("Method run is completed. The Result is {0}",number3);
}

And I got the following result

enter image description here

2

There are 2 best solutions below

0
On

As far as i know, debug and trace level logs have more info than other levels

This is by convention, not to do with the LogTrace and LogDebug methods.

Programmers choose to send more information at the trace and debug log levels so that there is a high amount of information available when they need to diagnose issues e.g.

_logger.LogInformation("Starting data processing at {StartTime}"); _logger.LogTrace("Starting data processing at {StartTime} on {Enviroment}. Started By user {Username}. Last run at {LastRunTime}");

Less information is sent to other log levels so that it is possible to get log files that are not clogged up with loads of diagnostic information.

Log files can be configured to ignore log levels so they can receive information at the log level that is necessary for the requirements of the file.

Typically a system running in production will have more than one log file targeting different log levels - usually a detailed log file for diagnostics and a less detailed one to monitor the activity of the application.

0
On

There is no special optimization for Debug or Trace-events. LogTrace and LogError are just extension methods that calls the same underlying ILogger.Log-method.

The idea is that one only enables Trace or Debug, when needing to diagnose problems. When a LogLevel is disabled, then no output is generated and no allocations will be made.

The important part is how you build the _logger that you are benchmarking, which decides what Levels are enabled for logging together with their output-targets.

See also LoggerMessage.Define if you care about performance. And want to avoid the params-array-allocation introduced by using LogTrace or LogError-extension-methods.