diff --git a/eng/MSBuild/Shared.props b/eng/MSBuild/Shared.props index 13719d54959..7cb15292288 100644 --- a/eng/MSBuild/Shared.props +++ b/eng/MSBuild/Shared.props @@ -50,4 +50,8 @@ + + + + diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBuffer.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBuffer.cs new file mode 100644 index 00000000000..40c84f6850c --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBuffer.cs @@ -0,0 +1,122 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Threading; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; +using Microsoft.Shared.Diagnostics; +using static Microsoft.Extensions.Logging.ExtendedLogger; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering; + +internal sealed class HttpRequestBuffer : ILoggingBuffer +{ + private readonly IOptionsMonitor _options; + private readonly IOptionsMonitor _globalOptions; + private readonly ConcurrentQueue _buffer; + private readonly TimeProvider _timeProvider = TimeProvider.System; + private readonly IBufferedLogger _bufferedLogger; + + private DateTimeOffset _lastFlushTimestamp; + private int _bufferSize; + + public HttpRequestBuffer(IBufferedLogger bufferedLogger, + IOptionsMonitor options, + IOptionsMonitor globalOptions) + { + _options = options; + _globalOptions = globalOptions; + _bufferedLogger = bufferedLogger; + _buffer = new ConcurrentQueue(); + } + + public bool TryEnqueue(LogEntry logEntry) + { + SerializedLogRecord serializedLogRecord = default; + if (logEntry.State is ModernTagJoiner modernTagJoiner) + { + if (!IsEnabled(logEntry.Category, logEntry.LogLevel, logEntry.EventId, modernTagJoiner)) + { + return false; + } + + serializedLogRecord = new SerializedLogRecord(logEntry.LogLevel, logEntry.EventId, _timeProvider.GetUtcNow(), modernTagJoiner, logEntry.Exception, + ((Func)(object)logEntry.Formatter)(modernTagJoiner, logEntry.Exception)); + } + else if (logEntry.State is LegacyTagJoiner legacyTagJoiner) + { + if (!IsEnabled(logEntry.Category, logEntry.LogLevel, logEntry.EventId, legacyTagJoiner)) + { + return false; + } + + serializedLogRecord = new SerializedLogRecord(logEntry.LogLevel, logEntry.EventId, _timeProvider.GetUtcNow(), legacyTagJoiner, logEntry.Exception, + ((Func)(object)logEntry.Formatter)(legacyTagJoiner, logEntry.Exception)); + } + else + { + Throw.InvalidOperationException($"Unsupported type of the log state object detected: {typeof(TState)}"); + } + + if (serializedLogRecord.SizeInBytes > _globalOptions.CurrentValue.MaxLogRecordSizeInBytes) + { + return false; + } + + _buffer.Enqueue(serializedLogRecord); + _ = Interlocked.Add(ref _bufferSize, serializedLogRecord.SizeInBytes); + + Trim(); + + return true; + } + + public void Flush() + { + _lastFlushTimestamp = _timeProvider.GetUtcNow(); + + SerializedLogRecord[] bufferedRecords = _buffer.ToArray(); + + _buffer.Clear(); + + var deserializedLogRecords = new List(bufferedRecords.Length); + foreach (var bufferedRecord in bufferedRecords) + { + deserializedLogRecords.Add( + new DeserializedLogRecord( + bufferedRecord.Timestamp, + bufferedRecord.LogLevel, + bufferedRecord.EventId, + bufferedRecord.Exception, + bufferedRecord.FormattedMessage, + bufferedRecord.Attributes)); + } + + _bufferedLogger.LogRecords(deserializedLogRecords); + } + + public bool IsEnabled(string category, LogLevel logLevel, EventId eventId, IReadOnlyList> attributes) + { + if (_timeProvider.GetUtcNow() < _lastFlushTimestamp + _globalOptions.CurrentValue.SuspendAfterFlushDuration) + { + return false; + } + + LogBufferingFilterRuleSelector.Select(_options.CurrentValue.Rules, category, logLevel, eventId, attributes, out LogBufferingFilterRule? rule); + + return rule is not null; + } + + private void Trim() + { + while (_bufferSize > _options.CurrentValue.MaxPerRequestBufferSizeInBytes && _buffer.TryDequeue(out var item)) + { + _ = Interlocked.Add(ref _bufferSize, -item.SizeInBytes); + } + } +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferHolder.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferHolder.cs new file mode 100644 index 00000000000..4200b5e5494 --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferHolder.cs @@ -0,0 +1,24 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Concurrent; +using Microsoft.Extensions.Diagnostics.Buffering; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering; + +internal sealed class HttpRequestBufferHolder +{ + private readonly ConcurrentDictionary _buffers = new(); + + public ILoggingBuffer GetOrAdd(string category, Func valueFactory) => + _buffers.GetOrAdd(category, valueFactory); + + public void Flush() + { + foreach (var buffer in _buffers.Values) + { + buffer.Flush(); + } + } +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferManager.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferManager.cs new file mode 100644 index 00000000000..bc9a469cbb9 --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferManager.cs @@ -0,0 +1,56 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using Microsoft.AspNetCore.Http; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering; + +internal sealed class HttpRequestBufferManager : HttpRequestLogBuffer +{ + private readonly LogBuffer _globalBuffer; + private readonly IHttpContextAccessor _httpContextAccessor; + private readonly IOptionsMonitor _requestOptions; + private readonly IOptionsMonitor _globalOptions; + + public HttpRequestBufferManager( + LogBuffer globalBuffer, + IHttpContextAccessor httpContextAccessor, + IOptionsMonitor requestOptions, + IOptionsMonitor globalOptions) + { + _globalBuffer = globalBuffer; + _httpContextAccessor = httpContextAccessor; + _requestOptions = requestOptions; + _globalOptions = globalOptions; + } + + public override void Flush() => _globalBuffer.Flush(); + + public override void FlushCurrentRequestLogs() + { + _httpContextAccessor.HttpContext?.RequestServices.GetService()?.Flush(); + } + + public override bool TryEnqueue(IBufferedLogger bufferedLogger, in LogEntry logEntry) + { + HttpContext? httpContext = _httpContextAccessor.HttpContext; + if (httpContext is null) + { + return _globalBuffer.TryEnqueue(bufferedLogger, logEntry); + } + + HttpRequestBufferHolder? bufferHolder = httpContext.RequestServices.GetService(); + ILoggingBuffer? buffer = bufferHolder?.GetOrAdd(logEntry.Category, _ => new HttpRequestBuffer(bufferedLogger, _requestOptions, _globalOptions)!); + + if (buffer is null) + { + return _globalBuffer.TryEnqueue(bufferedLogger, logEntry); + } + + return buffer.TryEnqueue(logEntry); + } +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferingLoggingBuilderExtensions.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferingLoggingBuilderExtensions.cs new file mode 100644 index 00000000000..8c61553e78c --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestBufferingLoggingBuilderExtensions.cs @@ -0,0 +1,107 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.AspNetCore.Diagnostics.Buffering; +using Microsoft.AspNetCore.Http; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.DependencyInjection.Extensions; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; +using Microsoft.Shared.DiagnosticIds; +using Microsoft.Shared.Diagnostics; + +namespace Microsoft.Extensions.Logging; + +/// +/// Lets you register HTTP request log buffering in a dependency injection container. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +public static class HttpRequestBufferingLoggingBuilderExtensions +{ + /// + /// Adds HTTP request log buffering to the logging infrastructure. + /// + /// The . + /// The to add. + /// The value of . + /// is . + /// + /// Matched logs will be buffered in a buffer specific to each HTTP request and can optionally be flushed and emitted during the request lifetime. + /// + public static ILoggingBuilder AddHttpRequestBuffering(this ILoggingBuilder builder, IConfiguration configuration) + { + _ = Throw.IfNull(builder); + _ = Throw.IfNull(configuration); + + _ = builder.Services.AddSingleton>(new HttpRequestLogBufferingConfigureOptions(configuration)); + + return builder + .AddHttpRequestBufferManager() + .AddGlobalBuffering(configuration); + } + + /// + /// Adds HTTP request log buffering to the logging infrastructure. + /// + /// The . + /// The buffer configuration delegate. + /// The value of . + /// is . + /// + /// Matched logs will be buffered in a buffer specific to each HTTP request and can optionally be flushed and emitted during the request lifetime. + /// + public static ILoggingBuilder AddHttpRequestBuffering(this ILoggingBuilder builder, Action configure) + { + _ = Throw.IfNull(builder); + _ = Throw.IfNull(configure); + + _ = builder.Services.Configure(configure); + + HttpRequestLogBufferingOptions options = new HttpRequestLogBufferingOptions(); + configure(options); + + return builder + .AddHttpRequestBufferManager() + .AddGlobalBuffering(opts => opts.Rules = options.Rules); + } + + /// + /// Adds HTTP request log buffering to the logging infrastructure. + /// + /// The . + /// The log level (and below) to apply the buffer to. + /// The value of . + /// is . + /// + /// Matched logs will be buffered in a buffer specific to each HTTP request and can optionally be flushed and emitted during the request lifetime. + /// + public static ILoggingBuilder AddHttpRequestBuffering(this ILoggingBuilder builder, LogLevel? logLevel = null) + { + _ = Throw.IfNull(builder); + + _ = builder.Services.Configure(options => options.Rules.Add(new LogBufferingFilterRule(logLevel: logLevel))); + + return builder + .AddHttpRequestBufferManager() + .AddGlobalBuffering(logLevel); + } + + internal static ILoggingBuilder AddHttpRequestBufferManager(this ILoggingBuilder builder) + { + builder.Services.TryAddScoped(); + builder.Services.TryAddSingleton(); + builder.Services.TryAddSingleton(sp => + { + var globalBufferManager = sp.GetRequiredService(); + return ActivatorUtilities.CreateInstance(sp, globalBufferManager); + }); + builder.Services.TryAddSingleton(sp => sp.GetRequiredService()); + builder.Services.TryAddSingleton(sp => sp.GetRequiredService()); + + return builder; + } +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBuffer.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBuffer.cs new file mode 100644 index 00000000000..6fca3fa5b82 --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBuffer.cs @@ -0,0 +1,20 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Shared.DiagnosticIds; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering; + +/// +/// Buffers HTTP request logs into circular buffers and drops them after some time if not flushed. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +public abstract class HttpRequestLogBuffer : LogBuffer +{ + /// + /// Flushes buffers and emits buffered logs for the current HTTP request. + /// + public abstract void FlushCurrentRequestLogs(); +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBufferingConfigureOptions.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBufferingConfigureOptions.cs new file mode 100644 index 00000000000..004fc1d89d5 --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBufferingConfigureOptions.cs @@ -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. + +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Options; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering; + +internal sealed class HttpRequestLogBufferingConfigureOptions : IConfigureOptions +{ + private const string BufferingKey = "Buffering"; + private readonly IConfiguration _configuration; + + public HttpRequestLogBufferingConfigureOptions(IConfiguration configuration) + { + _configuration = configuration; + } + + public void Configure(HttpRequestLogBufferingOptions options) + { + if (_configuration == null) + { + return; + } + + var section = _configuration.GetSection(BufferingKey); + if (!section.Exists()) + { + return; + } + + var parsedOptions = section.Get(); + if (parsedOptions is null) + { + return; + } + + foreach (var rule in parsedOptions.Rules) + { + options.Rules.Add(rule); + } + } +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBufferingOptions.cs b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBufferingOptions.cs new file mode 100644 index 00000000000..4b42320a4af --- /dev/null +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/HttpRequestLogBufferingOptions.cs @@ -0,0 +1,29 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Shared.DiagnosticIds; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering; + +/// +/// The options for HTTP request log buffering. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +public class HttpRequestLogBufferingOptions +{ + /// + /// Gets or sets the size in bytes of the buffer for a request. If the buffer size exceeds this limit, the oldest buffered log records will be dropped. + /// + /// TO DO: add validation. + public int MaxPerRequestBufferSizeInBytes { get; set; } = 5_000_000; + +#pragma warning disable CA2227 // Collection properties should be read only - setter is necessary for options pattern + /// + /// Gets or sets the collection of used for filtering log messages for the purpose of further buffering. + /// + public IList Rules { get; set; } = []; +#pragma warning restore CA2227 +} diff --git a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Microsoft.AspNetCore.Diagnostics.Middleware.csproj b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Microsoft.AspNetCore.Diagnostics.Middleware.csproj index 5484aa8f5af..0c42f2575ec 100644 --- a/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Microsoft.AspNetCore.Diagnostics.Middleware.csproj +++ b/src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Microsoft.AspNetCore.Diagnostics.Middleware.csproj @@ -8,17 +8,17 @@ $(NetCoreTargetFrameworks) + true true true - false - false + true true false false true false - true - true + false + false diff --git a/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Logging/FakeLogger.cs b/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Logging/FakeLogger.cs index 56973c9e78d..19d91bb8e27 100644 --- a/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Logging/FakeLogger.cs +++ b/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Logging/FakeLogger.cs @@ -5,7 +5,10 @@ using System.Collections; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics.CodeAnalysis; using System.Globalization; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Shared.DiagnosticIds; using Microsoft.Shared.Diagnostics; namespace Microsoft.Extensions.Logging.Testing; @@ -17,7 +20,7 @@ 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. /// -public class FakeLogger : ILogger +public class FakeLogger : ILogger, IBufferedLogger { private readonly ConcurrentDictionary _disabledLevels = new(); // used as a set, the value is ignored @@ -105,6 +108,25 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except /// public string? Category { get; } + /// + [Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] + public void LogRecords(IEnumerable records) + { + _ = Throw.IfNull(records); + + var l = new List(); + + foreach (var rec in records) + { +#pragma warning disable CA2201 // Do not raise reserved exception types + var exception = rec.Exception is not null ? new Exception(rec.Exception) : null; +#pragma warning restore CA2201 // Do not raise reserved exception types + var record = new FakeLogRecord(rec.LogLevel, rec.EventId, ConsumeTState(rec.Attributes), exception, rec.FormattedMessage ?? string.Empty, + l.ToArray(), Category, !_disabledLevels.ContainsKey(rec.LogLevel), rec.Timestamp); + Collector.AddRecord(record); + } + } + internal IExternalScopeProvider ScopeProvider { get; set; } = new LoggerExternalScopeProvider(); private static object? ConsumeTState(object? state) diff --git a/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Microsoft.Extensions.Diagnostics.Testing.csproj b/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Microsoft.Extensions.Diagnostics.Testing.csproj index 01f3b954262..6a30cf38e8f 100644 --- a/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Microsoft.Extensions.Diagnostics.Testing.csproj +++ b/src/Libraries/Microsoft.Extensions.Diagnostics.Testing/Microsoft.Extensions.Diagnostics.Testing.csproj @@ -1,4 +1,4 @@ - + Microsoft.Extensions.Diagnostics.Testing Hand-crafted fakes to make telemetry-related testing easier. @@ -7,11 +7,12 @@ + true true true true true - $(NoWarn);SYSLIB1100;SYSLIB1101 + $(NoWarn);IL2026;SYSLIB1100;SYSLIB1101 @@ -29,6 +30,7 @@ + diff --git a/src/Libraries/Microsoft.Extensions.Hosting.Testing/Microsoft.Extensions.Hosting.Testing.csproj b/src/Libraries/Microsoft.Extensions.Hosting.Testing/Microsoft.Extensions.Hosting.Testing.csproj index 63f7651746f..0d47e1d65b9 100644 --- a/src/Libraries/Microsoft.Extensions.Hosting.Testing/Microsoft.Extensions.Hosting.Testing.csproj +++ b/src/Libraries/Microsoft.Extensions.Hosting.Testing/Microsoft.Extensions.Hosting.Testing.csproj @@ -7,6 +7,7 @@ + true true true true diff --git a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj index cc5de094e47..056497ebf0f 100644 --- a/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj +++ b/src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj @@ -9,13 +9,12 @@ $(NoWarn);LA0006 + true true true true false true - true - true false true false diff --git a/src/Libraries/Microsoft.Extensions.Http.Resilience/Microsoft.Extensions.Http.Resilience.csproj b/src/Libraries/Microsoft.Extensions.Http.Resilience/Microsoft.Extensions.Http.Resilience.csproj index 8d280d747cb..68af32dae52 100644 --- a/src/Libraries/Microsoft.Extensions.Http.Resilience/Microsoft.Extensions.Http.Resilience.csproj +++ b/src/Libraries/Microsoft.Extensions.Http.Resilience/Microsoft.Extensions.Http.Resilience.csproj @@ -6,6 +6,7 @@ + true true true true diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/BufferedLoggerProxy.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/BufferedLoggerProxy.cs new file mode 100644 index 00000000000..9cda54b51b5 --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/BufferedLoggerProxy.cs @@ -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. + +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +internal sealed class BufferedLoggerProxy : IBufferedLogger +{ + private readonly ExtendedLogger _parentLogger; + + public BufferedLoggerProxy(ExtendedLogger parentLogger) + { + _parentLogger = parentLogger; + } + + public void LogRecords(IEnumerable records) + { + LoggerInformation[] loggerInformations = _parentLogger.Loggers; + foreach (LoggerInformation loggerInformation in loggerInformations) + { + ILogger iLogger = loggerInformation.Logger; + if (iLogger is IBufferedLogger bufferedLogger) + { + bufferedLogger.LogRecords(records); + } + else + { + foreach (BufferedLogRecord record in records) + { +#pragma warning disable CA2201 // Do not raise reserved exception types + iLogger.Log( + record.LogLevel, + record.EventId, + record.Attributes, + record.Exception is not null ? new Exception(record.Exception) : null, + (_, _) => record.FormattedMessage ?? string.Empty); +#pragma warning restore CA2201 // Do not raise reserved exception types + } + } + } + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBuffer.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBuffer.cs new file mode 100644 index 00000000000..b4fddaf8b65 --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBuffer.cs @@ -0,0 +1,133 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Threading; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; +using Microsoft.Shared.Diagnostics; +using static Microsoft.Extensions.Logging.ExtendedLogger; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +internal sealed class GlobalBuffer : ILoggingBuffer +{ + private readonly IOptionsMonitor _options; + private readonly ConcurrentQueue _buffer; + private readonly IBufferedLogger _bufferedLogger; + private readonly TimeProvider _timeProvider; + private DateTimeOffset _lastFlushTimestamp; + + private int _bufferSize; +#if NETFRAMEWORK + private object _netfxBufferLocker = new(); +#endif + + public GlobalBuffer(IBufferedLogger bufferedLogger, IOptionsMonitor options, TimeProvider timeProvider) + { + _options = options; + _timeProvider = timeProvider; + _buffer = new ConcurrentQueue(); + _bufferedLogger = bufferedLogger; + } + + public bool TryEnqueue(LogEntry logEntry) + { + SerializedLogRecord serializedLogRecord = default; + if (logEntry.State is ModernTagJoiner modernTagJoiner) + { + if (!IsEnabled(logEntry.Category, logEntry.LogLevel, logEntry.EventId, modernTagJoiner)) + { + return false; + } + + serializedLogRecord = new SerializedLogRecord(logEntry.LogLevel, logEntry.EventId, _timeProvider.GetUtcNow(), modernTagJoiner, logEntry.Exception, + ((Func)(object)logEntry.Formatter)(modernTagJoiner, logEntry.Exception)); + } + else if (logEntry.State is LegacyTagJoiner legacyTagJoiner) + { + if (!IsEnabled(logEntry.Category, logEntry.LogLevel, logEntry.EventId, legacyTagJoiner)) + { + return false; + } + + serializedLogRecord = new SerializedLogRecord(logEntry.LogLevel, logEntry.EventId, _timeProvider.GetUtcNow(), legacyTagJoiner, logEntry.Exception, + ((Func)(object)logEntry.Formatter)(legacyTagJoiner, logEntry.Exception)); + } + else + { + Throw.InvalidOperationException($"Unsupported type of the log state detected: {typeof(TState)}"); + } + + if (serializedLogRecord.SizeInBytes > _options.CurrentValue.MaxLogRecordSizeInBytes) + { + return false; + } + + _buffer.Enqueue(serializedLogRecord); + _ = Interlocked.Add(ref _bufferSize, serializedLogRecord.SizeInBytes); + + Trim(); + + return true; + } + + public void Flush() + { + _lastFlushTimestamp = _timeProvider.GetUtcNow(); + + SerializedLogRecord[] bufferedRecords = _buffer.ToArray(); + +#if NETFRAMEWORK + lock (_netfxBufferLocker) + { + while (_buffer.TryDequeue(out _)) + { + // Clear the buffer + } + } +#else + _buffer.Clear(); +#endif + + var deserializedLogRecords = new List(bufferedRecords.Length); + foreach (var bufferedRecord in bufferedRecords) + { + deserializedLogRecords.Add( + new DeserializedLogRecord( + bufferedRecord.Timestamp, + bufferedRecord.LogLevel, + bufferedRecord.EventId, + bufferedRecord.Exception, + bufferedRecord.FormattedMessage, + bufferedRecord.Attributes)); + } + + _bufferedLogger.LogRecords(deserializedLogRecords); + + // TO DO: adjust _buffersize after flushing. + } + + private void Trim() + { + while (_bufferSize > _options.CurrentValue.MaxBufferSizeInBytes && _buffer.TryDequeue(out var item)) + { + _ = Interlocked.Add(ref _bufferSize, -item.SizeInBytes); + } + } + + private bool IsEnabled(string category, LogLevel logLevel, EventId eventId, IReadOnlyList> attributes) + { + if (_timeProvider.GetUtcNow() < _lastFlushTimestamp + _options.CurrentValue.SuspendAfterFlushDuration) + { + return false; + } + + LogBufferingFilterRuleSelector.Select(_options.CurrentValue.Rules, category, logLevel, eventId, attributes, out LogBufferingFilterRule? rule); + + return rule is not null; + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBufferManager.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBufferManager.cs new file mode 100644 index 00000000000..f1a76ebb06b --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBufferManager.cs @@ -0,0 +1,41 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Concurrent; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +internal sealed class GlobalBufferManager : LogBuffer +{ + internal readonly ConcurrentDictionary Buffers = []; + private readonly IOptionsMonitor _options; + private readonly TimeProvider _timeProvider = TimeProvider.System; + + public GlobalBufferManager(IOptionsMonitor options) + { + _options = options; + } + + internal GlobalBufferManager(IOptionsMonitor options, TimeProvider timeProvider) + { + _timeProvider = timeProvider; + _options = options; + } + + public override void Flush() + { + foreach (var buffer in Buffers.Values) + { + buffer.Flush(); + } + } + + public override bool TryEnqueue(IBufferedLogger bufferedLogger, in LogEntry logEntry) + { + var buffer = Buffers.GetOrAdd(logEntry.Category, _ => new GlobalBuffer(bufferedLogger, _options, _timeProvider)); + return buffer.TryEnqueue(logEntry); + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBufferingLoggingBuilderExtensions.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBufferingLoggingBuilderExtensions.cs new file mode 100644 index 00000000000..cb48c3fe74e --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBufferingLoggingBuilderExtensions.cs @@ -0,0 +1,91 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.DependencyInjection.Extensions; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; +using Microsoft.Shared.DiagnosticIds; +using Microsoft.Shared.Diagnostics; + +namespace Microsoft.Extensions.Logging; + +/// +/// Lets you register log buffering in a dependency injection container. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +public static class GlobalBufferingLoggingBuilderExtensions +{ + /// + /// Adds global log buffering to the logging infrastructure. + /// + /// The . + /// The to add. + /// The value of . + /// is . + /// + /// Matched logs will be buffered and can optionally be flushed and emitted. + /// + public static ILoggingBuilder AddGlobalBuffering(this ILoggingBuilder builder, IConfiguration configuration) + { + _ = Throw.IfNull(builder); + _ = Throw.IfNull(configuration); + + _ = builder.Services.AddSingleton>(new GlobalLogBufferingConfigureOptions(configuration)); + + return builder.AddGlobalBufferManager(); + } + + /// + /// Adds global log buffering to the logging infrastructure. + /// + /// The . + /// Configure buffer options. + /// The value of . + /// is . + /// + /// Matched logs will be buffered and can optionally be flushed and emitted. + /// + public static ILoggingBuilder AddGlobalBuffering(this ILoggingBuilder builder, Action configure) + { + _ = Throw.IfNull(builder); + _ = Throw.IfNull(configure); + + _ = builder.Services.Configure(configure); + + return builder.AddGlobalBufferManager(); + } + + /// + /// Adds global log buffering to the logging infrastructure. + /// + /// The . + /// The log level (and below) to apply the buffer to. + /// The value of . + /// is . + /// + /// Matched logs will be buffered and can optionally be flushed and emitted. + /// + public static ILoggingBuilder AddGlobalBuffering(this ILoggingBuilder builder, LogLevel? logLevel = null) + { + _ = Throw.IfNull(builder); + + _ = builder.Services.Configure(options => options.Rules.Add(new LogBufferingFilterRule(logLevel: logLevel))); + + return builder.AddGlobalBufferManager(); + } + + internal static ILoggingBuilder AddGlobalBufferManager(this ILoggingBuilder builder) + { + _ = builder.Services.AddExtendedLoggerFeactory(); + + builder.Services.TryAddSingleton(); + builder.Services.TryAddSingleton(static sp => sp.GetRequiredService()); + + return builder; + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalLogBufferingConfigureOptions.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalLogBufferingConfigureOptions.cs new file mode 100644 index 00000000000..f595567bdee --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalLogBufferingConfigureOptions.cs @@ -0,0 +1,53 @@ +// 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.Configuration; +using Microsoft.Extensions.Options; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +internal sealed class GlobalLogBufferingConfigureOptions : IConfigureOptions +{ + private const string BufferingKey = "Buffering"; + private readonly IConfiguration _configuration; + + public GlobalLogBufferingConfigureOptions(IConfiguration configuration) + { + _configuration = configuration; + } + + public void Configure(GlobalLogBufferingOptions options) + { + if (_configuration == null) + { + return; + } + + var section = _configuration.GetSection(BufferingKey); + if (!section.Exists()) + { + return; + } + + var parsedOptions = section.Get(); + if (parsedOptions is null) + { + return; + } + + if (parsedOptions.MaxLogRecordSizeInBytes > 0) + { + options.MaxLogRecordSizeInBytes = parsedOptions.MaxLogRecordSizeInBytes; + } + + if (parsedOptions.MaxBufferSizeInBytes > 0) + { + options.MaxBufferSizeInBytes = parsedOptions.MaxBufferSizeInBytes; + } + + foreach (var rule in parsedOptions.Rules) + { + options.Rules.Add(rule); + } + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalLogBufferingOptions.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalLogBufferingOptions.cs new file mode 100644 index 00000000000..6d96908341e --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalLogBufferingOptions.cs @@ -0,0 +1,45 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Shared.DiagnosticIds; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// The options for global log buffering. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +public class GlobalLogBufferingOptions +{ + /// + /// Gets or sets the time to suspend the buffering after flushing. + /// + /// + /// 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 time. + /// + public TimeSpan SuspendAfterFlushDuration { get; set; } = TimeSpan.FromSeconds(30); + + /// + /// Gets or sets the maxiumum size of each individual log record in bytes. If the size of a log record exceeds this limit, it won't be buffered. + /// + /// TO DO: add validation. + public int MaxLogRecordSizeInBytes { get; set; } = 50_000; + + /// + /// Gets or sets the maximum size of the buffer in bytes. If adding a new log entry would cause the buffer size to exceed this limit, + /// the oldest buffered log records will be dropped to make room. + /// + /// TO DO: add validation. + public int MaxBufferSizeInBytes { get; set; } = 500_000_000; + +#pragma warning disable CA2227 // Collection properties should be read only - setter is necessary for options pattern + /// + /// Gets or sets the collection of used for filtering log messages for the purpose of further buffering. + /// + public IList Rules { get; set; } = []; +#pragma warning restore CA2227 +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBuffer.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBuffer.cs new file mode 100644 index 00000000000..343662a0958 --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBuffer.cs @@ -0,0 +1,31 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Shared.DiagnosticIds; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// Buffers logs into circular buffers and drops them after some time if not flushed. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +#pragma warning disable S1694 // An abstract class should have both abstract and concrete methods +public abstract class LogBuffer +#pragma warning restore S1694 // An abstract class should have both abstract and concrete methods +{ + /// + /// Flushes the buffer and emits all buffered logs. + /// + public abstract void Flush(); + + /// + /// Enqueues a log record in the underlying buffer, if available. + /// + /// A logger capable of logging buffered log records. + /// A log entry to be buffered. + /// Type of the log state in the instance. + /// if the log record was buffered; otherwise, . + public abstract bool TryEnqueue(IBufferedLogger bufferedLogger, in LogEntry logEntry); +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRule.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRule.cs new file mode 100644 index 00000000000..affc131bf40 --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRule.cs @@ -0,0 +1,63 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; +using Microsoft.Shared.DiagnosticIds; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// Defines a rule used to filter log messages for purposes of further buffering. +/// +[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)] +public class LogBufferingFilterRule +{ + /// + /// Initializes a new instance of the class. + /// + /// The category name to use in this filter rule. + /// The to use in this filter rule. + /// The event ID to use in this filter rule. + /// The event name to use in this filter rule. + /// The log state attributes to use in this filter tule. + public LogBufferingFilterRule( + string? categoryName = null, + LogLevel? logLevel = null, + int? eventId = null, + string? eventName = null, + IReadOnlyList>? attributes = null) + { + CategoryName = categoryName; + LogLevel = logLevel; + EventId = eventId; + EventName = eventName; + Attributes = attributes; + } + + /// + /// Gets the logger category name this rule applies to. + /// + public string? CategoryName { get; } + + /// + /// Gets the maximum of messages this rule applies to. + /// + public LogLevel? LogLevel { get; } + + /// + /// Gets the evnet ID of messages where this rule applies to. + /// + public int? EventId { get; } + + /// + /// Gets the name of the event this rule applies to. + /// + public string? EventName { get; } + + /// + /// Gets the log state attributes of messages where this rules applies to. + /// + public IReadOnlyList>? Attributes { get; } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRuleSelector.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRuleSelector.cs new file mode 100644 index 00000000000..08bf5a88307 --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRuleSelector.cs @@ -0,0 +1,173 @@ +// 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 System.Linq; +using Microsoft.Extensions.Logging; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// Selects the best rule from the list of rules for a given log event. +/// +internal static class LogBufferingFilterRuleSelector +{ + private static readonly IEqualityComparer> _stringifyComparer = new StringifyComprarer(); + + /// + /// Selects the best rule from the list of rules for a given log event. + /// + /// The list of rules to select from. + /// The category of the log event. + /// The log level of the log event. + /// The event id of the log event. + /// The log state attributes of the log event. + /// The best rule that matches the log event. + public static void Select(IList rules, string category, LogLevel logLevel, + EventId eventId, IReadOnlyList>? attributes, out LogBufferingFilterRule? bestRule) + { + 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 + + LogBufferingFilterRule? current = null; + if (rules is not null) + { + foreach (LogBufferingFilterRule rule in rules) + { + if (IsBetter(rule, current, category, logLevel, eventId, attributes)) + { + current = rule; + } + } + } + + if (current != null) + { + bestRule = current; + } + } + + private static bool IsBetter(LogBufferingFilterRule rule, LogBufferingFilterRule? current, string category, + LogLevel logLevel, EventId eventId, IReadOnlyList>? attributes) + { + // 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.CategoryName; + 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 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; + } + } + + // Skip rules with inapplicable attributes + if (rule.Attributes?.Count > 0 && attributes?.Count > 0) + { + foreach (KeyValuePair ruleAttribute in rule.Attributes) + { + if (!attributes.Contains(ruleAttribute, _stringifyComparer)) + { + return false; + } + } + } + + // Decide whose category is better - rule vs current + if (current?.CategoryName != null) + { + if (rule.CategoryName == null) + { + return false; + } + + if (current.CategoryName.Length > rule.CategoryName.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; + } + } + + // Decide whose attributes are better - rule vs current + if (current?.Attributes?.Count > 0) + { + if (rule.Attributes is null || rule.Attributes.Count == 0) + { + return false; + } + + if (rule.Attributes.Count < current.Attributes.Count) + { + return false; + } + } + + return true; + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/StringifyComprarer.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/StringifyComprarer.cs new file mode 100644 index 00000000000..fbec3961880 --- /dev/null +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Buffering/StringifyComprarer.cs @@ -0,0 +1,35 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +internal sealed class StringifyComprarer : IEqualityComparer> +{ + public bool Equals(KeyValuePair x, KeyValuePair y) + { + if (x.Key != y.Key) + { + return false; + } + + if (x.Value is null && y.Value is null) + { + return true; + } + + if (x.Value is null || y.Value is null) + { + return false; + } + + return x.Value.ToString() == y.Value.ToString(); + } + + public int GetHashCode(KeyValuePair obj) + { + return HashCode.Combine(obj.Key, obj.Value?.ToString()); + } +} diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLogger.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLogger.cs index 693637781c8..1c44834b5cf 100644 --- a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLogger.cs +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLogger.cs @@ -4,7 +4,8 @@ using System; using System.Collections.Generic; using System.Diagnostics; -using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Shared.Pools; namespace Microsoft.Extensions.Logging; @@ -31,10 +32,19 @@ internal sealed partial class ExtendedLogger : ILogger public MessageLogger[] MessageLoggers { get; set; } = Array.Empty(); public ScopeLogger[] ScopeLoggers { get; set; } = Array.Empty(); + private readonly LogBuffer? _bufferingManager; + private readonly IBufferedLogger? _bufferedLogger; + public ExtendedLogger(ExtendedLoggerFactory factory, LoggerInformation[] loggers) { _factory = factory; Loggers = loggers; + + _bufferingManager = _factory.Config.BufferingManager; + if (_bufferingManager is not null) + { + _bufferedLogger = new BufferedLoggerProxy(this); + } } public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) @@ -261,11 +271,35 @@ private void ModernPath(LogLevel logLevel, EventId eventId, LoggerMessageState m RecordException(exception, joiner.EnrichmentTagCollector, config); } + bool shouldBuffer = true; for (int i = 0; i < loggers.Length; i++) { ref readonly MessageLogger loggerInfo = ref loggers[i]; if (loggerInfo.IsNotFilteredOut(logLevel)) { + if (shouldBuffer) + { + if (_bufferingManager is not null) + { + var logEntry = new LogEntry(logLevel, loggerInfo.Category!, eventId, joiner, exception, static (s, e) => + { + var fmt = s.Formatter!; + return fmt(s.State!, e); + }); + var wasBuffered = _bufferingManager.TryEnqueue(_bufferedLogger!, logEntry); + + if (wasBuffered) + { + // The record was buffered, so we skip logging it here and for all other loggers. + // When a caller needs to flush the buffer and calls Flush(), + // the buffer manager will internally call IBufferedLogger.LogRecords to emit log records. + break; + } + } + + shouldBuffer = false; + } + try { loggerInfo.LoggerLog(logLevel, eventId, joiner, exception, static (s, e) => @@ -345,11 +379,36 @@ private void LegacyPath(LogLevel logLevel, EventId eventId, TState state RecordException(exception, joiner.EnrichmentTagCollector, config); } + bool shouldBuffer = true; for (int i = 0; i < loggers.Length; i++) { ref readonly MessageLogger loggerInfo = ref loggers[i]; if (loggerInfo.IsNotFilteredOut(logLevel)) { + if (shouldBuffer) + { + if (_bufferingManager is not null) + { + var logEntry = new LogEntry(logLevel, loggerInfo.Category!, eventId, joiner, exception, static (s, e) => + { + var fmt = (Func)s.Formatter!; + return fmt((TState)s.State!, e); + }); + bool wasBuffered = _bufferingManager.TryEnqueue(_bufferedLogger!, in logEntry); + + if (wasBuffered) + { + // The record was buffered, so we skip logging it here and for all other loggers. + // When a caller needs to flush the buffer and calls Flush(), + // the buffer manager will internally call IBufferedLogger.LogRecords to emit log records. + break; + } + + } + + shouldBuffer = false; + } + try { loggerInfo.Logger.Log(logLevel, eventId, joiner, exception, static (s, e) => diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLoggerFactory.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLoggerFactory.cs index 9a98b8446f4..f24cc911f9f 100644 --- a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLoggerFactory.cs +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLoggerFactory.cs @@ -7,6 +7,7 @@ using System.Linq; using Microsoft.Extensions.Compliance.Classification; using Microsoft.Extensions.Compliance.Redaction; +using Microsoft.Extensions.Diagnostics.Buffering; using Microsoft.Extensions.Diagnostics.Enrichment; using Microsoft.Extensions.Options; using Microsoft.Shared.Diagnostics; @@ -23,6 +24,7 @@ internal sealed class ExtendedLoggerFactory : ILoggerFactory private readonly IDisposable? _enrichmentOptionsChangeTokenRegistration; private readonly IDisposable? _redactionOptionsChangeTokenRegistration; private readonly Action[] _enrichers; + private readonly LogBuffer? _bufferingManager; private readonly KeyValuePair[] _staticTags; private readonly Func _redactorProvider; private volatile bool _disposed; @@ -39,10 +41,12 @@ public ExtendedLoggerFactory( IExternalScopeProvider? scopeProvider = null, IOptionsMonitor? enrichmentOptions = null, IOptionsMonitor? redactionOptions = null, - IRedactorProvider? redactorProvider = null) + IRedactorProvider? redactorProvider = null, + LogBuffer? bufferingManager = null) #pragma warning restore S107 // Methods should not have too many parameters { _scopeProvider = scopeProvider; + _bufferingManager = bufferingManager; _factoryOptions = factoryOptions == null || factoryOptions.Value == null ? new LoggerFactoryOptions() : factoryOptions.Value; @@ -289,13 +293,14 @@ private LoggerConfig ComputeConfig(LoggerEnrichmentOptions? enrichmentOptions, L enrichmentOptions.IncludeExceptionMessage, enrichmentOptions.MaxStackTraceLength, _redactorProvider, - redactionOptions.ApplyDiscriminator); + redactionOptions.ApplyDiscriminator, + _bufferingManager); } private void UpdateEnrichmentOptions(LoggerEnrichmentOptions enrichmentOptions) => Config = ComputeConfig(enrichmentOptions, null); private void UpdateRedactionOptions(LoggerRedactionOptions redactionOptions) => Config = ComputeConfig(null, redactionOptions); - private struct ProviderRegistration + public struct ProviderRegistration { public ILoggerProvider Provider; public bool ShouldDispose; diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggerConfig.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggerConfig.cs index 34716ca4e38..80c953e1335 100644 --- a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggerConfig.cs +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggerConfig.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using Microsoft.Extensions.Compliance.Classification; using Microsoft.Extensions.Compliance.Redaction; +using Microsoft.Extensions.Diagnostics.Buffering; using Microsoft.Extensions.Diagnostics.Enrichment; namespace Microsoft.Extensions.Logging; @@ -20,7 +21,8 @@ public LoggerConfig( bool includeExceptionMessage, int maxStackTraceLength, Func getRedactor, - bool addRedactionDiscriminator) + bool addRedactionDiscriminator, + LogBuffer? bufferingManager) { #pragma warning restore S107 // Methods should not have too many parameters StaticTags = staticTags; @@ -31,6 +33,7 @@ public LoggerConfig( IncludeExceptionMessage = includeExceptionMessage; GetRedactor = getRedactor; AddRedactionDiscriminator = addRedactionDiscriminator; + BufferingManager = bufferingManager; } public KeyValuePair[] StaticTags { get; } @@ -41,4 +44,5 @@ public LoggerConfig( public int MaxStackTraceLength { get; } public Func GetRedactor { get; } public bool AddRedactionDiscriminator { get; } + public LogBuffer? BufferingManager { get; } } diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingEnrichmentExtensions.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingEnrichmentExtensions.cs index 1d4262b454e..87563067283 100644 --- a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingEnrichmentExtensions.cs +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingEnrichmentExtensions.cs @@ -34,9 +34,10 @@ public static ILoggingBuilder EnableEnrichment(this ILoggingBuilder builder, Act _ = Throw.IfNull(builder); _ = Throw.IfNull(configure); - builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton()); - _ = builder.Services.Configure(configure); - _ = builder.Services.AddOptionsWithValidateOnStart(); + _ = builder.Services + .AddExtendedLoggerFeactory() + .Configure(configure) + .AddOptionsWithValidateOnStart(); return builder; } @@ -52,9 +53,24 @@ public static ILoggingBuilder EnableEnrichment(this ILoggingBuilder builder, ICo _ = Throw.IfNull(builder); _ = Throw.IfNull(section); - builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton()); - _ = builder.Services.AddOptionsWithValidateOnStart().Bind(section); + _ = builder.Services + .AddExtendedLoggerFeactory() + .AddOptionsWithValidateOnStart().Bind(section); return builder; } + + /// + /// Adds a default implementation of the to the service collection. + /// + /// The . + /// The value of . + internal static IServiceCollection AddExtendedLoggerFeactory(this IServiceCollection services) + { + _ = Throw.IfNull(services); + + services.TryAddEnumerable(ServiceDescriptor.Singleton()); + + return services; + } } diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingRedactionExtensions.cs b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingRedactionExtensions.cs index 4ec3ea9ef3e..284e24f10ea 100644 --- a/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingRedactionExtensions.cs +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggingRedactionExtensions.cs @@ -4,7 +4,6 @@ using System; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.DependencyInjection; -using Microsoft.Extensions.DependencyInjection.Extensions; using Microsoft.Extensions.Logging; using Microsoft.Shared.Diagnostics; @@ -34,8 +33,9 @@ public static ILoggingBuilder EnableRedaction(this ILoggingBuilder builder, Acti _ = Throw.IfNull(builder); _ = Throw.IfNull(configure); - builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton()); - _ = builder.Services.Configure(configure); + _ = builder.Services + .AddExtendedLoggerFeactory() + .Configure(configure); return builder; } @@ -51,8 +51,9 @@ public static ILoggingBuilder EnableRedaction(this ILoggingBuilder builder, ICon _ = Throw.IfNull(builder); _ = Throw.IfNull(section); - builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton()); - _ = builder.Services.AddOptions().Bind(section); + _ = builder.Services + .AddExtendedLoggerFeactory() + .AddOptions().Bind(section); return builder; } diff --git a/src/Libraries/Microsoft.Extensions.Telemetry/Microsoft.Extensions.Telemetry.csproj b/src/Libraries/Microsoft.Extensions.Telemetry/Microsoft.Extensions.Telemetry.csproj index 3d39591e547..6c19aab939e 100644 --- a/src/Libraries/Microsoft.Extensions.Telemetry/Microsoft.Extensions.Telemetry.csproj +++ b/src/Libraries/Microsoft.Extensions.Telemetry/Microsoft.Extensions.Telemetry.csproj @@ -6,17 +6,22 @@ + true true - true + true + true true + true + true + true true true true - true - true + true true true - + $(NoWarn);IL2026 + normal @@ -31,9 +36,11 @@ - + + + diff --git a/src/Shared/LoggingBuffering/DeserializedLogRecord.cs b/src/Shared/LoggingBuffering/DeserializedLogRecord.cs new file mode 100644 index 00000000000..02a5cf1712d --- /dev/null +++ b/src/Shared/LoggingBuffering/DeserializedLogRecord.cs @@ -0,0 +1,65 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +#if !SHARED_PROJECT || NET9_0_OR_GREATER +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// Represents a log record deserialized from somewhere, such as buffer. +/// +internal sealed class DeserializedLogRecord : BufferedLogRecord +{ + /// + /// Initializes a new instance of the class. + /// + /// The time when the log record was first created. + /// Logging severity level. + /// Event ID. + /// An exception string for this record. + /// The formatted log message. + /// The set of name/value pairs associated with the record. + public DeserializedLogRecord( + DateTimeOffset timestamp, + LogLevel logLevel, + EventId eventId, + string? exception, + string? formattedMessage, + IReadOnlyList> attributes) + { + _timestamp = timestamp; + _logLevel = logLevel; + _eventId = eventId; + _exception = exception; + _formattedMessage = formattedMessage; + _attributes = attributes; + } + + /// + public override DateTimeOffset Timestamp => _timestamp; + private DateTimeOffset _timestamp; + + /// + public override LogLevel LogLevel => _logLevel; + private LogLevel _logLevel; + + /// + public override EventId EventId => _eventId; + private EventId _eventId; + + /// + public override string? Exception => _exception; + private string? _exception; + + /// + public override string? FormattedMessage => _formattedMessage; + private string? _formattedMessage; + + /// + public override IReadOnlyList> Attributes => _attributes; + private IReadOnlyList> _attributes; +} +#endif diff --git a/src/Shared/LoggingBuffering/ILoggingBuffer.cs b/src/Shared/LoggingBuffering/ILoggingBuffer.cs new file mode 100644 index 00000000000..0ff1fb2c872 --- /dev/null +++ b/src/Shared/LoggingBuffering/ILoggingBuffer.cs @@ -0,0 +1,24 @@ +// 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.Abstractions; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// Interface for a logging buffer. +/// +internal interface ILoggingBuffer +{ + /// + /// Enqueues a log record in the underlying buffer. + /// + /// Type of the log state in the instance. + /// if the log record was buffered; otherwise, . + bool TryEnqueue(LogEntry logEntry); + + /// + /// Flushes the buffer. + /// + void Flush(); +} diff --git a/src/Shared/LoggingBuffering/SerializedLogRecord.cs b/src/Shared/LoggingBuffering/SerializedLogRecord.cs new file mode 100644 index 00000000000..561220e2094 --- /dev/null +++ b/src/Shared/LoggingBuffering/SerializedLogRecord.cs @@ -0,0 +1,101 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Logging; + +namespace Microsoft.Extensions.Diagnostics.Buffering; + +/// +/// Represents a log record that has been serialized for purposes of buffering or similar. +/// +#pragma warning disable CA1815 // Override equals and operator equals on value types - not used for this struct, would be dead code +internal readonly struct SerializedLogRecord +{ + /// + /// Initializes a new instance of the struct. + /// + /// Logging severity level. + /// Event ID. + /// The time when the log record was first created. + /// The set of name/value pairs associated with the record. + /// An exception string for this record. + /// The formatted log message. + public SerializedLogRecord( + LogLevel logLevel, + EventId eventId, + DateTimeOffset timestamp, + IReadOnlyList> attributes, + Exception? exception, + string formattedMessage) + { + LogLevel = logLevel; + EventId = eventId; + Timestamp = timestamp; + + List> serializedAttributes = []; + if (attributes is not null) + { + serializedAttributes = new List>(attributes.Count); + for (int i = 0; i < attributes.Count; i++) + { + string key = attributes[i].Key; + string value = attributes[i].Value?.ToString() ?? string.Empty; + serializedAttributes.Add(new KeyValuePair(key, value)); + + SizeInBytes += key.Length * sizeof(char); + SizeInBytes += value.Length * sizeof(char); + } + } + + Attributes = serializedAttributes; + + Exception = exception?.Message; + if (Exception is not null) + { + SizeInBytes += Exception.Length * sizeof(char); + } + + FormattedMessage = formattedMessage; + if (FormattedMessage is not null) + { + SizeInBytes += FormattedMessage.Length * sizeof(char); + } + } + + /// + /// Gets the variable set of name/value pairs associated with the record. + /// + public IReadOnlyList> Attributes { get; } + + /// + /// Gets the formatted log message. + /// + public string? FormattedMessage { get; } + + /// + /// Gets an exception string for this record. + /// + public string? Exception { get; } + + /// + /// Gets the time when the log record was first created. + /// + public DateTimeOffset Timestamp { get; } + + /// + /// Gets the record's logging severity level. + /// + public LogLevel LogLevel { get; } + + /// + /// Gets the record's event ID. + /// + public EventId EventId { get; } + + /// + /// Gets the approximate size of the serialized log record in bytes. + /// + public int SizeInBytes { get; init; } +} diff --git a/src/Shared/Shared.csproj b/src/Shared/Shared.csproj index 439c3788557..d25c011a05f 100644 --- a/src/Shared/Shared.csproj +++ b/src/Shared/Shared.csproj @@ -29,6 +29,7 @@ + diff --git a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Buffering/HttpRequestBufferLoggerBuilderExtensionsTests.cs b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Buffering/HttpRequestBufferLoggerBuilderExtensionsTests.cs new file mode 100644 index 00000000000..52cd5132af9 --- /dev/null +++ b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Buffering/HttpRequestBufferLoggerBuilderExtensionsTests.cs @@ -0,0 +1,62 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Diagnostics.Buffering; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; +using Xunit; + +namespace Microsoft.AspNetCore.Diagnostics.Buffering.Test; + +public class HttpRequestBufferLoggerBuilderExtensionsTests +{ + [Fact] + public void AddHttpRequestBuffering_RegistersInDI() + { + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(builder => + { + builder.AddHttpRequestBuffering(LogLevel.Warning); + }); + + var serviceProvider = serviceCollection.BuildServiceProvider(); + var buffer = serviceProvider.GetService(); + + Assert.NotNull(buffer); + Assert.IsAssignableFrom(buffer); + } + + [Fact] + public void WhenArgumentNull_Throws() + { + var builder = null as ILoggingBuilder; + var configuration = null as IConfiguration; + + Assert.Throws(() => builder!.AddHttpRequestBuffering(LogLevel.Warning)); + Assert.Throws(() => builder!.AddHttpRequestBuffering(configuration!)); + } + + [Fact] + public void AddHttpRequestBufferConfiguration_RegistersInDI() + { + List expectedData = + [ + new LogBufferingFilterRule(categoryName: "Program.MyLogger", logLevel: LogLevel.Information, eventId: 1, eventName: "number one"), + new LogBufferingFilterRule(logLevel: LogLevel.Information), + ]; + ConfigurationBuilder configBuilder = new ConfigurationBuilder(); + configBuilder.AddJsonFile("appsettings.json"); + IConfigurationRoot configuration = configBuilder.Build(); + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(b => b.AddHttpRequestBuffering(configuration)); + var serviceProvider = serviceCollection.BuildServiceProvider(); + var options = serviceProvider.GetService>(); + Assert.NotNull(options); + Assert.NotNull(options.CurrentValue); + Assert.Equivalent(expectedData, options.CurrentValue.Rules); + } +} diff --git a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/AcceptanceTests.cs b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/AcceptanceTests.cs index 869b0716e17..abbf4fc5752 100644 --- a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/AcceptanceTests.cs +++ b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/AcceptanceTests.cs @@ -11,6 +11,7 @@ using System.Net.Mime; using System.Threading.Tasks; using Microsoft.AspNetCore.Builder; +using Microsoft.AspNetCore.Diagnostics.Buffering; using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.HttpLogging; @@ -55,6 +56,30 @@ public static void Configure(IApplicationBuilder app) app.UseRouting(); app.UseHttpLogging(); + app.Map("/flushrequestlogs", static x => + x.Run(static async context => + { + await context.Request.Body.DrainAsync(default); + + // normally, this would be a Middleware and HttpRequestLogBuffer would be injected via constructor + var bufferManager = context.RequestServices.GetService(); + bufferManager?.FlushCurrentRequestLogs(); + })); + + app.Map("/flushalllogs", static x => + x.Run(static async context => + { + await context.Request.Body.DrainAsync(default); + + // normally, this would be a Middleware and HttpRequestLogBuffer would be injected via constructor + var bufferManager = context.RequestServices.GetService(); + if (bufferManager is not null) + { + bufferManager.FlushCurrentRequestLogs(); + bufferManager.Flush(); + } + })); + app.Map("/error", static x => x.Run(static async context => { @@ -714,6 +739,50 @@ await RunAsync( }); } + [Fact] + public async Task HttpRequestBuffering() + { + await RunAsync( + LogLevel.Trace, + services => services + .AddLogging(builder => + { + // enable Microsoft.AspNetCore.Routing.Matching.DfaMatcher debug logs + // which are produced by ASP.NET Core within HTTP context. + // This is what is going to be buffered and tested. + builder.AddFilter("Microsoft.AspNetCore.Routing.Matching.DfaMatcher", LogLevel.Debug); + + // Disable HTTP logging middleware, otherwise even though they are not buffered, + // they will be logged as usual and contaminate test results: + builder.AddFilter("Microsoft.AspNetCore.HttpLogging", LogLevel.None); + + builder.AddHttpRequestBuffering(LogLevel.Debug); + }), + async (logCollector, client, sp) => + { + // just HTTP request logs: + using var response = await client.GetAsync("/flushrequestlogs").ConfigureAwait(false); + Assert.True(response.IsSuccessStatusCode); + await WaitForLogRecordsAsync(logCollector, _defaultLogTimeout); + Assert.Equal(1, logCollector.Count); + Assert.Equal(LogLevel.Debug, logCollector.LatestRecord.Level); + Assert.Equal("Microsoft.AspNetCore.Routing.Matching.DfaMatcher", logCollector.LatestRecord.Category); + + // HTTP request logs + global logs: + using var loggerFactory = sp.GetRequiredService(); + var logger = loggerFactory.CreateLogger("test"); + logger.LogTrace("This is a log message"); + using var response2 = await client.GetAsync("/flushalllogs").ConfigureAwait(false); + Assert.True(response2.IsSuccessStatusCode); + await WaitForLogRecordsAsync(logCollector, _defaultLogTimeout); + + // 1 and 2 records are from DfaMatcher, and 3rd is from our test category + Assert.Equal(3, logCollector.Count); + Assert.Equal(LogLevel.Trace, logCollector.LatestRecord.Level); + Assert.Equal("test", logCollector.LatestRecord.Category); + }); + } + [Fact] public async Task HttpLogging_LogRecordIsNotCreated_If_Disabled() { diff --git a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/HeaderNormalizerTests.cs b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/HeaderNormalizerTests.cs index 481a186a08d..82a063cc55c 100644 --- a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/HeaderNormalizerTests.cs +++ b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/Logging/HeaderNormalizerTests.cs @@ -5,6 +5,8 @@ using Microsoft.Extensions.Compliance.Classification; using Xunit; +namespace Microsoft.AspNetCore.Diagnostics.Logging.Test; + public class HeaderNormalizerTests { [Fact] diff --git a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/appsettings.json b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/appsettings.json index c1503ee98da..9597f27c636 100644 --- a/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/appsettings.json +++ b/test/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware.Tests/appsettings.json @@ -17,5 +17,18 @@ "userId": "EUII", "userContent": "CustomerContent" } + }, + "Buffering": { + "Rules": [ + { + "CategoryName": "Program.MyLogger", + "LogLevel": "Information", + "EventId": 1, + "EventName": "number one" + }, + { + "LogLevel": "Information" + } + ] } } diff --git a/test/Libraries/Microsoft.Extensions.AI.Integration.Tests/Microsoft.Extensions.AI.Integration.Tests.csproj b/test/Libraries/Microsoft.Extensions.AI.Integration.Tests/Microsoft.Extensions.AI.Integration.Tests.csproj index cf9f4d9703d..9050d16663e 100644 --- a/test/Libraries/Microsoft.Extensions.AI.Integration.Tests/Microsoft.Extensions.AI.Integration.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.AI.Integration.Tests/Microsoft.Extensions.AI.Integration.Tests.csproj @@ -8,6 +8,7 @@ $(NoWarn);CA1063;CA1861;SA1130;VSTHRD003 true + true diff --git a/test/Libraries/Microsoft.Extensions.AI.Ollama.Tests/Microsoft.Extensions.AI.Ollama.Tests.csproj b/test/Libraries/Microsoft.Extensions.AI.Ollama.Tests/Microsoft.Extensions.AI.Ollama.Tests.csproj index 5db789e3b6b..1b485b302ca 100644 --- a/test/Libraries/Microsoft.Extensions.AI.Ollama.Tests/Microsoft.Extensions.AI.Ollama.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.AI.Ollama.Tests/Microsoft.Extensions.AI.Ollama.Tests.csproj @@ -5,6 +5,7 @@ + true true diff --git a/test/Libraries/Microsoft.Extensions.AI.OpenAI.Tests/Microsoft.Extensions.AI.OpenAI.Tests.csproj b/test/Libraries/Microsoft.Extensions.AI.OpenAI.Tests/Microsoft.Extensions.AI.OpenAI.Tests.csproj index 66412bfeace..eae3a41d364 100644 --- a/test/Libraries/Microsoft.Extensions.AI.OpenAI.Tests/Microsoft.Extensions.AI.OpenAI.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.AI.OpenAI.Tests/Microsoft.Extensions.AI.OpenAI.Tests.csproj @@ -6,6 +6,7 @@ + true true true diff --git a/test/Libraries/Microsoft.Extensions.AI.Tests/Microsoft.Extensions.AI.Tests.csproj b/test/Libraries/Microsoft.Extensions.AI.Tests/Microsoft.Extensions.AI.Tests.csproj index 32589c430e0..4a1753b2350 100644 --- a/test/Libraries/Microsoft.Extensions.AI.Tests/Microsoft.Extensions.AI.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.AI.Tests/Microsoft.Extensions.AI.Tests.csproj @@ -5,6 +5,7 @@ + true $(NoWarn);CA1063;CA1861;SA1130;VSTHRD003 true diff --git a/test/Libraries/Microsoft.Extensions.Diagnostics.Probes.Tests/Microsoft.Extensions.Diagnostics.Probes.Tests.csproj b/test/Libraries/Microsoft.Extensions.Diagnostics.Probes.Tests/Microsoft.Extensions.Diagnostics.Probes.Tests.csproj index 5f6ca415e12..6f9488a33d8 100644 --- a/test/Libraries/Microsoft.Extensions.Diagnostics.Probes.Tests/Microsoft.Extensions.Diagnostics.Probes.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.Diagnostics.Probes.Tests/Microsoft.Extensions.Diagnostics.Probes.Tests.csproj @@ -2,6 +2,7 @@ Microsoft.Extensions.Diagnostics.Probes.Test Unit tests for Microsoft.Extensions.Diagnostics.Probes + true diff --git a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Microsoft.Extensions.Http.Diagnostics.Tests.csproj b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Microsoft.Extensions.Http.Diagnostics.Tests.csproj index 4bc20735577..cf7192a9df5 100644 --- a/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Microsoft.Extensions.Http.Diagnostics.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.Http.Diagnostics.Tests/Microsoft.Extensions.Http.Diagnostics.Tests.csproj @@ -2,6 +2,7 @@ Microsoft.Extensions.Http.Diagnostics.Test Unit tests for Microsoft.Extensions.Http.Diagnostics. + true diff --git a/test/Libraries/Microsoft.Extensions.Options.ContextualOptions.Tests/Microsoft.Extensions.Options.Contextual.Tests.csproj b/test/Libraries/Microsoft.Extensions.Options.ContextualOptions.Tests/Microsoft.Extensions.Options.Contextual.Tests.csproj index d440b8820db..a2f9e84a160 100644 --- a/test/Libraries/Microsoft.Extensions.Options.ContextualOptions.Tests/Microsoft.Extensions.Options.Contextual.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.Options.ContextualOptions.Tests/Microsoft.Extensions.Options.Contextual.Tests.csproj @@ -2,6 +2,7 @@ Microsoft.Extensions.Options.Contextual.Test Unit tests for Microsoft.Extensions.Options.Contextual + true diff --git a/test/Libraries/Microsoft.Extensions.Resilience.Tests/Microsoft.Extensions.Resilience.Tests.csproj b/test/Libraries/Microsoft.Extensions.Resilience.Tests/Microsoft.Extensions.Resilience.Tests.csproj index 163b01082d1..02ad31cde93 100644 --- a/test/Libraries/Microsoft.Extensions.Resilience.Tests/Microsoft.Extensions.Resilience.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.Resilience.Tests/Microsoft.Extensions.Resilience.Tests.csproj @@ -2,6 +2,7 @@ Microsoft.Extensions.Resilience.Test Unit tests for Microsoft.Extensions.Resilience + true diff --git a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Buffering/GlobalBufferLoggerBuilderExtensionsTests.cs b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Buffering/GlobalBufferLoggerBuilderExtensionsTests.cs new file mode 100644 index 00000000000..76d62e496f9 --- /dev/null +++ b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Buffering/GlobalBufferLoggerBuilderExtensionsTests.cs @@ -0,0 +1,71 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Diagnostics.Buffering; +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.AddGlobalBuffering(LogLevel.Warning); + }); + + var serviceProvider = serviceCollection.BuildServiceProvider(); + var bufferManager = serviceProvider.GetService(); + + Assert.NotNull(bufferManager); + Assert.IsAssignableFrom(bufferManager); + } + + [Fact] + public void WhenArgumentNull_Throws() + { + var builder = null as ILoggingBuilder; + var configuration = null as IConfiguration; + + Assert.Throws(() => builder!.AddGlobalBuffering(LogLevel.Warning)); + Assert.Throws(() => builder!.AddGlobalBuffering(configuration!)); + } + + [Fact] + public void AddGlobalBuffer_WithConfiguration_RegistersInDI() + { + List expectedData = + [ + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Information, 1, "number one", [new("region", "westus2"), new ("priority", 1)]), + new LogBufferingFilterRule(logLevel : LogLevel.Information), + ]; + ConfigurationBuilder configBuilder = new ConfigurationBuilder(); + configBuilder.AddJsonFile("appsettings.json"); + IConfigurationRoot configuration = configBuilder.Build(); + var serviceCollection = new ServiceCollection(); + serviceCollection.AddLogging(builder => + { + builder.AddGlobalBuffering(configuration); + builder.Services.Configure(options => + { + options.MaxLogRecordSizeInBytes = 33; + }); + }); + var serviceProvider = serviceCollection.BuildServiceProvider(); + var options = serviceProvider.GetService>(); + Assert.NotNull(options); + Assert.NotNull(options.CurrentValue); + Assert.Equal(33, options.CurrentValue.MaxLogRecordSizeInBytes); // value comes from the Configure() call + Assert.Equal(1000, options.CurrentValue.MaxBufferSizeInBytes); // value comes from appsettings.json + Assert.Equal(TimeSpan.FromSeconds(30), options.CurrentValue.SuspendAfterFlushDuration); // value comes from default + Assert.Equivalent(expectedData, options.CurrentValue.Rules); + } +} diff --git a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Buffering/LoggerFilterRuleSelectorTests.cs b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Buffering/LoggerFilterRuleSelectorTests.cs new file mode 100644 index 00000000000..e41e877bd7c --- /dev/null +++ b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Buffering/LoggerFilterRuleSelectorTests.cs @@ -0,0 +1,90 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Linq; +using Microsoft.Extensions.Diagnostics.Buffering; +using Xunit; + +namespace Microsoft.Extensions.Logging.Test; +public class LoggerFilterRuleSelectorTests +{ + [Fact] + public void SelectsRightRule() + { + // Arrange + var rules = new List + { + new LogBufferingFilterRule(null, null, null, null), + new LogBufferingFilterRule(null, null, 1, null), + new LogBufferingFilterRule(null, LogLevel.Information, 1, null), + new LogBufferingFilterRule(null, LogLevel.Information, 1, null), + new LogBufferingFilterRule(null, LogLevel.Warning, null, null), + new LogBufferingFilterRule(null, LogLevel.Warning, 2, null), + new LogBufferingFilterRule(null, LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program1.MyLogger", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.*MyLogger1", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes: [new("region2", "westus2")]), // inapplicable key + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes:[new("region", "westus3")]), // inapplicable value + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes:[new("region", "westus2")]), // the best rule - [11] + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 2, null), + new LogBufferingFilterRule("Program.MyLogger", null, 1, null), + new LogBufferingFilterRule(null, LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, null, null), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Error, 1, null), + }; + + // Act + LogBufferingFilterRuleSelector.Select( + rules, "Program.MyLogger", LogLevel.Warning, 1, [new("region", "westus2")], out var actualResult); + + // Assert + Assert.Same(rules[11], actualResult); + } + + [Fact] + public void WhenManyRuleApply_SelectsLast() + { + // Arrange + var rules = new List + { + new LogBufferingFilterRule(null, LogLevel.Information, 1, null), + new LogBufferingFilterRule(null, LogLevel.Information, 1, null), + new LogBufferingFilterRule(null, LogLevel.Warning, null, null), + new LogBufferingFilterRule(null, LogLevel.Warning, 2, null), + new LogBufferingFilterRule(null, LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program1.MyLogger", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.*MyLogger1", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.MyLogger*", LogLevel.Warning, 1, null), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes:[new("region", "westus2")]), // the best rule + new LogBufferingFilterRule("Program.MyLogger*", LogLevel.Warning, 1, attributes:[new("region", "westus2")]), // same as the best, but last and should be selected + }; + + // Act + LogBufferingFilterRuleSelector.Select(rules, "Program.MyLogger", LogLevel.Warning, 1, [new("region", "westus2")], out var actualResult); + + // Assert + Assert.Same(rules.Last(), actualResult); + } + + [Fact] + public void CanWorkWithValueTypeAttributes() + { + // Arrange + var rules = new List + { + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes:[new("priority", 1)]), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes:[new("priority", 2)]), // the best rule + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, attributes:[new("priority", 3)]), + new LogBufferingFilterRule("Program.MyLogger", LogLevel.Warning, 1, null), + }; + + // Act + LogBufferingFilterRuleSelector.Select(rules, "Program.MyLogger", LogLevel.Warning, 1, [new("priority", "2")], out var actualResult); + + // Assert + Assert.Same(rules[1], actualResult); + } +} diff --git a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/ExtendedLoggerTests.cs b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/ExtendedLoggerTests.cs index 69d1d0e8f57..27820b1ea24 100644 --- a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/ExtendedLoggerTests.cs +++ b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/ExtendedLoggerTests.cs @@ -6,6 +6,7 @@ using System.Linq; using Microsoft.Extensions.Compliance.Testing; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Diagnostics.Buffering; using Microsoft.Extensions.Diagnostics.Enrichment; using Microsoft.Extensions.Logging.Testing; using Microsoft.Extensions.Options; @@ -119,6 +120,34 @@ public static void FeatureEnablement(bool enableRedaction, bool enableEnrichment } } + [Fact] + public static void GlobalBuffering_CanonicalUsecase() + { + using var provider = new Provider(); + using var factory = Utils.CreateLoggerFactory( + builder => + { + builder.AddProvider(provider); + builder.AddGlobalBuffering(LogLevel.Warning); + }); + + var logger = factory.CreateLogger("my category"); + logger.LogWarning("MSG0"); + logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2"); + + // nothing is logged because the buffer not flushed yet + Assert.Equal(0, provider.Logger!.Collector.Count); + + // instead of this, users would get LogBuffer from DI and call Flush on it + var dlf = (Utils.DisposingLoggerFactory)factory; + var bufferManager = dlf.ServiceProvider.GetRequiredService(); + + bufferManager.Flush(); + + // 2 log records emitted because the buffer has been flushed + Assert.Equal(2, provider.Logger!.Collector.Count); + } + [Theory] [CombinatorialData] public static void BagAndJoiner(bool objectVersion) diff --git a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/Utils.cs b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/Utils.cs index bf09f8cb91c..cb6a39a29e8 100644 --- a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/Utils.cs +++ b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/Utils.cs @@ -24,21 +24,21 @@ public static ILoggerFactory CreateLoggerFactory(Action? config return new DisposingLoggerFactory(loggerFactory, serviceProvider); } - private sealed class DisposingLoggerFactory : ILoggerFactory + internal sealed class DisposingLoggerFactory : ILoggerFactory { private readonly ILoggerFactory _loggerFactory; - private readonly ServiceProvider _serviceProvider; + internal readonly ServiceProvider ServiceProvider; public DisposingLoggerFactory(ILoggerFactory loggerFactory, ServiceProvider serviceProvider) { _loggerFactory = loggerFactory; - _serviceProvider = serviceProvider; + ServiceProvider = serviceProvider; } public void Dispose() { - _serviceProvider.Dispose(); + ServiceProvider.Dispose(); } public ILogger CreateLogger(string categoryName) diff --git a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Microsoft.Extensions.Telemetry.Tests.csproj b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Microsoft.Extensions.Telemetry.Tests.csproj index 7273b05c6c7..522fe8a9991 100644 --- a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Microsoft.Extensions.Telemetry.Tests.csproj +++ b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/Microsoft.Extensions.Telemetry.Tests.csproj @@ -5,6 +5,7 @@ + true false false false diff --git a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/appsettings.json b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/appsettings.json index 16ea15c7ed8..f829c55c4dc 100644 --- a/test/Libraries/Microsoft.Extensions.Telemetry.Tests/appsettings.json +++ b/test/Libraries/Microsoft.Extensions.Telemetry.Tests/appsettings.json @@ -16,5 +16,30 @@ "MeterStateOverrides": { "": "Disabled" } + }, + "Buffering": { + "MaxLogRecordSizeInBytes": 100, + "MaxBufferSizeInBytes": 1000, + "Rules": [ + { + "CategoryName": "Program.MyLogger", + "LogLevel": "Information", + "EventId": 1, + "EventName" : "number one", + "Attributes": [ + { + "key": "region", + "value": "westus2" + }, + { + "key": "priority", + "value": 1 + } + ] + }, + { + "LogLevel": "Information" + } + ] } }