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

Unable to log baggages via a processor #2992

Closed
day0ops opened this issue Mar 8, 2022 · 18 comments · Fixed by #4274
Closed

Unable to log baggages via a processor #2992

day0ops opened this issue Mar 8, 2022 · 18 comments · Fixed by #4274
Assignees
Labels
bug Something isn't working
Milestone

Comments

@day0ops
Copy link

day0ops commented Mar 8, 2022

Bug Report

List of packages below,

<PackageReference Include="OpenTelemetry" Version="1.2.0-rc3" />
<PackageReference Include="OpenTelemetry.Exporter.Console" Version="1.2.0-rc3" />
<PackageReference Include="OpenTelemetry.Extensions.Hosting" Version="1.0.0-rc9" />
<PackageReference Include="OpenTelemetry.Instrumentation.AspNetCore" Version="1.0.0-rc9" />
<PackageReference Include="OpenTelemetry.Instrumentation.Http" Version="1.0.0-rc9" />

Runtime version: net6.0

Symptom

I'm trying to use a custom processor like the following to see the baggages that are being propagated. However in this processor Baggage.Current is not present to process the baggages.

public class TelemetryBaggageLogger : BaseProcessor<Activity>
{
    private readonly ILogger<TelemetryBaggageLogger> _logger;
    
    public TelemetryBaggageLogger(ILogger<TelemetryBaggageLogger> logger)
    {
	    _logger = logger ?? throw new ArgumentNullException(nameof(logger));
    }
    
    public override void OnStart(Activity activity)
    {
	    _logger.LogInformation("-------------------> Logging Baggages In BaseProcessor:OnStart <-------------------");
            IDictionaryEnumerator baggageEnumerator = Baggage.Current.GetEnumerator();
            while (baggageEnumerator.MoveNext())
            {
                _logger.LogInformation($"OnStart->Received baggage {baggageEnumerator.Key}:{baggageEnumerator.Value}");
            }
    }
    
    public override void OnEnd(Activity activity)
    {
	    _logger.LogInformation("-------------------> Logging Baggages In BaseProcessor:OnEnd <-------------------");
            IDictionaryEnumerator baggageEnumerator = Baggage.Current.GetEnumerator();
            while (baggageEnumerator.MoveNext())
            {
                _logger.LogInformation($"OnEnd->Received baggage {baggageEnumerator.Key}:{baggageEnumerator.Value}");
            }
    }
}

I inject the processor as the following in the downstream (destination) service.

.AddProcessor(new TelemetryBaggageLogger(logger))

However, I can see the baggages propagating if I log the baggage information in the controller of the downstream service but not the processor.

To Reproduce

Complete code can be found in the project.

It's a simple set of services, Library -> Catalog. Library (source service) calls the Catalog API (downstream service) with a set of baggages.

Baggage.SetBaggage("test.baggage1", "bag1");
Baggage.SetBaggage("test.baggage2", "bag2");

To run the project, use docker-compose -f docker-compose.yml -f docker-compose.override.yml up
To start propagating use curl, curl -iv http://localhost:8002/api/Orders/books

@day0ops day0ops added the bug Something isn't working label Mar 8, 2022
@day0ops
Copy link
Author

day0ops commented Mar 9, 2022

@cijothomas Sorry to ping direct but looks like the issue is resolved with var baggageEnumerator = activity?.Baggage.GetEnumerator(); when enumerating in the processor. Why isnt this possible with Baggage.GetEnumerator() ?

@CodeBlanch
Copy link
Member

@pseudonator Sort of a complicated situation you've run into!

ASP.NET Core 5 and below didn't understand the W3C/OTel baggage header. It used a header called Correlation-Context. So Baggage API is the OTel SDK providing the feature. It flows like this...

That is why in your processor you see empty baggage from the OTel API.

Now as of ASP.NET Core 6 the framework understands baggage. That is why in your processor activity?.Baggage works, it is being handled by that initial step creating the Activity.

@cijothomas
Copy link
Member

If OTel.Instrumentation.AspNetCore is used - then it should have worked in all versions. It does the job of extracting Baggage from "baggage" header.

@tronda
Copy link

tronda commented Apr 20, 2022

We have a desktop application running on .NET FX 4.7.2 where we would like to add enduser.id and enduser.role as baggage since this is what the documentation recommends. On the server side we have both .NET Core services and .NET FX 4.7.2 services running where we would like to get the enduser.* baggage propagated to.

  • In order to propagate these to the services from the desktop client - do I have to add a custom propagator or configure an existing one?
  • On the .NET Core services - is the solution to upgrade to .NET 6?
  • On the .NET FX 4.7.2 service - do I have to add something to get the ASP.NET stack for dotnetfx in order to receive that baggage?

As of now we are focused on distributed tracing.

@paulbatum
Copy link

Ran into the same problem. My enricher that is converting baggage to tags has to enumerate Activity.Baggage to successfully find the baggage. Does this mean that the documentation here is out of date or incorrect?
https://github.com/open-telemetry/opentelemetry-dotnet/tree/main/src/OpenTelemetry.Api#baggage-api

Because it explicitly states that we should interact with Baggage via the Baggage API and not via the activity.

@cijothomas
Copy link
Member

Ran into the same problem. My enricher that is converting baggage to tags has to enumerate Activity.Baggage to successfully find the baggage. Does this mean that the documentation here is out of date or incorrect? https://github.com/open-telemetry/opentelemetry-dotnet/tree/main/src/OpenTelemetry.Api#baggage-api

Because it explicitly states that we should interact with Baggage via the Baggage API and not via the activity.

The document is the correct usage of Baggage API, and it also includes an example enrichment from Baggage. https://github.com/open-telemetry/opentelemetry-dotnet/blob/main/docs/trace/extending-the-sdk/MyEnrichingProcessor.cs

@paulbatum
Copy link

@cijothomas Here is a repro: https://github.com/paulbatum/opentelemetrysample

Steps:

  1. Clone the repo and set Console, AppA and AppB all to run on startup.
  2. If you want to look at the traces in jaeger, run it locally. Otherwise you can comment out the code in https://github.com/paulbatum/OpenTelemetrySample/blob/master/Common/OpenTelemetryConfiguration.cs that is setting up the otlp exporter.
  3. Run the app. You should be able to observe that the user ID header that is attached as baggage in AppA is successfully added to the tags for spans generated by AppB.
  4. Remove the lines that use Activity.Baggage here - https://github.com/paulbatum/OpenTelemetrySample/blob/1d29f0afabf4c76daa0ee58d08bbe6fb67404584/Common/OpenTelemetryConfiguration.cs#L64-L68
  5. Rerun and you will find that the user ID tag is not attached to the AppB spans.
  6. Note that there is code that is using Baggage.GetBaggage, but its not successfully finding the userID baggage.

Its possible this app is doing something wrong, but the point is that at least in this example, the enricher that uses Baggage.GetBaggage() does not work as expected.

@cijothomas
Copy link
Member

I just modified the existing example in this repo (https://github.com/open-telemetry/opentelemetry-dotnet/blob/main/examples/AspNetCore/Controllers/WeatherForecastController.cs)

foreach (var baggage in Baggage.GetBaggage())
{
    Activity.Current?.SetTag(baggage.Key, baggage.Value);
}

And made a request to it passing a header baggage with value as "foo=bar", and the activity added additional tag (foo with value as bar).

Can you check the existing example app to see if it helps identify the issue in your app?

@paulbatum
Copy link

paulbatum commented Sep 16, 2022

The main difference that jumps out at me is that you're not doing this from a telemetry processor. In my sample, if I put code that checks Baggage.GetBaggage in the controller, it gets picked up. Its only missing from Baggage.GetBaggage when the processor attached to appB runs.

Also, in my sample, the telemetry processor in app A does pick up the baggage ok, presumably because code explicitly set the baggage in the controller with Baggage.SetBaggage(..). So it seems like the issue is a combination of 1) having baggage get handled automatically by asp.net instrumentation and b) using said baggage from a telemetry processor.

does the order of the last 3 lines of code here somehow matter?

        builder.Services.AddOpenTelemetryTracing(t =>
            t.AddSource(ActivitySource.Name)
            .SetResourceBuilder(ResourceBuilder.CreateDefault()
                .AddService(applicationName))
            .AddHttpClientInstrumentation()
            .AddAspNetCoreInstrumentation()
            .AddProcessor(new TraceBaggageEnricher())

@cijothomas
Copy link
Member

@CodeBlanch We have a "lost Baggage" issue here due to https://github.com/open-telemetry/opentelemetry-dotnet/blob/main/src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInListener.cs#L238

I am not able to recollect the reason behind clearing Baggage from ASP.NET Core Instrumentation, not from the SDKs Activity.OnEnd logic (after calling processors..)

@cijothomas
Copy link
Member

@cijothomas
Copy link
Member

@paulbatum There is nothing wrong in your code or the Baggage API or the SDK. The misbehaving component is the Asp.Net Core instrumentation library. Will get back once we dig into this a bit more.

@CodeBlanch
Copy link
Member

I was just chatting with @vishweshbankwar about this. Figured I would post some thoughts here.

Unclear to me this is an issue.

In Processor.OnEnd what does Activity.Current represent? Is it the Activity currently being processed by OnEnd, or is it something else or null? If the later, why would we expect Baggage.Current to be any different? If Activity.Current is still set in Processor.OnEnd then I would agree this is an issue we should fix... but I think it has been updated away by then.

To say that another way, Activity.Current and Baggage.Current are only good until the Activity is stopped/completed at which point they become the parent or null.

@paulbatum Have you tried to use the "Enrich" feature to access/process the baggage while the Activity is still live/current?

@CodeBlanch
Copy link
Member

Just replying to myself, Activity.Current does seem to be valid in Processor.OnEnd! Looking at options for how we could fix this.

@cijothomas
Copy link
Member

we should proceed to remove the cleanup of baggage in asp.net and asp.net core instrumentation libraries and that should take care of fixing this.
Tagging this as instrumentation-library issue, and not Otel API/SDK issue.

@cijothomas
Copy link
Member

Though this fix is in asp.net core, tagging for consideration in 1.5.0 of sdk timeline.

@dinaso
Copy link

dinaso commented Feb 17, 2023

I ran into the same issue that baggage cleanup. I am looking forward to the fix.

@cijothomas
Copy link
Member

@vishweshbankwar is working on this with the goal of fixing this in 1.5

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants