[BUG] OpenTelemetry traces contain System.Threading.Tasks.TaskCanceledException

[ibruynin]

Library name and version

Azure.Messaging.ServiceBus 7.18.4

Describe the bug

Use case

A worker continuously starts and stops processing on the ServiceBusProcessor.
The async MessageHandler creates activities to trace the processing of the messages received.
This creates spans in aspire dashboard / Jaeger which is wanted behaviour.

Implementation

Program.cs

// enable experimental tracing
AppContext.SetSwitch("Azure.Experimental.EnableActivitySource", true);
// enable OTEL
// this adds tracing.AddSource("Azure.Messaging.ServiceBus.*");
builder.Services.AddMyOpenTelemetry(builder.Configuration)

Worker.cs

protected override async Task ExecuteAsync(CancellationToken stoppingToken) {
  while (true)
  {
  // start processing
  await processor.StartProcessingAsync(stoppingToken);
  // make sure no more messages are processed in this run
  for (int i = 0; i < 10; ++i)
  {
      if (MessagesProcessed >= MAXMSGS)
      {
           break;
      }
      await Task.Delay(100);
  }
  // stop processing (give room to other threads)
  await processor.StopProcessingAsync(stoppingToken);
  }
}

async Task MessageHandler(ProcessMessageEventArgs args)
{
    using (var act = _metricsClient.StartMessageReceivingActivity()) {
        // processing logic here
        await args.CompleteMessageAsync(args.Message);
    }
}

Actual behaviour

The activity (ServiceBusReceiver.Receive) for effectively received messages are linked to the activity span created in the MessageHandler. (👍)

The activity (ServiceBusReceiver.Receive) also appears with error: true and error.type: System.Threading.Tasks.TaskCanceledException due to the fact that the processor is stopped in the loop in ExecuteAsync. (👎)

Expected behavior

Since StartProcessingAsync and StopProcessingAsync operations are normal operations, I'd expect no errors/exceptions in the traces.

Actual behavior

cfr. "Actual behaviour" in description

Reproduction Steps

cfr. "Implementation" in description

Environment

.net 9

Microsoft Visual Studio Enterprise 2022
Version 17.12.1
VisualStudio.17.Release/17.12.1+35514.174
Installed Version: Enterprise

[github-actions]

Hello @ibruynin. I'm an AI assistant for the azure-sdk-for-net repository. I have some suggestions that you can try out while the team gets back to you.

• The TaskCanceledException seen in the OpenTelemetry traces is expected when calling StopProcessingAsync on a ServiceBusProcessor. This cancellation is a normal part of the processor shutdown sequence.
• To avoid reporting these cancellations as errors, consider filtering or suppressing TaskCanceledException in your telemetry configuration.
• Refer to the Azure SDK Diagnostics sample for guidance on handling distributed tracing scenarios, where similar patterns are discussed.
• You might also find useful insights in the Aspire Dashboard documentation on managing activity sources with OpenTelemetry.

These suggestions should help tailor your implementation so that normal shutdown exceptions do not generate error spans in your tracing outputs.

The team will get back to you shortly, hopefully this helps in the meantime.

[jsquire]

Hi @ibruynin. Thanks for reaching out and we regret that you're experiencing difficulties. By design, all errors are captured and surfaced as part of diagnostics, but I agree with your perspective that TaskCanceledExceptions are an expected part of normal flow. I'm going to loop in our OTel owner and if they agree, we'll look at filtering these out.

[jsquire]

@lmolkova: Would you please share your thoughts?

//cc: @m-redding, @jeo02

[ibruynin]

Hi @jsquire - Thanks for the swift response.
As proposed by github-actions, adding a processor in the traceBuilder

tracing
    .AddSource("Azure.Messaging.ServiceBus.*")
    .AddProcessor(new TaskCanceledExceptionFilterProcessor());

that looks like this:

public class TaskCanceledExceptionFilterProcessor : BaseProcessor<Activity>
{
    public override void OnEnd(Activity activity)
    {
        if (activity.Status == ActivityStatusCode.Error &&
            activity.StatusDescription.Contains("TaskCanceledException") &&
            activity.DisplayName == "ServiceBusReceiver.Receive")) // [Edit: only filter these activities for this exception]
        {
            // Suppress the activity                
            activity.ActivityTraceFlags &= ~ActivityTraceFlags.Recorded;
        }
        base.OnEnd(activity);            
    }
}

does seem to do the trick. Still interested in the thoughts on this!

[lmolkova]

There is a philosophical question of whether cancellation is an error or not. In this case, the receive operation completes prematurely because the processor is being stopped. If processor is stopped by mistake, this error might be useful.

I believe this is related to #47985 - we should not report the receive activity when processor is being used since it's an internal implementation detail and is noisy. I think this issue is another argument that we should stop reporting it (for processor case).

[jsquire]

After talking this over internally, we have decided not to filter cancellation exceptions. As Liudmila mentions, these may be useful in some contexts, may be something that others are already relying on, and they're also surfaced from the REST-based Azure SDK packages. In this specific scenario, filtering out "Receive" for the processor would silence the spam here.