Add logging sampling (#5574)

Author: evgenyfedorov2

src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Microsoft.AspNetCore.Diagnostics.Middleware.csproj

@@ -17,7 +17,6 @@
     <InjectSharedPools>false</InjectSharedPools>
     <InjectSharedBufferWriterPool>true</InjectSharedBufferWriterPool>
     <InjectSharedNumericExtensions>false</InjectSharedNumericExtensions>
-    <InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
     <InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
   </PropertyGroup>
 

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Microsoft.Extensions.Http.Diagnostics.csproj

@@ -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>

src/Libraries/Microsoft.Extensions.Telemetry.Abstractions/Sampling/LoggingSampler.cs

@@ -0,0 +1,25 @@
+// 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.Logging;
+
+/// <summary>
+/// Controls the number of samples of log records collected and sent to the backend.
+/// </summary>
+#pragma warning disable S1694 // An abstract class should have both abstract and concrete methods
+[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
+public abstract class LoggingSampler
+#pragma warning restore S1694 // An abstract class should have both abstract and concrete methods
+{
+    /// <summary>
+    /// Makes a sampling decision for the provided <paramref name="logEntry"/>.
+    /// </summary>
+    /// <param name="logEntry">The log entry used to make the sampling decision for.</param>
+    /// <typeparam name="TState">The type of the log entry state.</typeparam>
+    /// <returns><see langword="true" /> if the log record should be sampled; otherwise, <see langword="false" />.</returns>
+    public abstract bool ShouldSample<TState>(in LogEntry<TState> logEntry);
+}

src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLogger.cs

@@ -4,7 +4,7 @@
 using System;
 using System.Collections.Generic;
 using System.Diagnostics;
-using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Abstractions;
 using Microsoft.Shared.Pools;
 
 namespace Microsoft.Extensions.Logging;
@@ -15,7 +15,7 @@ namespace Microsoft.Extensions.Logging;
 //       redactor code calls recursively back into the logger. Don't do that.
 //
 // NOTE: Unlike the original logger in dotnet/runtime, this logger eats exceptions thrown from invoked loggers, enrichers,
-//       and redactors, rather than forwarding the exceptions to the caller. The fact an exception occured is recorded in
+//       and redactors, rather than forwarding the exceptions to the caller. The fact an exception occurred is recorded in
 //       the event log instead. The idea is that failures in the telemetry stack should not lead to failures in the
 //       application. It's better to keep running with missing telemetry rather than crashing the process completely.
 
@@ -49,7 +49,7 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
             }
         }
 
-        LegacyPath<TState>(logLevel, eventId, state, exception, formatter);
+        LegacyPath(logLevel, eventId, state, exception, formatter);
     }
 
     public IDisposable? BeginScope<TState>(TState state)
@@ -261,16 +261,33 @@ private void ModernPath(LogLevel logLevel, EventId eventId, LoggerMessageState m
             RecordException(exception, joiner.EnrichmentTagCollector, config);
         }
 
+        bool? samplingDecision = null;
         for (int i = 0; i < loggers.Length; i++)
         {
             ref readonly MessageLogger loggerInfo = ref loggers[i];
             if (loggerInfo.IsNotFilteredOut(logLevel))
             {
+                if (samplingDecision is null && config.Sampler is not null)
+                {
+                    var logEntry = new LogEntry<ModernTagJoiner>(logLevel, loggerInfo.Category, eventId, joiner, exception, static (s, e) =>
+                    {
+                        Func<LoggerMessageState, Exception?, string> fmt = s.Formatter!;
+                        return fmt(s.State!, e);
+                    });
+                    samplingDecision = config.Sampler.ShouldSample(in logEntry);
+                }
+
+                if (samplingDecision is false)
+                {
+                    // the record was not selected for being sampled in, so we drop it.
+                    break;
+                }
+
                 try
                 {
                     loggerInfo.LoggerLog(logLevel, eventId, joiner, exception, static (s, e) =>
                     {
-                        var fmt = s.Formatter!;
+                        Func<LoggerMessageState, Exception?, string>? fmt = s.Formatter!;
                         return fmt(s.State!, e);
                     });
                 }
@@ -345,11 +362,28 @@ private void LegacyPath<TState>(LogLevel logLevel, EventId eventId, TState state
             RecordException(exception, joiner.EnrichmentTagCollector, config);
         }
 
+        bool? samplingDecision = null;
         for (int i = 0; i < loggers.Length; i++)
         {
             ref readonly MessageLogger loggerInfo = ref loggers[i];
             if (loggerInfo.IsNotFilteredOut(logLevel))
             {
+                if (samplingDecision is null && config.Sampler is not null)
+                {
+                    var logEntry = new LogEntry<LegacyTagJoiner>(logLevel, loggerInfo.Category, eventId, joiner, exception, static (s, e) =>
+                    {
+                        var fmt = (Func<TState, Exception?, string>)s.Formatter!;
+                        return fmt((TState)s.State!, e);
+                    });
+                    samplingDecision = config.Sampler.ShouldSample(in logEntry);
+                }
+
+                if (samplingDecision is false)
+                {
+                    // the record was not selected for being sampled in, so we drop it.
+                    break;
+                }
+
                 try
                 {
                     loggerInfo.Logger.Log(logLevel, eventId, joiner, exception, static (s, e) =>

src/Libraries/Microsoft.Extensions.Telemetry/Logging/ExtendedLoggerFactory.cs

@@ -23,6 +23,7 @@ internal sealed class ExtendedLoggerFactory : ILoggerFactory
     private readonly IDisposable? _enrichmentOptionsChangeTokenRegistration;
     private readonly IDisposable? _redactionOptionsChangeTokenRegistration;
     private readonly Action<IEnrichmentTagCollector>[] _enrichers;
+    private readonly LoggingSampler? _sampler;
     private readonly KeyValuePair<string, object?>[] _staticTags;
     private readonly Func<DataClassificationSet, Redactor> _redactorProvider;
     private volatile bool _disposed;
@@ -35,6 +36,7 @@ public ExtendedLoggerFactory(
         IEnumerable<ILogEnricher> enrichers,
         IEnumerable<IStaticLogEnricher> staticEnrichers,
         IOptionsMonitor<LoggerFilterOptions> filterOptions,
+        LoggingSampler? sampler = null,
         IOptions<LoggerFactoryOptions>? factoryOptions = null,
         IExternalScopeProvider? scopeProvider = null,
         IOptionsMonitor<LoggerEnrichmentOptions>? enrichmentOptions = null,
@@ -43,6 +45,7 @@ public ExtendedLoggerFactory(
 #pragma warning restore S107 // Methods should not have too many parameters
     {
         _scopeProvider = scopeProvider;
+        _sampler = sampler;
 
         _factoryOptions = factoryOptions == null || factoryOptions.Value == null ? new LoggerFactoryOptions() : factoryOptions.Value;
 
@@ -284,6 +287,7 @@ private LoggerConfig ComputeConfig(LoggerEnrichmentOptions? enrichmentOptions, L
 
         return new(_staticTags,
                 _enrichers,
+                _sampler,
                 enrichmentOptions.CaptureStackTraces,
                 enrichmentOptions.UseFileInfoForStackTraces,
                 enrichmentOptions.IncludeExceptionMessage,

src/Libraries/Microsoft.Extensions.Telemetry/Logging/Import/LoggerInformation.cs

@@ -17,7 +17,7 @@ namespace Microsoft.Extensions.Logging
 {
     internal readonly struct MessageLogger
     {
-        public MessageLogger(ILogger logger, string? category, string? providerTypeFullName, LogLevel? minLevel, Func<string?, string?, LogLevel, bool>? filter)
+        public MessageLogger(ILogger logger, string category, string? providerTypeFullName, LogLevel? minLevel, Func<string?, string?, LogLevel, bool>? filter)
         {
             Logger = logger;
             Category = category;
@@ -36,7 +36,7 @@ public MessageLogger(ILogger logger, string? category, string? providerTypeFullN
 
         public ILogger Logger { get; }
 
-        public string? Category { get; }
+        public string Category { get; }
 
         private string? ProviderTypeFullName { get; }
 

src/Libraries/Microsoft.Extensions.Telemetry/Logging/LoggerConfig.cs

@@ -15,6 +15,7 @@ internal sealed class LoggerConfig
     public LoggerConfig(
         KeyValuePair<string, object?>[] staticTags,
         Action<IEnrichmentTagCollector>[] enrichers,
+        LoggingSampler? sampler,
         bool captureStackTraces,
         bool useFileInfoForStackTraces,
         bool includeExceptionMessage,
@@ -25,6 +26,7 @@ public LoggerConfig(
 #pragma warning restore S107 // Methods should not have too many parameters
         StaticTags = staticTags;
         Enrichers = enrichers;
+        Sampler = sampler;
         CaptureStackTraces = captureStackTraces;
         UseFileInfoForStackTraces = useFileInfoForStackTraces;
         MaxStackTraceLength = maxStackTraceLength;
@@ -35,6 +37,7 @@ public LoggerConfig(
 
     public KeyValuePair<string, object?>[] StaticTags { get; }
     public Action<IEnrichmentTagCollector>[] Enrichers { get; }
+    public LoggingSampler? Sampler { get; }
     public bool CaptureStackTraces { get; }
     public bool UseFileInfoForStackTraces { get; }
     public bool IncludeExceptionMessage { get; }

src/Libraries/Microsoft.Extensions.Telemetry/Microsoft.Extensions.Telemetry.csproj

@@ -7,6 +7,8 @@
 
   <PropertyGroup>
     <AllowUnsafeBlocks>true</AllowUnsafeBlocks>
+    <InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
+    <InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
     <InjectSharedText>true</InjectSharedText>
     <InjectSharedDataValidation>true</InjectSharedDataValidation>
     <InjectSharedNumericExtensions>true</InjectSharedNumericExtensions>

src/Libraries/Microsoft.Extensions.Telemetry/Sampling/ILogSamplingFilterRule.cs

@@ -0,0 +1,32 @@
+// 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.Sampling;
+
+/// <summary>
+/// Represents a rule used for filtering log messages for purposes of log sampling and buffering.
+/// </summary>
+internal interface ILogSamplingFilterRule
+{
+    /// <summary>
+    /// Gets the logger category this rule applies to.
+    /// </summary>
+    string? CategoryName { get; }
+
+    /// <summary>
+    /// Gets the maximum <see cref="LogLevel"/> of messages.
+    /// </summary>
+    LogLevel? LogLevel { get; }
+
+    /// <summary>
+    /// Gets the event ID this rule applies to.
+    /// </summary>
+    int? EventId { get; }
+
+    /// <summary>
+    /// Gets the name of the event this rule applies to.
+    /// </summary>
+    string? EventName { get; }
+}

src/Libraries/Microsoft.Extensions.Telemetry/Sampling/LogSamplingRuleSelector.cs

@@ -0,0 +1,135 @@
+// 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.Concurrent;
+using System.Collections.Generic;
+using Microsoft.Extensions.Diagnostics.Sampling;
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.Extensions.Diagnostics.Sampling;
+
+internal sealed class LogSamplingRuleSelector<T>
+    where T : class, ILogSamplingFilterRule
+{
+    private readonly ConcurrentDictionary<(string, LogLevel, EventId), T?> _ruleCache = new();
+
+    public void InvalidateCache()
+    {
+        _ruleCache.Clear();
+    }
+
+    public T? Select(IList<T> rules, string category, LogLevel logLevel, EventId eventId)
+    {
+        return _ruleCache.GetOrAdd((category, logLevel, eventId), _ =>
+        {
+            // Filter rule selection:
+            // 0. Ignore rules whose LogLevel is defined but lower than the requested logLevel
+            // 1. Ignore rules whose EventId is defined but different from the requested eventId
+            // 2. For category filtering, handle optional wildcards (only one '*' allowed) and match the prefix/suffix ignoring case
+            // 3. Out of the matched set, pick the rule with the longest matching category
+            // 4. If no rules match by category, accept rules without a category
+            // 5. If exactly one rule remains, use it; if multiple remain, select the last in the list
+            T? current = null;
+            foreach (T rule in rules)
+            {
+                if (IsBetter(rule, current, category, logLevel, eventId))
+                {
+                    current = rule;
+                }
+            }
+
+            return current;
+        });
+    }
+
+    private static bool IsBetter(T rule, T? current, string category, LogLevel logLevel, EventId eventId)
+    {
+        // Skip rules with inapplicable log level
+        if (rule.LogLevel is not null && rule.LogLevel < logLevel)
+        {
+            return false;
+        }
+
+        // Skip rules with inapplicable event id
+        if (rule.EventId is not null && rule.EventId != eventId)
+        {
+            return false;
+        }
+
+        // Skip rules with inapplicable category
+        string? categoryName = rule.CategoryName;
+        if (categoryName is not null)
+        {
+            const char WildcardChar = '*';
+
+            int wildcardIndex = categoryName.IndexOf(WildcardChar);
+            if (wildcardIndex >= 0 &&
+                categoryName.IndexOf(WildcardChar, wildcardIndex + 1) >= 0)
+            {
+                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?.CategoryName is not null)
+        {
+            if (rule.CategoryName is null)
+            {
+                return false;
+            }
+
+            if (current.CategoryName.Length > rule.CategoryName.Length)
+            {
+                return false;
+            }
+        }
+
+        // Decide whose log level is better - rule vs current
+        if (current?.LogLevel is not null)
+        {
+            if (rule.LogLevel is 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 is not null)
+            {
+                return false;
+            }
+        }
+
+        return true;
+    }
+}