Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Add logging sampling #5574

Draft
wants to merge 38 commits into
base: main
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from 37 commits
Commits
Show all changes
38 commits
Select commit Hold shift + click to select a range
1280d1b
initial proposal
Jun 5, 2024
f8b502c
update
Jul 3, 2024
ed7e0db
rebase
evgenyfedorov2 Sep 12, 2024
e15139d
use .net 9
evgenyfedorov2 Sep 30, 2024
12fd4b4
bufferin - initial
evgenyfedorov2 Oct 7, 2024
9fa8403
Remove junk
evgenyfedorov2 Oct 7, 2024
2ff5f78
buffer - renames
evgenyfedorov2 Oct 9, 2024
0cf2c50
.
evgenyfedorov2 Oct 9, 2024
6f8265e
.
evgenyfedorov2 Oct 9, 2024
cdb2c82
Sampling WIP with Global and HttpRequest samplers
evgenyfedorov2 Oct 14, 2024
cb1de9d
sampling
evgenyfedorov2 Oct 14, 2024
c4596a3
cosmetic
evgenyfedorov2 Oct 14, 2024
5e92d14
Prepare to update API proposal
evgenyfedorov2 Oct 15, 2024
8f760b1
.
evgenyfedorov2 Oct 15, 2024
57f902b
state at 23_10_2024 after updating Github proposal
evgenyfedorov2 Oct 23, 2024
610647c
Return Global and Http Request buffering options
evgenyfedorov2 Oct 24, 2024
3be3850
polish sampling
evgenyfedorov2 Oct 24, 2024
8ce40c1
add alwaysOnSampler
evgenyfedorov2 Oct 24, 2024
d288300
update namespaces
evgenyfedorov2 Oct 24, 2024
e120145
abstractions test
evgenyfedorov2 Oct 24, 2024
b443094
add some tests
evgenyfedorov2 Oct 25, 2024
b41fcdf
remove buffering
evgenyfedorov2 Oct 25, 2024
a5e1440
merge
evgenyfedorov2 Oct 25, 2024
cbd2a15
update tests
evgenyfedorov2 Oct 25, 2024
5580cff
remove sample app
evgenyfedorov2 Oct 25, 2024
07a2860
cosmetic changes
evgenyfedorov2 Oct 25, 2024
9ac7cab
update tests
evgenyfedorov2 Oct 25, 2024
0df498f
validate supplied probability
evgenyfedorov2 Oct 25, 2024
7b9479d
Fix warnings
evgenyfedorov2 Oct 25, 2024
4007ce1
Merge branch 'main' into evgenyfedorov2/log_sampling
evgenyfedorov2 Oct 26, 2024
473bfca
more tests
evgenyfedorov2 Oct 26, 2024
b140e68
Address PR comments
evgenyfedorov2 Oct 30, 2024
32b5adc
Address PR comments
evgenyfedorov2 Oct 31, 2024
ebd4795
wip
evgenyfedorov2 Nov 4, 2024
901bc22
add config support to Ratio based Sampler
evgenyfedorov2 Nov 6, 2024
e33863e
fix warnings
evgenyfedorov2 Nov 6, 2024
d43f891
Merge branch 'main' into evgenyfedorov2/log_sampling
evgenyfedorov2 Nov 6, 2024
0adbfc7
PR comments
evgenyfedorov2 Nov 7, 2024
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,6 @@
<InjectSharedPools>false</InjectSharedPools>
<InjectSharedBufferWriterPool>true</InjectSharedBufferWriterPool>
<InjectSharedNumericExtensions>false</InjectSharedNumericExtensions>
<InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
<InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
</PropertyGroup>

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,36 @@
// 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.Logging;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.Extensions.Diagnostics.Sampling;

/// <summary>
/// Represents a rule used for filtering log messages for purposes of log sampling and buffering.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public interface ILoggerSamplerFilterRule
Copy link
Member

Choose a reason for hiding this comment

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

I'd suggest making this interface internal

{
/// <summary>
/// Gets the logger category this rule applies to.
/// </summary>
public string? Category { get; }

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

/// <summary>
/// Gets the maximum <see cref="LogLevel"/> of messages where this rule applies to.
/// </summary>
public int? EventId { get; }

/// <summary>
/// Gets the filter delegate that would be applied to messages that passed the <see cref="LogLevel"/>.
/// </summary>
public Func<string?, LogLevel?, int?, bool>? Filter { get; }
Copy link
Member

Choose a reason for hiding this comment

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

I don't think this API needs to be included in the interface because the rule selector doesn't access it.

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,23 @@
// 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.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 LoggerSampler
#pragma warning restore S1694 // An abstract class should have both abstract and concrete methods
{
/// <summary>
/// Makes a sampling decision based on the provided <paramref name="parameters"/>.
/// </summary>
/// <param name="parameters">The parameters used to make the sampling decision.</param>
/// <returns><see langword="true" /> if the log record should be sampled; otherwise, <see langword="false" />.</returns>
public abstract bool ShouldSample(SamplingParameters parameters);
}
Original file line number Diff line number Diff line change
@@ -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;
using System.Diagnostics.CodeAnalysis;
using Microsoft.Shared.DiagnosticIds;

namespace Microsoft.Extensions.Logging;

/// <summary>
/// Contains the parameters helping make sampling decisions for logs.
/// </summary>
[Experimental(diagnosticId: DiagnosticIds.Experiments.Telemetry, UrlFormat = DiagnosticIds.UrlFormat)]
public readonly struct SamplingParameters : IEquatable<SamplingParameters>
noahfalk marked this conversation as resolved.
Show resolved Hide resolved
evgenyfedorov2 marked this conversation as resolved.
Show resolved Hide resolved
Copy link
Member

Choose a reason for hiding this comment

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

SamplingParameters

should we call it SamplingOptions better? we use Options everywhere and it convey the same meaning.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Here it is called SamplingParameters, that's why I have decided to re-use this name. Options kind of names are usually used to represent config with the IOptions<> pattern, so might not be the best choice here. What do you think?

Copy link
Member

Choose a reason for hiding this comment

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

SamplingParameters is ok. I was only trying to get attention if we thought about it. Let us stick with that name if no-one else has any concern about it. By the way, I tried to look at OTEL specs just in case they suggest something but couldn't find any info there.

{
/// <summary>
/// Initializes a new instance of the <see cref="SamplingParameters"/> struct.
/// </summary>
/// <param name="logLevel"><see cref="Microsoft.Extensions.Logging.LogLevel"/> of the log record.</param>
/// <param name="category">Category of the log record.</param>
/// <param name="eventId"><see cref="Microsoft.Extensions.Logging.EventId"/> of the log record.</param>
public SamplingParameters(LogLevel logLevel, string category, EventId eventId)
{
LogLevel = logLevel;
Category = category;
Copy link
Member

Choose a reason for hiding this comment

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

Category = category;

what happen if someone forced null value? should we intentionally not allow that here?

Copy link
Member

Choose a reason for hiding this comment

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

Are you proposing adding Throw.IfNull(category) check? I assume at the moment if you passed null then its possible you get a NullReferenceException inside the call to ShouldSample() depending on its implementation.

Copy link
Member

Choose a reason for hiding this comment

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

Are you proposing adding Throw.IfNull(category) check?

Yes.

I assume at the moment if you passed null then its possible you get a NullReferenceException inside the call to ShouldSample() depending on its implementation.

Getting NullReferenceException will be not a good experience. Get exception when creating SamplingParameters will be much better and informative.

EventId = eventId;
}

/// <summary>
/// Gets the log category.
/// </summary>
public string Category { get; }

/// <summary>
/// Gets the event ID.
/// </summary>
public EventId EventId { get; }

/// <summary>
/// Gets the log level.
/// </summary>
public LogLevel LogLevel { get; }

/// <inheritdoc/>
public override bool Equals(object? obj) =>
obj is SamplingParameters samplingParameters && Equals(samplingParameters);

/// <inheritdoc/>
public bool Equals(SamplingParameters other)
{
return other.EventId.Equals(EventId)
&& string.Equals(other.Category, Category, StringComparison.Ordinal)
&& other.LogLevel.Equals(LogLevel);
}

/// <inheritdoc/>
public override int GetHashCode() =>

HashCode.Combine(
LogLevel.GetHashCode(),
#if NETFRAMEWORK
Category.GetHashCode(),
#else
Category.GetHashCode(StringComparison.Ordinal),
#endif
EventId.GetHashCode());

/// <summary>
/// Checks if two specified <see cref="SamplingParameters"/> instances have the same value.
/// They are equal if their respective properties have the same values.
/// </summary>
/// <param name="left">The first <see cref="SamplingParameters"/>.</param>
/// <param name="right">The second <see cref="SamplingParameters"/>.</param>
/// <returns><see langword="true" /> if the objects are equal.</returns>
public static bool operator ==(SamplingParameters left, SamplingParameters right)
{
return left.Equals(right);
}

/// <summary>
/// Checks if two specified <see cref="SamplingParameters"/> instances have different values.
/// </summary>
/// <param name="left">The first <see cref="SamplingParameters"/>.</param>
/// <param name="right">The second <see cref="SamplingParameters"/>.</param>
/// <returns><see langword="true" /> if the objects are not equal.</returns>
public static bool operator !=(SamplingParameters left, SamplingParameters right)
{
return !left.Equals(right);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,6 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using Microsoft.Extensions.Logging;
using Microsoft.Shared.Pools;

namespace Microsoft.Extensions.Logging;
Expand All @@ -15,7 +14,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.

Expand All @@ -39,6 +38,12 @@ public ExtendedLogger(ExtendedLoggerFactory factory, LoggerInformation[] loggers

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
{
if (MessageLoggers.Length == 0 || !_factory.Config.Sampler.ShouldSample(new SamplingParameters(logLevel, MessageLoggers[0].Category, eventId)))
Copy link
Member

Choose a reason for hiding this comment

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

I think we want to run the sampler after we know the log record is enabled in at least one logger. For example if someone wanted to make a rate limiting sampler that logs no more than 1000 messages per second they might write:

class Sampler
{
    int _count; // pretend this gets reset to zero on timer every second
    bool ShouldSample(...) => _count++ < 1000;
}

If the app has lots of logging instrumentation that uses the Trace logging level, but the app config has trace logging disabled the app developer may not get any messages logged at all. The calls to Log() at trace level use up the entire quota of 1000 messages in the sampler only to get filtered out later by the Logger.IsEnabled() checks.

{
// the record was not selected for being sampled in, so we drop it.
return;
}

if (typeof(TState) == typeof(LoggerMessageState))
{
var msgState = (LoggerMessageState?)(object?)state;
Expand All @@ -49,7 +54,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)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
using Microsoft.Extensions.Compliance.Classification;
using Microsoft.Extensions.Compliance.Redaction;
using Microsoft.Extensions.Diagnostics.Enrichment;
using Microsoft.Extensions.Diagnostics.Sampling;
using Microsoft.Extensions.Options;
using Microsoft.Shared.Diagnostics;

Expand All @@ -23,6 +24,7 @@ internal sealed class ExtendedLoggerFactory : ILoggerFactory
private readonly IDisposable? _enrichmentOptionsChangeTokenRegistration;
private readonly IDisposable? _redactionOptionsChangeTokenRegistration;
private readonly Action<IEnrichmentTagCollector>[] _enrichers;
private readonly LoggerSampler _sampler;
private readonly KeyValuePair<string, object?>[] _staticTags;
private readonly Func<DataClassificationSet, Redactor> _redactorProvider;
private volatile bool _disposed;
Expand All @@ -35,6 +37,7 @@ public ExtendedLoggerFactory(
IEnumerable<ILogEnricher> enrichers,
IEnumerable<IStaticLogEnricher> staticEnrichers,
IOptionsMonitor<LoggerFilterOptions> filterOptions,
LoggerSampler? sampler = null,
IOptions<LoggerFactoryOptions>? factoryOptions = null,
IExternalScopeProvider? scopeProvider = null,
IOptionsMonitor<LoggerEnrichmentOptions>? enrichmentOptions = null,
Expand All @@ -43,6 +46,7 @@ public ExtendedLoggerFactory(
#pragma warning restore S107 // Methods should not have too many parameters
{
_scopeProvider = scopeProvider;
_sampler = sampler ?? new AlwaysOnSampler();
Copy link
Member

Choose a reason for hiding this comment

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

Performance-wise its probably a little bit faster to execute _sampler == null ? true : _sampler.ShouldSample() instead of invoking _sampler.ShouldSample() when no sampler was provided. You can do a little microbenchmark to confirm.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I will keep this thread open and update later

Copy link
Member

Choose a reason for hiding this comment

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

agree with @noah. Also it will be a way to check if the logger is created with sampler or not too.

Copy link
Member

Choose a reason for hiding this comment

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

seeing AlwaysOnSampler is internal, this make my previous comment is not accurate.


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

Expand Down Expand Up @@ -284,6 +288,7 @@ private LoggerConfig ComputeConfig(LoggerEnrichmentOptions? enrichmentOptions, L

return new(_staticTags,
_enrichers,
_sampler,
enrichmentOptions.CaptureStackTraces,
enrichmentOptions.UseFileInfoForStackTraces,
enrichmentOptions.IncludeExceptionMessage,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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; }

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ internal sealed class LoggerConfig
public LoggerConfig(
KeyValuePair<string, object?>[] staticTags,
Action<IEnrichmentTagCollector>[] enrichers,
LoggerSampler sampler,
bool captureStackTraces,
bool useFileInfoForStackTraces,
bool includeExceptionMessage,
Expand All @@ -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;
Expand All @@ -35,6 +37,7 @@ public LoggerConfig(

public KeyValuePair<string, object?>[] StaticTags { get; }
public Action<IEnrichmentTagCollector>[] Enrichers { get; }
public LoggerSampler Sampler { get; }
public bool CaptureStackTraces { get; }
public bool UseFileInfoForStackTraces { get; }
public bool IncludeExceptionMessage { get; }
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,8 @@

<PropertyGroup>
<AllowUnsafeBlocks>true</AllowUnsafeBlocks>
<InjectExperimentalAttributeOnLegacy>true</InjectExperimentalAttributeOnLegacy>
<InjectSharedDiagnosticIds>true</InjectSharedDiagnosticIds>
<InjectSharedText>true</InjectSharedText>
<InjectSharedDataValidation>true</InjectSharedDataValidation>
<InjectSharedNumericExtensions>true</InjectSharedNumericExtensions>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
// 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;

internal sealed class AlwaysOnSampler : LoggerSampler
{
public override bool ShouldSample(SamplingParameters _) => true;
}
Original file line number Diff line number Diff line change
@@ -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;
using Microsoft.Extensions.Logging;
using Microsoft.Shared.Diagnostics;

namespace Microsoft.Extensions.Diagnostics.Sampling;

internal sealed class FuncBasedSampler : LoggerSampler
{
private readonly Func<SamplingParameters, bool> _samplingDecisionFunc;

public FuncBasedSampler(Func<SamplingParameters, bool> samplingDecisionFunc)
{
_samplingDecisionFunc = Throw.IfNull(samplingDecisionFunc);
}

public override bool ShouldSample(SamplingParameters parameters) => _samplingDecisionFunc(parameters);
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
// 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 Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;

namespace Microsoft.Extensions.Diagnostics.Sampling;

#pragma warning disable CA5394 // Do not use insecure randomness
/// <summary>
/// Samples logs according to the specified probability.
/// </summary>
internal sealed class RatioBasedSampler : LoggerSampler
{
#if !NET6_0_OR_GREATER
private static readonly System.Threading.ThreadLocal<Random> _randomInstance = new(() => new Random());
#endif

private readonly IOptionsMonitor<RatioBasedSamplerOptions> _options;

/// <summary>
/// Initializes a new instance of the <see cref="RatioBasedSampler"/> class.
/// </summary>
public RatioBasedSampler(IOptionsMonitor<RatioBasedSamplerOptions> options)
{
_options = options;
}

/// <inheritdoc/>
public override bool ShouldSample(SamplingParameters parameters)
{
if (!TryApply(parameters, out var probability))
{
return true;
}

#if NET6_0_OR_GREATER
return Random.Shared.Next(int.MaxValue) < int.MaxValue * probability;
#else
return _randomInstance.Value!.Next(int.MaxValue) < int.MaxValue * probability;
#endif
}

private bool TryApply(SamplingParameters parameters, out double probability)
{
probability = 0.0;

// TO DO: check if we can optimize this. It is a hot path and
// we should be able to minimize number of rule selections on every log record.
Copy link
Member

Choose a reason for hiding this comment

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

I agree we'd want to optimize it but it doesn't impact the design review much. I think its good you left it as a TODO 👍.

SamplerRuleSelector.Select(_options.CurrentValue.Rules, parameters.Category, parameters.LogLevel, parameters.EventId, out RatioBasedSamplerFilterRule? rule);
if (rule is not null)
{
probability = rule.Probability;
return true;
}

return false;
}
}
Loading
Loading