Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add logging buffering #5635

Draft
wants to merge 38 commits into
base: main
Choose a base branch
from
Draft
Changes from 1 commit
Commits
Show all changes
38 commits
Select commit Hold shift + click to select a range
988c709
Buffering
evgenyfedorov2 Nov 13, 2024
2f1a335
Major update
evgenyfedorov2 Dec 7, 2024
2d2412e
Remove Json exception converter
evgenyfedorov2 Dec 12, 2024
f7eaab1
Fix namespaces
evgenyfedorov2 Dec 16, 2024
1f464df
Merge branch 'main' into evgenyfedorov2/log_buffering
evgenyfedorov2 Dec 16, 2024
a371d9c
Fix build
evgenyfedorov2 Dec 16, 2024
d7661a6
Slight design changes with interfaces as per PR comments
evgenyfedorov2 Jan 8, 2025
9d13ab0
Drop json serialization
evgenyfedorov2 Jan 9, 2025
fe00658
Add log record size estimation and limit buffer size in bytes
evgenyfedorov2 Jan 13, 2025
5fc421c
Add filtering by attributes
evgenyfedorov2 Jan 15, 2025
70cfc7c
Use attributes directly instead of Func delegate
evgenyfedorov2 Jan 21, 2025
e96277f
Add http buffer holder
evgenyfedorov2 Jan 21, 2025
a79fcbf
Make ILoggingBuffer and DeserializedLogRecord types internal
evgenyfedorov2 Jan 22, 2025
8a91c15
Move shared files to Shared project and add more tests
evgenyfedorov2 Jan 22, 2025
4f524eb
Add custom equality comparer
evgenyfedorov2 Jan 22, 2025
b2b6e56
Address API Review feedback
evgenyfedorov2 Feb 14, 2025
f3a6b85
Merge branch 'main' into evgenyfedorov2/log_buffering
evgenyfedorov2 Feb 14, 2025
1370225
merge
evgenyfedorov2 Feb 28, 2025
393ce26
API review feedback
evgenyfedorov2 Feb 28, 2025
20b5a4c
Remove extra lines
evgenyfedorov2 Feb 28, 2025
f5ce71e
Make tests culture agnostic
Mar 11, 2025
ce2f7fb
Global log buffering - options validation, rule selector optimization
Mar 11, 2025
6ffbacd
Rename to PerIncomingRequest
evgenyfedorov2 Mar 13, 2025
1370ccb
Minor updates
Mar 14, 2025
56257ca
More renames
Mar 14, 2025
73a8678
Rename shared folder LoggingBuffering to LogBuffering
Mar 14, 2025
8a42385
Remove per request options refresh because buffer are scoped anyway
Mar 14, 2025
7ff16fc
Remove unnecessary casting
Mar 14, 2025
35223f3
Add DebuggerDisplay to SerializedLogRecord.cs
Mar 15, 2025
bf0b59d
Added pooling of log record attributes lists
Mar 17, 2025
715ce25
Moved validation for max one asterisk in log category to options vali…
Mar 17, 2025
ccdfaeb
Add size of SerializedLogRecord struct to ballpark size estimation
Mar 17, 2025
4e1566b
Added a remark
Mar 17, 2025
5171413
Added remarks on buffer filter rules
Mar 17, 2025
58f7b20
Enable log buffering for .NET 8
Mar 17, 2025
cc0d9b7
Fix package downgrade
Mar 17, 2025
5ca502b
more package downgrade fixes
Mar 17, 2025
82eeb33
Suppress CS0436
Mar 17, 2025
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,97 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using Microsoft.Extensions.Diagnostics;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Extensions.Options;

namespace Microsoft.AspNetCore.Diagnostics.Logging;

internal sealed class HttpRequestBuffer : ILoggingBuffer
{
private readonly IOptionsMonitor<HttpRequestBufferOptions> _options;
private readonly ConcurrentDictionary<IBufferedLogger, ConcurrentQueue<HttpRequestBufferedLogRecord>> _buffers;
private readonly TimeProvider _timeProvider = TimeProvider.System;
private DateTimeOffset _lastFlushTimestamp;

public HttpRequestBuffer(IOptionsMonitor<HttpRequestBufferOptions> options)
{
_options = options;
_buffers = new ConcurrentDictionary<IBufferedLogger, ConcurrentQueue<HttpRequestBufferedLogRecord>>();
_lastFlushTimestamp = _timeProvider.GetUtcNow();
}

internal HttpRequestBuffer(IOptionsMonitor<HttpRequestBufferOptions> options, TimeProvider timeProvider)
: this(options)
{
_timeProvider = timeProvider;
_lastFlushTimestamp = _timeProvider.GetUtcNow();
}

public bool TryEnqueue(
IBufferedLogger logger,
LogLevel logLevel,
string category,
EventId eventId,
IReadOnlyList<KeyValuePair<string, object?>> joiner,
Exception? exception,
string formatter)
{
if (!IsEnabled(category, logLevel, eventId))
{
return false;
}

var record = new HttpRequestBufferedLogRecord(logLevel, eventId, joiner, exception, formatter);
var queue = _buffers.GetOrAdd(logger, _ => new ConcurrentQueue<HttpRequestBufferedLogRecord>());

// probably don't need to limit buffer capacity?
// because buffer is disposed when the respective HttpContext is disposed
// don't expect it to grow so much to cause a problem?
if (queue.Count >= _options.CurrentValue.PerRequestCapacity)
{
_ = queue.TryDequeue(out HttpRequestBufferedLogRecord? _);
}

queue.Enqueue(record);

return true;
}

public void Flush()
{
foreach (var (logger, queue) in _buffers)
{
var result = new List<BufferedLogRecord>();
while (!queue.IsEmpty)
{
if (queue.TryDequeue(out HttpRequestBufferedLogRecord? item))
{
result.Add(item);
}
}

logger.LogRecords(result);
}

_lastFlushTimestamp = _timeProvider.GetUtcNow();
}

public bool IsEnabled(string category, LogLevel logLevel, EventId eventId)
{
if (_timeProvider.GetUtcNow() < _lastFlushTimestamp + _options.CurrentValue.SuspendAfterFlushDuration)
{
return false;
}

LoggerFilterRuleSelector.Select<BufferFilterRule>(_options.CurrentValue.Rules, category, logLevel, eventId, out BufferFilterRule? rule);

return rule is not null;
}
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,43 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System.Collections.Generic;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Options;

namespace Microsoft.AspNetCore.Diagnostics.Logging;

internal sealed class HttpRequestBufferConfigureOptions : IConfigureOptions<HttpRequestBufferOptions>
{
private const string BufferingKey = "Buffering";
private readonly IConfiguration _configuration;

public HttpRequestBufferConfigureOptions(IConfiguration configuration)
{
_configuration = configuration;
}

public void Configure(HttpRequestBufferOptions options)
{
if (_configuration == null)
{
return;
}

var section = _configuration.GetSection(BufferingKey);
if (!section.Exists())
{
return;
}

var parsedOptions = section.Get<HttpRequestBufferOptions>();
if (parsedOptions is null)
{
return;
}

options.Rules.AddRange(parsedOptions.Rules);
}
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,97 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Diagnostics.CodeAnalysis;
using Microsoft.AspNetCore.Diagnostics.Logging;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.DependencyInjection.Extensions;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Microsoft.Shared.DiagnosticIds;
using Microsoft.Shared.Diagnostics;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// Lets you register log buffers in a dependency injection container.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public static class HttpRequestBufferLoggerBuilderExtensions
{
/// <summary>
/// Adds HTTP request-aware buffer to the logging infrastructure. Matched logs will be buffered in
/// a buffer specific to each HTTP request and can optionally be flushed and emitted during the request lifetime./>.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <param name="configuration">The <see cref="IConfiguration" /> to add.</param>
/// <returns>The value of <paramref name="builder"/>.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
public static ILoggingBuilder AddHttpRequestBuffer(this ILoggingBuilder builder, IConfiguration configuration)
{
_ = Throw.IfNull(builder);
_ = Throw.IfNull(configuration);

return builder
.AddHttpRequestBufferConfiguration(configuration)
.AddHttpRequestBufferProvider();
}

/// <summary>
/// Adds HTTP request-aware buffer to the logging infrastructure. Matched logs will be buffered in
/// a buffer specific to each HTTP request and can optionally be flushed and emitted during the request lifetime./>.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <param name="level">The log level (and below) to apply the buffer to.</param>
/// <param name="configure">The buffer configuration options.</param>
/// <returns>The value of <paramref name="builder"/>.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
public static ILoggingBuilder AddHttpRequestBuffer(this ILoggingBuilder builder, LogLevel? level = null, Action<HttpRequestBufferOptions>? configure = null)
{
_ = Throw.IfNull(builder);

_ = builder.Services
.Configure<HttpRequestBufferOptions>(options => options.Rules.Add(new BufferFilterRule(null, level, null)))
.Configure(configure ?? new Action<HttpRequestBufferOptions>(_ => { }));

return builder.AddHttpRequestBufferProvider();
}

/// <summary>
/// Adds HTTP request buffer provider to the logging infrastructure.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <returns>The <see cref="ILoggingBuilder"/> so that additional calls can be chained.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
public static ILoggingBuilder AddHttpRequestBufferProvider(this ILoggingBuilder builder)
{
_ = Throw.IfNull(builder);

builder.Services.TryAddScoped<HttpRequestBuffer>();
builder.Services.TryAddScoped<ILoggingBuffer>(sp => sp.GetRequiredService<HttpRequestBuffer>());
builder.Services.TryAddSingleton<IHttpContextAccessor, HttpContextAccessor>();
builder.Services.TryAddActivatedSingleton<ILoggingBufferProvider, HttpRequestBufferProvider>();

return builder.AddGlobalBufferProvider();
}

/// <summary>
/// Configures <see cref="HttpRequestBufferOptions" /> from an instance of <see cref="IConfiguration" />.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <param name="configuration">The <see cref="IConfiguration" /> to add.</param>
/// <returns>The value of <paramref name="builder"/>.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
internal static ILoggingBuilder AddHttpRequestBufferConfiguration(this ILoggingBuilder builder, IConfiguration configuration)
{
_ = Throw.IfNull(builder);

_ = builder.Services.AddSingleton<IConfigureOptions<HttpRequestBufferOptions>>(new HttpRequestBufferConfigureOptions(configuration));

return builder;
}
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,47 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using Microsoft.Extensions.Logging;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.AspNetCore.Diagnostics.Logging;

/// <summary>
/// The options for LoggerBuffer.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public class HttpRequestBufferOptions
{
/// <summary>
/// Gets or sets the time to suspend the buffer after flushing.
/// </summary>
/// <remarks>
/// Use this to temporarily suspend buffering after a flush, e.g. in case of an incident you may want all logs to be emitted immediately,
/// so the buffering will be suspended for the <see paramref="SuspendAfterFlushDuration"/> time.
/// </remarks>
public TimeSpan SuspendAfterFlushDuration { get; set; } = TimeSpan.FromSeconds(30);

/// <summary>
/// Gets or sets the size of the buffer for a request.
/// </summary>
public int PerRequestCapacity { get; set; } = 1_000;

/// <summary>
/// Gets or sets the size of the global buffer which applies to non-request logs only.
/// </summary>
public int GlobalCapacity { get; set; } = 1_000_000;

#pragma warning disable CA1002 // Do not expose generic lists - List is necessary to be able to call .AddRange()
#pragma warning disable CA2227 // Collection properties should be read only - setter is necessary for options pattern
/// <summary>
/// Gets or sets the collection of <see cref="BufferFilterRule"/> used for filtering log messages for the purpose of further buffering.
/// </summary>
public List<BufferFilterRule> Rules { get; set; } = [];
#pragma warning restore CA2227 // Collection properties should be read only
#pragma warning restore CA1002 // Do not expose generic lists
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System.Collections.Concurrent;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

namespace Microsoft.AspNetCore.Diagnostics.Logging;

internal sealed class HttpRequestBufferProvider : ILoggingBufferProvider
{
private readonly GlobalBufferProvider _globalBufferProvider;
private readonly IHttpContextAccessor _accessor;
private readonly ConcurrentDictionary<string, HttpRequestBuffer> _requestBuffers = new();

public HttpRequestBufferProvider(GlobalBufferProvider globalBufferProvider, IHttpContextAccessor accessor)
{
_globalBufferProvider = globalBufferProvider;
_accessor = accessor;
}

public ILoggingBuffer CurrentBuffer => _accessor.HttpContext is null
? _globalBufferProvider.CurrentBuffer
: _requestBuffers.GetOrAdd(_accessor.HttpContext.TraceIdentifier, _accessor.HttpContext.RequestServices.GetRequiredService<HttpRequestBuffer>());

// TO DO: Dispose request buffer when the respective HttpContext is disposed
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;

namespace Microsoft.AspNetCore.Diagnostics.Logging;

internal sealed class HttpRequestBufferedLogRecord : BufferedLogRecord
{
public HttpRequestBufferedLogRecord(
LogLevel logLevel,
EventId eventId,
IReadOnlyList<KeyValuePair<string, object?>> state,
Exception? exception,
string? formatter)
{
LogLevel = logLevel;
EventId = eventId;
Attributes = state;
Exception = exception?.ToString(); // wtf??
FormattedMessage = formatter;
}

public override IReadOnlyList<KeyValuePair<string, object?>> Attributes { get; }
public override string? FormattedMessage { get; }
public override string? Exception { get; }

public override DateTimeOffset Timestamp { get; }

public override LogLevel LogLevel { get; }

public override EventId EventId { get; }
}
#endif
Original file line number Diff line number Diff line change
@@ -17,7 +17,6 @@
<InjectSharedPools>false</InjectSharedPools>
<InjectSharedBufferWriterPool>true</InjectSharedBufferWriterPool>
<InjectSharedNumericExtensions>false</InjectSharedNumericExtensions>
<InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
<InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
</PropertyGroup>

Original file line number Diff line number Diff line change
@@ -6,6 +6,12 @@
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Globalization;
#if NET9_0_OR_GREATER
using System.Diagnostics.CodeAnalysis;
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Shared.DiagnosticIds;

#endif
using Microsoft.Shared.Diagnostics;

namespace Microsoft.Extensions.Logging.Testing;
@@ -17,7 +23,11 @@ namespace Microsoft.Extensions.Logging.Testing;
/// This type is intended for use in unit tests. It captures all the log state to memory and lets you inspect it
/// to validate that your code is logging what it should.
/// </remarks>
#if NET9_0_OR_GREATER
public class FakeLogger : ILogger, IBufferedLogger
#else
public class FakeLogger : ILogger
#endif
{
private readonly ConcurrentDictionary<LogLevel, bool> _disabledLevels = new(); // used as a set, the value is ignored

@@ -105,6 +115,27 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
/// </summary>
public string? Category { get; }

#if NET9_0_OR_GREATER
/// <inheritdoc/>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public void LogRecords(IEnumerable<BufferedLogRecord> records)
{
_ = Throw.IfNull(records);

var l = new List<object?>();
ScopeProvider.ForEachScope((scopeState, list) => list.Add(scopeState), l);

foreach (var rec in records)
{
#pragma warning disable CA2201 // TO DO: Remove suppression and implement propert Exception deserialization
var record = new FakeLogRecord(rec.LogLevel, rec.EventId, ConsumeTState(rec.Attributes), new Exception(rec.Exception), rec.FormattedMessage ?? string.Empty,
l.ToArray(), Category, !_disabledLevels.ContainsKey(rec.LogLevel), rec.Timestamp);
#pragma warning restore CA2201
Collector.AddRecord(record);
}
}
#endif

internal IExternalScopeProvider ScopeProvider { get; set; } = new LoggerExternalScopeProvider();

private static object? ConsumeTState(object? state)
Original file line number Diff line number Diff line change
@@ -14,8 +14,6 @@
<UseMetricsReportsGenerator>true</UseMetricsReportsGenerator>
<InjectGetOrAddOnLegacy>false</InjectGetOrAddOnLegacy>
<InjectTaskWaitAsyncOnLegacy>true</InjectTaskWaitAsyncOnLegacy>
<InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
<InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
<InjectTrimAttributesOnLegacy>false</InjectTrimAttributesOnLegacy>
<InjectSharedDebugger>true</InjectSharedDebugger>
<InjectSharedDataValidation>false</InjectSharedDataValidation>
Original file line number Diff line number Diff line change
@@ -0,0 +1,48 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System.Diagnostics.CodeAnalysis;
using Microsoft.Extensions.Diagnostics;
using Microsoft.Extensions.Logging;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// Defines a rule used to filter log messages for purposes of futher buffering.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public class BufferFilterRule : ILoggerFilterRule
{
/// <summary>
/// Initializes a new instance of the <see cref="BufferFilterRule"/> class.
/// </summary>
public BufferFilterRule()
: this(null, null, null)
{
}

/// <summary>
/// Initializes a new instance of the <see cref="BufferFilterRule"/> class.
/// </summary>
/// <param name="categoryName">The category name to use in this filter rule.</param>
/// <param name="logLevel">The <see cref="LogLevel"/> to use in this filter rule.</param>
/// <param name="eventId">The <see cref="EventId"/> to use in this filter rule.</param>
public BufferFilterRule(string? categoryName, LogLevel? logLevel, int? eventId)
{
Category = categoryName;
LogLevel = logLevel;
EventId = eventId;
}

/// <inheritdoc/>
public string? Category { get; set; }

/// <inheritdoc/>
public LogLevel? LogLevel { get; set; }

/// <inheritdoc/>
public int? EventId { get; set; }
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,129 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Diagnostics;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Extensions.Options;

namespace Microsoft.Extensions.Logging;

internal sealed class GlobalBuffer : BackgroundService, ILoggingBuffer
{
private readonly IOptionsMonitor<GlobalBufferOptions> _options;
private readonly ConcurrentDictionary<IBufferedLogger, ConcurrentQueue<GlobalBufferedLogRecord>> _buffers;
private readonly TimeProvider _timeProvider = TimeProvider.System;
private DateTimeOffset _lastFlushTimestamp;

public GlobalBuffer(IOptionsMonitor<GlobalBufferOptions> options)
{
_options = options;
_lastFlushTimestamp = _timeProvider.GetUtcNow();
_buffers = new ConcurrentDictionary<IBufferedLogger, ConcurrentQueue<GlobalBufferedLogRecord>>();
}

internal GlobalBuffer(IOptionsMonitor<GlobalBufferOptions> options, TimeProvider timeProvider)
: this(options)
{
_timeProvider = timeProvider;
_lastFlushTimestamp = _timeProvider.GetUtcNow();
}

public bool TryEnqueue(
IBufferedLogger logger,
LogLevel logLevel,
string category,
EventId eventId,
IReadOnlyList<KeyValuePair<string, object?>> joiner,
Exception? exception, string formatter)
{
if (!IsEnabled(category, logLevel, eventId))
{
return false;
}

var record = new GlobalBufferedLogRecord(logLevel, eventId, joiner, exception, formatter);
var queue = _buffers.GetOrAdd(logger, _ => new ConcurrentQueue<GlobalBufferedLogRecord>());
if (queue.Count >= _options.CurrentValue.Capacity)
{
_ = queue.TryDequeue(out GlobalBufferedLogRecord? _);
}

queue.Enqueue(record);

return true;
}

public void Flush()
{
foreach (var (logger, queue) in _buffers)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You and Martin should decide if you care about emitting the events in any particular order. As-is it looks like the sort order is first by an arbitrary category ordering and secondly by approximate time-order. If users see buffered logs dumped on the console that way they might be confused by it but I imagine most logging backends won't care at all. I'm fine with it as-is but I wanted to raise the question to ensure everyone else also is comfortable with it.

Copy link

@KalleOlaviNiemitalo KalleOlaviNiemitalo Dec 16, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have a logging provider that writes the events to files and I have been planning to support log buffering in that after it is upgraded to .NET 10 LTS. There though, I'd very much like to keep the events ordered by time, rather than by category. So if this PR implements per-category buffers, then I'd need to implement a separate step (in-process or out of process) that sorts the events after all per-category buffers have been flushed. More likely, I'd avoid the Microsoft.Extensions.Telemetry package, implement the buffering myself, and keep the events in chronological order. The API in dotnet/runtime at least makes that possible.

Copy link

@KalleOlaviNiemitalo KalleOlaviNiemitalo Jan 7, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This comment relates to the IBufferedLogger interface and to log buffering in general, not to any code in this pull request.

I've been working on a private implementation of a buffering logger factory that keeps the events in chronological order and supports .NET Framework too. It passes tests but I'll still need to work on:

  • performance measurements and optimizations
  • extensibility of log entry serialization
  • buffer flushing policy: does it have to support IConfiguration, or is it enough if the application can provide a predicate that gets a LogEntry<TState>
  • piloting in an actual service

In my implementation, there is typically one ILogBuffer per incoming request and possibly one global ILogBuffer as well; there are no per-category buffers. The per-category ILogger created by the ILoggerFactory locates the current ILogBuffer and passes to it both a LogEntry<TState> value and a "broadcasting" per-category IBufferedLogger reference. The ILogBuffer saves a queue entry that contains both the buffered form of the log entry and the IBufferedLogger reference. When the ILogBuffer is eventually flushed, it is expected to call IBufferedLogger.LogRecords(IEnumerable<BufferedLogRecord>), which then broadcasts the log records to the per-category, per-provider IBufferedLogger implementations if the logger filter rules allow. If consecutive queue entries have the same IBufferedLogger reference, then the log buffer can flush them in the same IBufferedLogger.LogRecords call.

In each of the following cases, the factory-created ILogger forwards the log entry to the per-provider ILogger immediately without buffering:

  • If the per-provider ILogger does not implement IBufferedLogger. (Because of this, nothing ever deserializes a log entry back from BufferedLogRecord, and my implementation avoids the problems noted in Add logging buffering #5635 (comment) and Add logging buffering #5635 (comment).)
  • If the logger factory configuration explicitly disables buffering for the logger provider.
  • If there is no current ILogBuffer.
  • If the current ILogBuffer decides that the log entry should not be buffered.

If the logger configuration is changed or ILoggerFactory.AddProvider is called, then the broadcasting IBufferedLogger instances are replaced with new ones that use the new configuration, and these new instances will be used in future queue entries, but any queue entries already in a log buffer keep referring to the old IBufferedLogger instances that use the old configuration.

A potential performance problem is that, if consecutive queue entries in a log buffer are for different log categories, then they have different IBufferedLogger references and cannot be included in the same IBufferedLogger.LogRecords(IEnumerable<BufferedLogRecord>) call. Thus, if the log categories keep alternating, then each IEnumerable<BufferedLogRecord> will have fewer elements, and flushing the entire buffer will require a greater number of IBufferedLogger.LogRecords calls. I'll need to measure the cost of this. It might be possible to replace IBufferedLogger with some new IMultiCategoryBufferedLogger interface that natively supports multiple log categories in the same IEnumerable<T>, but to take full advantage of it, the new interface would need to be implemented in logger provider packages as well.

Another performance risk is that my implementation currently has quite a few generic methods parameterised on <TState>. I recall reading that those are particularly slow in interface method calls; and that with value types, the native code is not shared. I did it this way to minimise allocations, but I should measure the real effect on performance.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@KalleOlaviNiemitalo - I'll leave it to @evgenyfedorov2 to mull this over but I just wanted to give a big thanks for all the thoughtful feedback and context you've added. Its much appreciated!

{
var result = new List<BufferedLogRecord>();
while (!queue.IsEmpty)
{
if (queue.TryDequeue(out GlobalBufferedLogRecord? item))
{
result.Add(item);
}
}

logger.LogRecords(result);
}

_lastFlushTimestamp = _timeProvider.GetUtcNow();
}

internal void RemoveExpiredItems()
{
foreach (var (logger, queue) in _buffers)
{
while (!queue.IsEmpty)
{
if (queue.TryPeek(out GlobalBufferedLogRecord? item))
{
if (_timeProvider.GetUtcNow() - item.Timestamp > _options.CurrentValue.Duration)
{
_ = queue.TryDequeue(out _);
}
else
{
break;
}
}
else
{
break;
}
}
}
}

protected override async Task ExecuteAsync(CancellationToken cancellationToken)
{
while (!cancellationToken.IsCancellationRequested)
{
await _timeProvider.Delay(_options.CurrentValue.Duration, cancellationToken).ConfigureAwait(false);
RemoveExpiredItems();
}
}

private bool IsEnabled(string category, LogLevel logLevel, EventId eventId)
{
if (_timeProvider.GetUtcNow() < _lastFlushTimestamp + _options.CurrentValue.SuspendAfterFlushDuration)
{
return false;
}

LoggerFilterRuleSelector.Select(_options.CurrentValue.Rules, category, logLevel, eventId, out BufferFilterRule? rule);

return rule is not null;
}
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,43 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System.Collections.Generic;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Options;

namespace Microsoft.Extensions.Logging;

internal sealed class GlobalBufferConfigureOptions : IConfigureOptions<GlobalBufferOptions>
{
private const string BufferingKey = "Buffering";
private readonly IConfiguration _configuration;

public GlobalBufferConfigureOptions(IConfiguration configuration)
{
_configuration = configuration;
}

public void Configure(GlobalBufferOptions options)
{
if (_configuration == null)
{
return;
}

var section = _configuration.GetSection(BufferingKey);
if (!section.Exists())
{
return;
}

var parsedOptions = section.Get<GlobalBufferOptions>();
if (parsedOptions is null)
{
return;
}

options.Rules.AddRange(parsedOptions.Rules);
}
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,99 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Diagnostics.CodeAnalysis;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.DependencyInjection.Extensions;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Microsoft.Shared.DiagnosticIds;
using Microsoft.Shared.Diagnostics;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// Lets you register log buffers in a dependency injection container.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public static class GlobalBufferLoggerBuilderExtensions
{
/// <summary>
/// Adds global buffer to the logging infrastructure.
/// Matched logs will be buffered and can optionally be flushed and emitted./>.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <param name="configuration">The <see cref="IConfiguration" /> to add.</param>
/// <returns>The value of <paramref name="builder"/>.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
public static ILoggingBuilder AddGlobalBuffer(this ILoggingBuilder builder, IConfiguration configuration)
{
_ = Throw.IfNull(builder);
_ = Throw.IfNull(configuration);

return builder
.AddGlobalBufferConfiguration(configuration)
.AddGlobalBufferProvider();
}

/// <summary>
/// Adds global buffer to the logging infrastructure.
/// Matched logs will be buffered and can optionally be flushed and emitted./>.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <param name="level">The log level (and below) to apply the buffer to.</param>
/// <param name="configure">Configure buffer options.</param>
/// <returns>The value of <paramref name="builder"/>.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
public static ILoggingBuilder AddGlobalBuffer(this ILoggingBuilder builder, LogLevel? level = null, Action<GlobalBufferOptions>? configure = null)
{
_ = Throw.IfNull(builder);

_ = builder.Services
.Configure<GlobalBufferOptions>(options => options.Rules.Add(new BufferFilterRule(null, level, null)))
.Configure(configure ?? new Action<GlobalBufferOptions>(_ => { }));

return builder.AddGlobalBufferProvider();
}

/// <summary>
/// Adds global logging buffer provider.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <returns>The <see cref="ILoggingBuilder"/> so that additional calls can be chained.</returns>
public static ILoggingBuilder AddGlobalBufferProvider(this ILoggingBuilder builder)
{
_ = Throw.IfNull(builder);

builder.Services.TryAddSingleton<GlobalBufferProvider>();
builder.Services.TryAddSingleton<ILoggingBufferProvider>(static sp => sp.GetRequiredService<GlobalBufferProvider>());

builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton<ILoggerFactory, ExtendedLoggerFactory>());

builder.Services.TryAddSingleton<GlobalBuffer>();
builder.Services.TryAddSingleton<ILoggingBuffer>(static sp => sp.GetRequiredService<GlobalBuffer>());
builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton<IHostedService, GlobalBuffer>(static sp => sp.GetRequiredService<GlobalBuffer>()));

return builder;
}

/// <summary>
/// Configures <see cref="GlobalBufferOptions" /> from an instance of <see cref="IConfiguration" />.
/// </summary>
/// <param name="builder">The <see cref="ILoggingBuilder" />.</param>
/// <param name="configuration">The <see cref="IConfiguration" /> to add.</param>
/// <returns>The value of <paramref name="builder"/>.</returns>
/// <exception cref="ArgumentNullException"><paramref name="builder"/> is <see langword="null"/>.</exception>
internal static ILoggingBuilder AddGlobalBufferConfiguration(this ILoggingBuilder builder, IConfiguration configuration)
{
_ = Throw.IfNull(builder);

_ = builder.Services.AddSingleton<IConfigureOptions<GlobalBufferOptions>>(new GlobalBufferConfigureOptions(configuration));

return builder;
}
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// The options for LoggerBuffer.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public class GlobalBufferOptions
{
/// <summary>
/// Gets or sets the time to suspend the buffer after flushing.
/// </summary>
/// <remarks>
/// Use this to temporarily suspend buffering after a flush, e.g. in case of an incident you may want all logs to be emitted immediately,
/// so the buffering will be suspended for the <see paramref="SuspendAfterFlushDuration"/> time.
/// </remarks>
public TimeSpan SuspendAfterFlushDuration { get; set; } = TimeSpan.FromSeconds(30);

/// <summary>
/// Gets or sets the duration to keep logs in the buffer.
/// </summary>
public TimeSpan Duration { get; set; } = TimeSpan.FromSeconds(30);

/// <summary>
/// Gets or sets the size of the buffer.
/// </summary>
public int Capacity { get; set; } = 1_000_000;

#pragma warning disable CA1002 // Do not expose generic lists - List is necessary to be able to call .AddRange()
#pragma warning disable CA2227 // Collection properties should be read only - setter is necessary for options pattern
/// <summary>
/// Gets or sets the collection of <see cref="BufferFilterRule"/> used for filtering log messages for the purpose of further buffering.
/// </summary>
public List<BufferFilterRule> Rules { get; set; } = [];
#pragma warning restore CA2227 // Collection properties should be read only
#pragma warning restore CA1002 // Do not expose generic lists
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
namespace Microsoft.Extensions.Logging;

internal sealed class GlobalBufferProvider : ILoggingBufferProvider
{
private readonly GlobalBuffer _buffer;

public GlobalBufferProvider(GlobalBuffer buffer)
{
_buffer = buffer;
}

public ILoggingBuffer CurrentBuffer => _buffer;
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;

namespace Microsoft.Extensions.Logging;

internal sealed class GlobalBufferedLogRecord : BufferedLogRecord
{
public GlobalBufferedLogRecord(
LogLevel logLevel,
EventId eventId,
IReadOnlyList<KeyValuePair<string, object?>> state,
Exception? exception,
string? formatter)
{
LogLevel = logLevel;
EventId = eventId;
Attributes = state;
Exception = exception?.ToString(); // wtf??
FormattedMessage = formatter;
}

public override IReadOnlyList<KeyValuePair<string, object?>> Attributes { get; }
public override string? FormattedMessage { get; }
public override string? Exception { get; }

public override DateTimeOffset Timestamp { get; }

public override LogLevel LogLevel { get; }

public override EventId EventId { get; }
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// Interface for a logging buffer.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public interface ILoggingBuffer
{
/// <summary>
/// Flushes the buffer and emits all buffered logs.
/// </summary>
void Flush();

/// <summary>
/// Enqueues a log record.
/// </summary>
/// <returns>true or false.</returns>
bool TryEnqueue(
IBufferedLogger logger,
LogLevel logLevel,
string category,
EventId eventId,
IReadOnlyList<KeyValuePair<string, object?>> joiner,
Exception? exception,
string formatter);
}
#endif
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System.Diagnostics.CodeAnalysis;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// Interface providing access to the current logging buffer.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public interface ILoggingBufferProvider
{
/// <summary>
/// Gets current logging buffer.
/// </summary>
public ILoggingBuffer CurrentBuffer { get; }
}
#endif
27 changes: 27 additions & 0 deletions src/Libraries/Microsoft.Extensions.Telemetry/ILoggerFilterRule.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using Microsoft.Extensions.Logging;

namespace Microsoft.Extensions.Diagnostics;

/// <summary>
/// Represents a rule used for filtering log messages for purposes of log sampling and buffering.
/// </summary>
internal interface ILoggerFilterRule
{
/// <summary>
/// Gets the logger category this rule applies to.
/// </summary>
public string? Category { get; }

/// <summary>
/// Gets the maximum <see cref="LogLevel"/> of messages.
/// </summary>
public LogLevel? LogLevel { get; }

/// <summary>
/// Gets the maximum <see cref="LogLevel"/> of messages where this rule applies to.
/// </summary>
public int? EventId { get; }
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,131 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#pragma warning disable CA1307 // Specify StringComparison for clarity
#pragma warning disable S1659 // Multiple variables should not be declared on the same line
#pragma warning disable S2302 // "nameof" should be used

using System;
using System.Collections.Generic;
using Microsoft.Extensions.Logging;

namespace Microsoft.Extensions.Diagnostics
{
internal static class LoggerFilterRuleSelector
{
public static void Select<T>(IList<T> rules, string category, LogLevel logLevel, EventId eventId,
out T? bestRule)
where T : class, ILoggerFilterRule
{
bestRule = null;

// TO DO: update the comment and logic
// Filter rule selection:
// 1. Select rules with longest matching categories
// 2. If there is nothing matched by category take all rules without category
// 3. If there is only one rule use it
// 4. If there are multiple rules use last

T? current = null;
foreach (T rule in rules)
{
if (IsBetter(rule, current, category, logLevel, eventId))
{
current = rule;
}
}

if (current != null)
{
bestRule = current;
}
}

private static bool IsBetter<T>(T rule, T? current, string category, LogLevel logLevel, EventId eventId)
where T : class, ILoggerFilterRule
{
// Skip rules with inapplicable log level
if (rule.LogLevel != null && rule.LogLevel < logLevel)
{
return false;
}

// Skip rules with inapplicable event id
if (rule.EventId != null && rule.EventId != eventId)
{
return false;
}

// Skip rules with inapplicable category
string? categoryName = rule.Category;
if (categoryName != null)
{
const char WildcardChar = '*';

int wildcardIndex = categoryName.IndexOf(WildcardChar);
if (wildcardIndex != -1 &&
categoryName.IndexOf(WildcardChar, wildcardIndex + 1) != -1)
{
throw new InvalidOperationException("Only one wildcard character is allowed in category name.");
}

ReadOnlySpan<char> prefix, suffix;
if (wildcardIndex == -1)
{
prefix = categoryName.AsSpan();
suffix = default;
}
else
{
prefix = categoryName.AsSpan(0, wildcardIndex);
suffix = categoryName.AsSpan(wildcardIndex + 1);
}

if (!category.AsSpan().StartsWith(prefix, StringComparison.OrdinalIgnoreCase) ||
!category.AsSpan().EndsWith(suffix, StringComparison.OrdinalIgnoreCase))
{
return false;
}
}

// Decide whose category is better - rule vs current
if (current?.Category != null)
{
if (rule.Category == null)
{
return false;
}

if (current.Category.Length > rule.Category.Length)
{
return false;
}
}

// Decide whose log level is better - rule vs current
if (current?.LogLevel != null)
{
if (rule.LogLevel == null)
{
return false;
}

if (current.LogLevel < rule.LogLevel)
{
return false;
}
}

// Decide whose event id is better - rule vs current
if (rule.EventId is null)
{
if (current?.EventId != null)
{
return false;
}
}

return true;
}
}
}
Original file line number Diff line number Diff line change
@@ -4,7 +4,9 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using Microsoft.Extensions.Logging;
#if NET9_0_OR_GREATER
using Microsoft.Extensions.Logging.Abstractions;
#endif
using Microsoft.Shared.Pools;

namespace Microsoft.Extensions.Logging;
@@ -266,6 +268,20 @@ private void ModernPath(LogLevel logLevel, EventId eventId, LoggerMessageState m
ref readonly MessageLogger loggerInfo = ref loggers[i];
if (loggerInfo.IsNotFilteredOut(logLevel))
{
#if NET9_0_OR_GREATER
if (loggerInfo.Logger is IBufferedLogger bufferedLogger)
{
if (config.BufferProvider is not null &&
config.BufferProvider.CurrentBuffer.TryEnqueue(bufferedLogger, logLevel, loggerInfo.Category!, eventId, joiner, exception, joiner.Formatter!(joiner.State, exception)))
{
// The record was buffered, so we skip logging it for now.
// When a caller needs to flush the buffer and calls ILoggerBuffer.Flush(),
// the buffer will internally call IBufferedLogger.LogRecords to emit log records.
continue;
}
}
#endif

try
{
loggerInfo.LoggerLog(logLevel, eventId, joiner, exception, static (s, e) =>
@@ -350,6 +366,22 @@ private void LegacyPath<TState>(LogLevel logLevel, EventId eventId, TState state
ref readonly MessageLogger loggerInfo = ref loggers[i];
if (loggerInfo.IsNotFilteredOut(logLevel))
{
#if NET9_0_OR_GREATER
if (loggerInfo.Logger is IBufferedLogger bufferedLogger)
{
if (config.BufferProvider is not null &&
config.BufferProvider.CurrentBuffer.TryEnqueue(
bufferedLogger, logLevel, loggerInfo.Category!, eventId, joiner, exception,
((Func<TState, Exception?, string>)joiner.Formatter)((TState)joiner.State!, exception)))
{
// The record was buffered, so we skip logging it for now.
// When a caller needs to flush the buffer and calls ILoggerBuffer.Flush(),
// the buffer will internally call IBufferedLogger.LogRecords to emit log records.
continue;
}
}
#endif

try
{
loggerInfo.Logger.Log(logLevel, eventId, joiner, exception, static (s, e) =>
Original file line number Diff line number Diff line change
@@ -23,6 +23,9 @@ internal sealed class ExtendedLoggerFactory : ILoggerFactory
private readonly IDisposable? _enrichmentOptionsChangeTokenRegistration;
private readonly IDisposable? _redactionOptionsChangeTokenRegistration;
private readonly Action<IEnrichmentTagCollector>[] _enrichers;
#if NET9_0_OR_GREATER
private readonly ILoggingBufferProvider? _bufferProvider;
#endif
private readonly KeyValuePair<string, object?>[] _staticTags;
private readonly Func<DataClassificationSet, Redactor> _redactorProvider;
private volatile bool _disposed;
@@ -39,10 +42,18 @@ public ExtendedLoggerFactory(
IExternalScopeProvider? scopeProvider = null,
IOptionsMonitor<LoggerEnrichmentOptions>? enrichmentOptions = null,
IOptionsMonitor<LoggerRedactionOptions>? redactionOptions = null,
#if NET9_0_OR_GREATER
IRedactorProvider? redactorProvider = null,
ILoggingBufferProvider? bufferProvider = null)
#else
IRedactorProvider? redactorProvider = null)
#endif
#pragma warning restore S107 // Methods should not have too many parameters
{
_scopeProvider = scopeProvider;
#if NET9_0_OR_GREATER
_bufferProvider = bufferProvider;
#endif

_factoryOptions = factoryOptions == null || factoryOptions.Value == null ? new LoggerFactoryOptions() : factoryOptions.Value;

@@ -289,7 +300,12 @@ private LoggerConfig ComputeConfig(LoggerEnrichmentOptions? enrichmentOptions, L
enrichmentOptions.IncludeExceptionMessage,
enrichmentOptions.MaxStackTraceLength,
_redactorProvider,
#if NET9_0_OR_GREATER
redactionOptions.ApplyDiscriminator,
_bufferProvider);
#else
redactionOptions.ApplyDiscriminator);
#endif
}

private void UpdateEnrichmentOptions(LoggerEnrichmentOptions enrichmentOptions) => Config = ComputeConfig(enrichmentOptions, null);
Original file line number Diff line number Diff line change
@@ -20,7 +20,12 @@ public LoggerConfig(
bool includeExceptionMessage,
int maxStackTraceLength,
Func<DataClassificationSet, Redactor> getRedactor,
#if NET9_0_OR_GREATER
bool addRedactionDiscriminator,
ILoggingBufferProvider? bufferProvider)
#else
bool addRedactionDiscriminator)
#endif
{
#pragma warning restore S107 // Methods should not have too many parameters
StaticTags = staticTags;
@@ -31,6 +36,9 @@ public LoggerConfig(
IncludeExceptionMessage = includeExceptionMessage;
GetRedactor = getRedactor;
AddRedactionDiscriminator = addRedactionDiscriminator;
#if NET9_0_OR_GREATER
BufferProvider = bufferProvider;
#endif
}

public KeyValuePair<string, object?>[] StaticTags { get; }
@@ -41,4 +49,7 @@ public LoggerConfig(
public int MaxStackTraceLength { get; }
public Func<DataClassificationSet, Redactor> GetRedactor { get; }
public bool AddRedactionDiscriminator { get; }
#if NET9_0_OR_GREATER
public ILoggingBufferProvider? BufferProvider { get; }
#endif
}
Original file line number Diff line number Diff line change
@@ -7,6 +7,8 @@

<PropertyGroup>
<AllowUnsafeBlocks>true</AllowUnsafeBlocks>
<InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
<InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
<InjectSharedText>true</InjectSharedText>
<InjectSharedDataValidation>true</InjectSharedDataValidation>
<InjectSharedNumericExtensions>true</InjectSharedNumericExtensions>
@@ -31,7 +33,7 @@
</ItemGroup>

<ItemGroup>
<PackageReference Include="Microsoft.Bcl.TimeProvider" Condition="!$([MSBuild]::IsTargetFrameworkCompatible('$(TargetFramework)', 'net8.0'))" />
<PackageReference Include="Microsoft.Bcl.TimeProvider" />
<PackageReference Include="Microsoft.Extensions.Logging.Configuration" />
<PackageReference Include="System.Collections.Immutable" Condition="!$([MSBuild]::IsTargetFrameworkCompatible('$(TargetFramework)', 'net8.0'))" />
</ItemGroup>
Original file line number Diff line number Diff line change
@@ -0,0 +1,81 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Xunit;

namespace Microsoft.AspNetCore.Diagnostics.Logging.Test;

public class HttpRequestBufferLoggerBuilderExtensionsTests
{
[Fact]
public void AddHttpRequestBuffer_RegistersInDI()
{
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(builder =>
{
builder.AddHttpRequestBuffer(LogLevel.Warning);
});

var serviceProvider = serviceCollection.BuildServiceProvider();
var buffer = serviceProvider.GetService<ILoggingBuffer>();

Assert.NotNull(buffer);
Assert.IsAssignableFrom<HttpRequestBuffer>(buffer);
}

[Fact]
public void AddHttpRequestBufferProvider_RegistersInDI()
{
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(builder =>
{
builder.AddHttpRequestBufferProvider();
});
var serviceProvider = serviceCollection.BuildServiceProvider();
var bufferProvider = serviceProvider.GetService<ILoggingBufferProvider>();
Assert.NotNull(bufferProvider);
Assert.IsAssignableFrom<HttpRequestBufferProvider>(bufferProvider);
}

[Fact]
public void WhenArgumentNull_Throws()
{
var builder = null as ILoggingBuilder;
var configuration = null as IConfiguration;

Assert.Throws<ArgumentNullException>(() => builder!.AddHttpRequestBuffer(LogLevel.Warning));
Assert.Throws<ArgumentNullException>(() => builder!.AddHttpRequestBuffer(configuration!));
Assert.Throws<ArgumentNullException>(() => builder!.AddHttpRequestBufferProvider());
}

[Fact]
public void AddHttpRequestBufferConfiguration_RegistersInDI()
{
List<BufferFilterRule> expectedData =
[
new BufferFilterRule("Program.MyLogger", LogLevel.Information, 1),
new BufferFilterRule(null, LogLevel.Information, null),
];
ConfigurationBuilder configBuilder = new ConfigurationBuilder();
configBuilder.AddJsonFile("appsettings.json");
IConfigurationRoot configuration = configBuilder.Build();
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(builder =>
{
builder.AddHttpRequestBufferConfiguration(configuration);
});
var serviceProvider = serviceCollection.BuildServiceProvider();
var options = serviceProvider.GetService<IOptionsMonitor<HttpRequestBufferOptions>>();
Assert.NotNull(options);
Assert.NotNull(options.CurrentValue);
Assert.Equivalent(expectedData, options.CurrentValue.Rules);
}
}
#endif
Original file line number Diff line number Diff line change
@@ -4,6 +4,7 @@
#if NET8_0_OR_GREATER

using System;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using System.Globalization;
using System.Net.Http;
@@ -24,6 +25,9 @@
using Microsoft.Extensions.Http.Diagnostics;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Testing;
#if NET9_0_OR_GREATER
using Microsoft.Extensions.Options;
#endif
using Microsoft.Extensions.Time.Testing;
using Microsoft.Net.Http.Headers;
using Microsoft.Shared.Text;
@@ -714,6 +718,48 @@ await RunAsync(
});
}

#if NET9_0_OR_GREATER
[Fact]
public async Task HttpRequestBuffering()
{
var clock = new FakeTimeProvider(TimeProvider.System.GetUtcNow());

HttpRequestBufferOptions options = new()
{
SuspendAfterFlushDuration = TimeSpan.FromSeconds(0),
Rules = new List<BufferFilterRule>
{
new(null, LogLevel.Information, null),
}
};
var buffer = new HttpRequestBuffer(new StaticOptionsMonitor<HttpRequestBufferOptions>(options), clock);

await RunAsync<TestStartup>(
LogLevel.Information,
services => services.AddLogging(builder =>
{
builder.Services.AddScoped<ILoggingBuffer>(sp => buffer);
builder.Services.AddScoped(sp => buffer);
builder.AddHttpRequestBuffer(LogLevel.Information);
}),
async (logCollector, client, sp) =>
{
using var response = await client.GetAsync("/home").ConfigureAwait(false);

Assert.True(response.IsSuccessStatusCode);

Assert.Equal(0, logCollector.Count);

using var scope = sp.CreateScope();
var buffer = scope.ServiceProvider.GetRequiredService<HttpRequestBuffer>();
buffer.Flush();

await WaitForLogRecordsAsync(logCollector, _defaultLogTimeout);
Assert.Equal(1, logCollector.Count);
});
}
#endif

[Fact]
public async Task HttpLogging_LogRecordIsNotCreated_If_Disabled()
{
@@ -757,5 +803,19 @@ private class ThrowingEnricher : IHttpLogEnricher
{
public void Enrich(IEnrichmentTagCollector collector, HttpContext httpContext) => throw new InvalidOperationException();
}

#if NET9_0_OR_GREATER
private sealed class StaticOptionsMonitor<T> : IOptionsMonitor<T>
{
public StaticOptionsMonitor(T currentValue)
{
CurrentValue = currentValue;
}

public IDisposable? OnChange(Action<T, string> listener) => null;
public T Get(string? name) => CurrentValue;
public T CurrentValue { get; }
}
#endif
}
#endif
Original file line number Diff line number Diff line change
@@ -5,6 +5,8 @@
using Microsoft.Extensions.Compliance.Classification;
using Xunit;

namespace Microsoft.AspNetCore.Diagnostics.Logging.Test;

public class HeaderNormalizerTests
{
[Fact]
Original file line number Diff line number Diff line change
@@ -17,5 +17,17 @@
"userId": "EUII",
"userContent": "CustomerContent"
}
},
"Buffering": {
"Rules": [
{
"Category": "Program.MyLogger",
"LogLevel": "Information",
"EventId": 1
},
{
"LogLevel": "Information"
}
]
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,67 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#if NET9_0_OR_GREATER
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Xunit;

namespace Microsoft.Extensions.Logging.Test;

public class GlobalBufferLoggerBuilderExtensionsTests
{
[Fact]
public void AddGlobalBuffer_RegistersInDI()
{
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(builder =>
{
builder.AddGlobalBuffer(LogLevel.Warning);
});

var serviceProvider = serviceCollection.BuildServiceProvider();
var buffer = serviceProvider.GetService<ILoggingBuffer>();

Assert.NotNull(buffer);
Assert.IsAssignableFrom<GlobalBuffer>(buffer);
}

[Fact]
public void WhenArgumentNull_Throws()
{
var builder = null as ILoggingBuilder;
var configuration = null as IConfiguration;

Assert.Throws<ArgumentNullException>(() => builder!.AddGlobalBuffer(LogLevel.Warning));
Assert.Throws<ArgumentNullException>(() => builder!.AddGlobalBuffer(configuration!));
Assert.Throws<ArgumentNullException>(() => builder!.AddGlobalBufferProvider());
}

[Fact]
public void AddGlobalBufferConfiguration_RegistersInDI()
{
List<BufferFilterRule> expectedData =
[
new BufferFilterRule("Program.MyLogger", LogLevel.Information, 1),
new BufferFilterRule(null, LogLevel.Information, null),
];
ConfigurationBuilder configBuilder = new ConfigurationBuilder();
configBuilder.AddJsonFile("appsettings.json");
IConfigurationRoot configuration = configBuilder.Build();
var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(builder =>
{
builder.AddGlobalBufferConfiguration(configuration);
});
var serviceProvider = serviceCollection.BuildServiceProvider();
var options = serviceProvider.GetService<IOptionsMonitor<GlobalBufferOptions>>();
Assert.NotNull(options);
Assert.NotNull(options.CurrentValue);
Assert.Equivalent(expectedData, options.CurrentValue.Rules);
}
}
#endif
Original file line number Diff line number Diff line change
@@ -9,6 +9,9 @@
using Microsoft.Extensions.Diagnostics.Enrichment;
using Microsoft.Extensions.Logging.Testing;
using Microsoft.Extensions.Options;
#if NET9_0_OR_GREATER
using Microsoft.Extensions.Time.Testing;
#endif
using Moq;
using Xunit;

@@ -119,6 +122,58 @@ public static void FeatureEnablement(bool enableRedaction, bool enableEnrichment
}
}

#if NET9_0_OR_GREATER
[Fact]
public static void GlobalBuffering()
{
const string Category = "B1";
var clock = new FakeTimeProvider(TimeProvider.System.GetUtcNow());

GlobalBufferOptions options = new()
{
Duration = TimeSpan.FromSeconds(60),
SuspendAfterFlushDuration = TimeSpan.FromSeconds(0),
Rules = new List<BufferFilterRule>
{
new(null, LogLevel.Warning, null),
}
};
using var buffer = new GlobalBuffer(new StaticOptionsMonitor<GlobalBufferOptions>(options), clock);

using var provider = new Provider();
using var factory = Utils.CreateLoggerFactory(
builder =>
{
builder.AddProvider(provider);
builder.Services.AddSingleton(buffer);
builder.AddGlobalBufferProvider();
});

var logger = factory.CreateLogger(Category);
logger.LogWarning("MSG0");
logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2");

// nothing is logged because the buffer is not flushed
Assert.Equal(0, provider.Logger!.Collector.Count);

buffer.Flush();

// 2 log records emitted because the buffer was flushed
Assert.Equal(2, provider.Logger!.Collector.Count);

logger.LogWarning("MSG0");
logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2");

clock.Advance(options.Duration);

// forcefully clear buffer instead of async waiting for it to be done on its own which is inherently racy.
buffer.RemoveExpiredItems();

// still 2 because the buffer is cleared after Duration time elapses
Assert.Equal(2, provider.Logger!.Collector.Count);
}
#endif

[Theory]
[CombinatorialData]
public static void BagAndJoiner(bool objectVersion)
Original file line number Diff line number Diff line change
@@ -20,6 +20,7 @@
<ProjectReference Include="..\..\..\src\Libraries\Microsoft.Extensions.Compliance.Testing\Microsoft.Extensions.Compliance.Testing.csproj" />
<ProjectReference Include="..\..\..\src\Libraries\Microsoft.Extensions.Hosting.Testing\Microsoft.Extensions.Hosting.Testing.csproj" />
<ProjectReference Include="..\..\..\src\Libraries\Microsoft.Extensions.Diagnostics.Testing\Microsoft.Extensions.Diagnostics.Testing.csproj" />
<ProjectReference Include="..\..\..\src\Libraries\Microsoft.Extensions.TimeProvider.Testing\Microsoft.Extensions.TimeProvider.Testing.csproj" Condition="$([MSBuild]::IsTargetFrameworkCompatible('$(TargetFramework)', 'net9.0'))"/>
</ItemGroup>

<ItemGroup>
Original file line number Diff line number Diff line change
@@ -16,5 +16,17 @@
"MeterStateOverrides": {
"": "Disabled"
}
},
"Buffering": {
"Rules": [
{
"Category": "Program.MyLogger",
"LogLevel": "Information",
"EventId": 1
},
{
"LogLevel": "Information"
}
]
}
}