[Bug]: Customizing the severity of telemetry events has no effect: PipelineExecuted, PipelineExecuting

[miko96]

According to the documentation there is an ability to customize severity of telemetry events:

https://www.pollydocs.org/advanced/telemetry.html#customizing-the-severity-of-telemetry-events

telemetryOptions.SeverityProvider = args => args.Event.EventName switch
{
// Decrease severity of specific events
"PipelineExecuted" => ResilienceEventSeverity.None,
"PipelineExecuting" => ResilienceEventSeverity.None,
_ => args.Event.Severity
};

The problem is that overridden severity level has no effect for the events "PipelineExecuted", "PipelineExecuting".

Polly/src/Polly.Extensions/Telemetry/TelemetryListenerImpl.cs

Lines 168 to 187 in 12a80e1

	var level = severity.AsLogLevel();
	if (GetArgs<TArgs, PipelineExecutingArguments>(args.Arguments, out _))
	{
	_logger.PipelineExecuting(
	args.Source.PipelineName.GetValueOrPlaceholder(),
	args.Source.PipelineInstanceName.GetValueOrPlaceholder(),
	args.Context.OperationKey);
	}
	else if (GetArgs<TArgs, PipelineExecutedArguments>(args.Arguments, out var pipelineExecuted))
	{
	_logger.PipelineExecuted(
	LogLevel.Debug,
	args.Source.PipelineName.GetValueOrPlaceholder(),
	args.Source.PipelineInstanceName.GetValueOrPlaceholder(),
	args.Context.OperationKey,
	GetResult(args.Context, args.Outcome),
	pipelineExecuted.Duration.TotalMilliseconds,
	args.Outcome?.Exception);
	}

Expected behavior

No response

Actual behavior

No response

Steps to reproduce

No response

Exception(s) (if any)

No response

Polly version

No response

.NET Version

No response

Anything else?

No response

[peter-csala]

I did not have time to test it but I think you are using wrong names for the events.

You should use StrategyExecuting instead of PipelineExecuting:

Polly/src/Polly.Extensions/Telemetry/Log.cs

Lines 37 to 44 in 03e3fc6

	[LoggerMessage(
	1,
	LogLevel.Debug,
	"Resilience pipeline executing. " +
	SourceWithoutStrategy + Separator +
	OperationKey,
	EventName = "StrategyExecuting")]
	public static partial void PipelineExecuting(

You should use StrategyExecuted instead of PipelineExecuted:

Polly/src/Polly.Extensions/Telemetry/Log.cs

Lines 50 to 58 in 03e3fc6

	[LoggerMessage(
	EventId = 2,
	Message = "Resilience pipeline executed. " +
	SourceWithoutStrategy + Separator +
	OperationKey + Separator +
	Result + Separator +
	ExecutionTime,
	EventName = "StrategyExecuted")]
	public static partial void PipelineExecuted(

Could you please give it a try?

[miko96]

The event names used in severity provider are correct. Please look at the source code emitting the events:

Polly/src/Polly.Core/Utils/Pipeline/CompositeComponent.cs

Lines 106 to 114 in 03e3fc6

	_telemetry.Report(new ResilienceEvent(ResilienceEventSeverity.Debug, TelemetryUtil.PipelineExecuting), context, default(PipelineExecutingArguments));
	var outcome = await ExecuteCoreWithoutTelemetry(callback, context, state).ConfigureAwait(context.ContinueOnCapturedContext);
	_telemetry.Report(
	new ResilienceEvent(ResilienceEventSeverity.Information, TelemetryUtil.PipelineExecuted),
	context,
	outcome,
	new PipelineExecutedArguments(_timeProvider.GetElapsedTime(timeStamp)));

Polly/src/Polly.Core/Telemetry/TelemetryUtil.cs

Lines 9 to 11 in 03e3fc6

	internal const string PipelineExecuting = "PipelineExecuting";
	internal const string PipelineExecuted = "PipelineExecuted";

[peter-csala]

Okay, I've put together this simple app:

var telemetryOptions = new TelemetryOptions
{
	SeverityProvider = args => 
	{
		var originalSeverity = args.Event.Severity;
		var overridenSeverity = args.Event.EventName switch
		{
				"ExecutionAttempt" => ResilienceEventSeverity.None,
				"OnRetry" => ResilienceEventSeverity.None,
				"PipelineExecuting" => ResilienceEventSeverity.None,
				"PipelineExecuted" => ResilienceEventSeverity.None,
				_ => args.Event.Severity
		};
		Console.WriteLine($"Name: {args.Event.EventName}, Original: {originalSeverity}, Overridden: {overridenSeverity}"); 
		return overridenSeverity;
	},
	LoggerFactory = LoggerFactory.Create(builder => builder.AddConsole().SetMinimumLevel(LogLevel.Debug))
};

var pipeline = new ResiliencePipelineBuilder()
	.AddRetry(new() {
		ShouldHandle = args => ValueTask.FromResult<bool>(true)
	})
	.ConfigureTelemetry(telemetryOptions)
	.Build();

pipeline.Execute(() => Console.WriteLine());

The output:

Name: PipelineExecuting, Original: Debug, Overridden: None
dbug: Polly[1]
      Resilience pipeline executing. Source: '(null)/(null)', Operation Key: '(null)'

Name: ExecutionAttempt, Original: Warning, Overridden: None
Name: OnRetry, Original: Warning, Overridden: None

Name: ExecutionAttempt, Original: Warning, Overridden: None
Name: OnRetry, Original: Warning, Overridden: None

Name: ExecutionAttempt, Original: Warning, Overridden: None
Name: OnRetry, Original: Warning, Overridden: None

Name: ExecutionAttempt, Original: Error, Overridden: None
Name: PipelineExecuted, Original: Information, Overridden: None
dbug: Polly[2]
      Resilience pipeline executed. Source: '(null)/(null)', Operation Key: '', Result: 'void', Execution Time: 6036.5127ms

I have to dig deeper into the TelemetryListenerImpl to see why the overridden value is not respected.

@martincostello You can assign this issue to me, I can work on this next week.

[github-actions]

Thanks for creating this issue @miko96 - the associated changes have been published as part of version 8.6.4 📦, which is now available from NuGet.org 🚀