Docs - best practices for ILogger.IsEnabled (#5459)

This commit is contained in:
Reiley Yang 2024-03-19 16:05:01 -07:00 committed by GitHub
parent 76cafe5d80
commit af57ae8787
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 61 additions and 6 deletions

View File

@ -179,6 +179,51 @@ logger.LogInformation("Hello from {food} {price}.", food, price);
Refer to the [logging performance
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.
:heavy_check_mark: You should hold a high bar while using
[`ILogger.IsEnabled`](https://learn.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger.isenabled).
The logging API is highly optimized for the scenario where most loggers are
**disabled** for certain log levels. Making an extra call to `IsEnabled` before
logging will not give you any performance gain.
> [!WARNING]
> The `logger.IsEnabled(LogLevel.Information)` call in the following code is not
going to give any performance gain. Refer to the [logging performance
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.
```csharp
var food = "tomato";
var price = 2.99;
if (logger.IsEnabled(LogLevel.Information)) // do not do this, there is no perf gain
{
logger.SayHello(food, price);
}
internal static partial class LoggerExtensions
{
[LoggerMessage(Level = LogLevel.Information, Message = "Hello from {food} {price}.")]
public static partial void SayHello(this ILogger logger, string food, double price);
}
```
`IsEnabled` can give performance benefits when it is expensive to evaluate the
arguments. For example, in the following code the `Database.GetFoodPrice`
invocation will be skipped if the logger is not enabled:
```csharp
if (logger.IsEnabled(LogLevel.Information))
{
logger.SayHello(food, Database.GetFoodPrice(food));
}
```
Although `IsEnabled` can give some performance benefits in the above scenario,
for most users it can cause more problems. For example, the performance of the
code is now depending on which logger is being enabled, not to mention the
argument evaluation might have significant side effects that are now depending
on the logging configuration.
## LoggerFactory
In many cases, you can use [ILogger](#ilogger) without having to interact with

View File

@ -8,5 +8,5 @@ namespace Benchmarks.Logs;
public static partial class Food
{
[LoggerMessage(Level = LogLevel.Information, Message = "Hello from {food} {price}.")]
public static partial void SayHello(ILogger logger, string food, double price);
public static partial void SayHello(this ILogger logger, string food, double price);
}

View File

@ -19,6 +19,7 @@ BenchmarkDotNet v0.13.10, Windows 11 (10.0.22621.3007/22H2/2022Update/SunValley2
| NoListenerStringInterpolation | 124.458 ns | 2.5188 ns | 2.2329 ns | 0.0114 | 72 B |
| NoListenerExtensionMethod | 36.326 ns | 0.2916 ns | 0.2435 ns | 0.0102 | 64 B |
| NoListener | 1.375 ns | 0.0586 ns | 0.0896 ns | - | - |
| UnnecessaryIsEnabledCheck | 1.332 ns | 0.0225 ns | 0.0188 ns | - | - |
| CreateLoggerRepeatedly | 48.295 ns | 0.5951 ns | 0.4970 ns | 0.0038 | 24 B |
| OneProcessor | 98.133 ns | 1.8805 ns | 1.5703 ns | 0.0063 | 40 B |
| TwoProcessors | 105.414 ns | 0.4610 ns | 0.3850 ns | 0.0063 | 40 B |
@ -96,32 +97,41 @@ public class LogBenchmarks
[Benchmark]
public void NoListener()
{
Food.SayHello(this.loggerWithNoListener, FoodName, FoodPrice);
this.loggerWithNoListener.SayHello(FoodName, FoodPrice);
}
[Benchmark]
public void UnnecessaryIsEnabledCheck()
{
if (this.loggerWithNoListener.IsEnabled(LogLevel.Information))
{
this.loggerWithNoListener.SayHello(FoodName, FoodPrice);
}
}
[Benchmark]
public void CreateLoggerRepeatedly()
{
var logger = this.loggerFactoryWithNoListener.CreateLogger<LogBenchmarks>();
Food.SayHello(logger, FoodName, FoodPrice);
logger.SayHello(FoodName, FoodPrice);
}
[Benchmark]
public void OneProcessor()
{
Food.SayHello(this.loggerWithOneProcessor, FoodName, FoodPrice);
this.loggerWithOneProcessor.SayHello(FoodName, FoodPrice);
}
[Benchmark]
public void TwoProcessors()
{
Food.SayHello(this.loggerWithTwoProcessors, FoodName, FoodPrice);
this.loggerWithTwoProcessors.SayHello(FoodName, FoodPrice);
}
[Benchmark]
public void ThreeProcessors()
{
Food.SayHello(this.loggerWithThreeProcessors, FoodName, FoodPrice);
this.loggerWithThreeProcessors.SayHello(FoodName, FoodPrice);
}
internal class DummyLogProcessor : BaseProcessor<LogRecord>