dotnet / dotnet/extensions

LogBuffering with CategoryName only rule ignores the rule for previously emitted log levels

Open
#7,486 0 comments 0 reactions 0 assignees View on GitHub
area-telemetry bug untriaged
Dominant language
C#
Stars
3.2k
Forks
894
Avg merge
1d 12h
Merged PRs (30d)
23

Description

### Description

Trying to implement global log buffering according to the article:

https://learn.microsoft.com/en-us/dotnet/core/extensions/logging/log-buffering

using the json configuration example in the article but having a single rule that consists only CategoryName,

the log buffering ignores log messages of that category (and instead the logs will be emitted immediatly) if previously a log message with the **same log level** but a **different category** (Microsoft.Hosting.Lifetime for example) was written.

### Reproduction Steps

Create a worker service project

Install Microsoft.Extensions.Telemetry nuget package (i used 10.5.0)

Add the global buffer with a rule consisting only the category name (i used "LogBufferTest" as the project name):
and AutoFlushDuration as 00:00:00 so logs wont be emitted after the flush in the worker

```
builder.Logging.AddGlobalBuffer(o =>
{
o.AutoFlushDuration = TimeSpan.Zero;
o.Rules.Add(new LogBufferingFilterRule(categoryName: nameof(LogBufferTest)));
});
```

Add `"LogBufferTest": "Trace"` to the appsettings.Development.json Logging section so all log levels for that category will be emitted.

Replace the Worker class with:

```
public class Worker(ILogger logger, GlobalLogBuffer globalLogBuffer, ILoggerFactory loggerFactory) : BackgroundService
{
protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
loggerFactory.CreateLogger("DifferentCategory").LogCritical("Hi from a different category Critical");

logger.LogTrace("Hi from Trace");
logger.LogDebug("Hi from Debug");
logger.LogInformation("Hi from Information");
logger.LogWarning("Hi from Warning");
logger.LogError("Hi from Error");
logger.LogCritical("Hi from Critical");

await Task.Delay(1000, stoppingToken);

globalLogBuffer.Flush();

await Task.Delay(1000, stoppingToken);

logger.LogTrace("Hi from Trace");
logger.LogDebug("Hi from Debug");
logger.LogInformation("Hi from Information");
logger.LogWarning("Hi from Warning");
logger.LogError("Hi from Error");
logger.LogCritical("Hi from Critical");
}
}
```

### Expected behavior

I expect to see the first `Hi from Information` `Hi from Critical` logs written to console only after the flush and the second ones to not be written at all, similar to the logs of the other levels.

### Actual behavior

Because of the standard `Microsoft.Hosting.Lifetime` information logs, the first `Hi from Information` will be emitted before the flush, and the second one will also be emitted after the flush, a similar thing happens to `Hi from Critical` because of the log from the `DifferentCategory` logger.

Raising the minimum log level of `Microsoft.Hosting.Lifetime` (to warning for example) will cause those logs to not be emitted and the `Hi from Information` logs to behave as expected, Removing the `Hi from a different category Critical` will do the same for the `Hi from Critical` logs

### Regression?

_No response_

### Known Workarounds

_No response_

### Configuration

_No response_

### Other information

_No response_

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.