Skip to content

Commit af57ae8

Browse files
authored
Docs - best practices for ILogger.IsEnabled (#5459)
1 parent 76cafe5 commit af57ae8

File tree

3 files changed

+61
-6
lines changed

3 files changed

+61
-6
lines changed

docs/logs/README.md

+45
Original file line numberDiff line numberDiff line change
@@ -179,6 +179,51 @@ logger.LogInformation("Hello from {food} {price}.", food, price);
179179
Refer to the [logging performance
180180
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.
181181

182+
:heavy_check_mark: You should hold a high bar while using
183+
[`ILogger.IsEnabled`](https://learn.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger.isenabled).
184+
185+
The logging API is highly optimized for the scenario where most loggers are
186+
**disabled** for certain log levels. Making an extra call to `IsEnabled` before
187+
logging will not give you any performance gain.
188+
189+
> [!WARNING]
190+
> The `logger.IsEnabled(LogLevel.Information)` call in the following code is not
191+
going to give any performance gain. Refer to the [logging performance
192+
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.
193+
194+
```csharp
195+
var food = "tomato";
196+
var price = 2.99;
197+
198+
if (logger.IsEnabled(LogLevel.Information)) // do not do this, there is no perf gain
199+
{
200+
logger.SayHello(food, price);
201+
}
202+
203+
internal static partial class LoggerExtensions
204+
{
205+
[LoggerMessage(Level = LogLevel.Information, Message = "Hello from {food} {price}.")]
206+
public static partial void SayHello(this ILogger logger, string food, double price);
207+
}
208+
```
209+
210+
`IsEnabled` can give performance benefits when it is expensive to evaluate the
211+
arguments. For example, in the following code the `Database.GetFoodPrice`
212+
invocation will be skipped if the logger is not enabled:
213+
214+
```csharp
215+
if (logger.IsEnabled(LogLevel.Information))
216+
{
217+
logger.SayHello(food, Database.GetFoodPrice(food));
218+
}
219+
```
220+
221+
Although `IsEnabled` can give some performance benefits in the above scenario,
222+
for most users it can cause more problems. For example, the performance of the
223+
code is now depending on which logger is being enabled, not to mention the
224+
argument evaluation might have significant side effects that are now depending
225+
on the logging configuration.
226+
182227
## LoggerFactory
183228

184229
In many cases, you can use [ILogger](#ilogger) without having to interact with

test/Benchmarks/Logs/Food.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -8,5 +8,5 @@ namespace Benchmarks.Logs;
88
public static partial class Food
99
{
1010
[LoggerMessage(Level = LogLevel.Information, Message = "Hello from {food} {price}.")]
11-
public static partial void SayHello(ILogger logger, string food, double price);
11+
public static partial void SayHello(this ILogger logger, string food, double price);
1212
}

test/Benchmarks/Logs/LogBenchmarks.cs

+15-5
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@ .NET SDK 8.0.101
1919
| NoListenerStringInterpolation | 124.458 ns | 2.5188 ns | 2.2329 ns | 0.0114 | 72 B |
2020
| NoListenerExtensionMethod | 36.326 ns | 0.2916 ns | 0.2435 ns | 0.0102 | 64 B |
2121
| NoListener | 1.375 ns | 0.0586 ns | 0.0896 ns | - | - |
22+
| UnnecessaryIsEnabledCheck | 1.332 ns | 0.0225 ns | 0.0188 ns | - | - |
2223
| CreateLoggerRepeatedly | 48.295 ns | 0.5951 ns | 0.4970 ns | 0.0038 | 24 B |
2324
| OneProcessor | 98.133 ns | 1.8805 ns | 1.5703 ns | 0.0063 | 40 B |
2425
| TwoProcessors | 105.414 ns | 0.4610 ns | 0.3850 ns | 0.0063 | 40 B |
@@ -96,32 +97,41 @@ public void NoListenerExtensionMethod()
9697
[Benchmark]
9798
public void NoListener()
9899
{
99-
Food.SayHello(this.loggerWithNoListener, FoodName, FoodPrice);
100+
this.loggerWithNoListener.SayHello(FoodName, FoodPrice);
101+
}
102+
103+
[Benchmark]
104+
public void UnnecessaryIsEnabledCheck()
105+
{
106+
if (this.loggerWithNoListener.IsEnabled(LogLevel.Information))
107+
{
108+
this.loggerWithNoListener.SayHello(FoodName, FoodPrice);
109+
}
100110
}
101111

102112
[Benchmark]
103113
public void CreateLoggerRepeatedly()
104114
{
105115
var logger = this.loggerFactoryWithNoListener.CreateLogger<LogBenchmarks>();
106-
Food.SayHello(logger, FoodName, FoodPrice);
116+
logger.SayHello(FoodName, FoodPrice);
107117
}
108118

109119
[Benchmark]
110120
public void OneProcessor()
111121
{
112-
Food.SayHello(this.loggerWithOneProcessor, FoodName, FoodPrice);
122+
this.loggerWithOneProcessor.SayHello(FoodName, FoodPrice);
113123
}
114124

115125
[Benchmark]
116126
public void TwoProcessors()
117127
{
118-
Food.SayHello(this.loggerWithTwoProcessors, FoodName, FoodPrice);
128+
this.loggerWithTwoProcessors.SayHello(FoodName, FoodPrice);
119129
}
120130

121131
[Benchmark]
122132
public void ThreeProcessors()
123133
{
124-
Food.SayHello(this.loggerWithThreeProcessors, FoodName, FoodPrice);
134+
this.loggerWithThreeProcessors.SayHello(FoodName, FoodPrice);
125135
}
126136

127137
internal class DummyLogProcessor : BaseProcessor<LogRecord>

0 commit comments

Comments
 (0)