Question: How to properly intercept response body on Enrich method

[zfael]

Question

I've been digging into a way to intercept the response body using the Enrich method available in the AddAspNetCoreInstrumentation hook.

The thing is that I haven't found a way to properly get the actual response body into a string version or even an object, the HttpResponse object is available at the OnStopActivity event name but, turns out, the body stream is kind not ready to be read at that point.
Would like to know if someone has already been able to accomplish that or if there's even a way of accomplishing it.

Quick code example:

services.AddOpenTelemetryTracing((builder) =>
{
    builder
    .AddAspNetCoreInstrumentation((options) => options.Enrich = async (activity, eventName, rawObject) =>
    {
        if (eventName.Equals("OnStartActivity"))
        {
            // no issues here, was able to properly get the Request Body

            if (rawObject is HttpRequest httpRequest)
            {
                if (httpRequest?.Body != null && httpRequest.Body.CanRead)
                {
                    using (var sr = new StreamReader(httpRequest.Body))
                    {
                        var requestBody = await sr.ReadToEndAsync();
                        activity.SetTag("http.request.body", requestBody);
                    }
                }

                activity.SetTag("http.request.headers", httpRequest?.Headers.ToString());
                activity.SetTag("requestProtocol", httpRequest.Protocol);
            }
        }
        else if (eventName.Equals("OnStopActivity"))
        {
            if (rawObject is HttpResponse httpResponse)
            {
                // heres the part where I'm kinda struggling to get the Response body, Ive tried a few different attempts, like the request one, but not luck yet
            }
        }
    })
})

Describe your environment.

ASP.NET Core 3.1 Web API project (using the weather example that Visual Studio automatically creates).

What are you trying to achieve?
Being able to properly intercept the response body so I can add that into the activity as a tag (I bet this is pretty simple to accomplish and it's just me being a noob at it 😄 )

[eddynaka]

@zfael , when i implemented i haven't test an async behavior.
https://github.com/open-telemetry/opentelemetry-dotnet/blob/master/src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInListener.cs
https://github.com/open-telemetry/opentelemetry-dotnet/blob/master/test/OpenTelemetry.Instrumentation.AspNetCore.Tests/BasicTests.cs
if you check the second link and run the tests that we implemented the enrich, you will be able to trigger the onstop. Can you check if that works?

[zfael]

@eddynaka Sorry but I have been facing some issues on compile the opentelemetry-dotnet project on my end but I'll give it a shot if I get it working, thanks for the point to that 👍

[eddynaka]

ping me on gitter, i might be able to help

[zfael]

sure, just pinged you

[CodeBlanch]

@zfael I think what you are going to run into here is that ASP.NET Core doesn't stop the Activity (triggering the Enrich call) until after the response has been written and closed:

https://github.com/dotnet/aspnetcore/blob/6ea0926914704c92ffbb34f955d391ef7fd66aec/src/Hosting/Hosting/src/Internal/HostingApplication.cs#L91-L94

https://github.com/dotnet/aspnetcore/blob/2f64d67a7ce574f4b02103aea2a6bf00ad256df7/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs#L138

You are better approaching this using some middleware. In that middleware, save & switch the response body with a MemoryStream you control. Call/Await "next" to finish the pipeline. Then do what you want with the response sitting in your MemoryStream. When you are all done, write that MemoryStream out to the original response body. Just know, you are going to eat up a lot of memory and delay your responses doing this.

[makiyamad]

edit: Look at the comments below pointed by @CodeBlanch before trying this out. This doubles the memory hit for every request/response.

My original comment: One thing that worked well for me was enriching the HttpClient Instrumentation and using HttpRequestMessage and HttpResponseMessage. This way I could use ReadAsStringAsync() for the request & response. My TraceProviderBuilder ended up like the following:

builder
	.SetSampler(new AlwaysOnSampler())
	.AddAspNetCoreInstrumentation()
	.AddHttpClientInstrumentation(options =>
	{
		options.Enrich = (activity, eventName, rawObject) =>
		{
			if (eventName.Equals("OnStartActivity"))
			{
				if (rawObject is HttpRequestMessage httpRequest)
				{
					var request = "empty";
					if (httpRequest.Content != null)
						request = httpRequest.Content.ReadAsStringAsync().Result;
					activity.SetTag("http.request_content", request);
				}
			}

			if (eventName.Equals("OnStopActivity"))
			{

				if (rawObject is HttpResponseMessage httpResponse)
				{
					var response = "empty";
					if (httpResponse.Content != null)
						response = httpResponse.Content.ReadAsStringAsync().Result;
					activity.SetTag("http.response_content", response);
				}
			}

		};
	})

This way I was able to visualize the http.request_content & http.response_content in the UI of my chosen telemetry tool.

[CodeBlanch]

@makiyamad Great I'm glad you got it to work! Thanks for sharing the code. The HttpClient ("outgoing") instrumentation fires before returning from Send so the response should always be available when enrich fires.

A couple of things to watch out for...

• async (activity, eventName, rawObject)
  The instrumentation is NOT awaiting the task created by adding async to the lambda. This could cause race conditions or other hard to debug issues.
• Memory usage is going to go WAY up reading every request + response into a string. ReadAsStringAsync is going to buffer first, and then produce a string. So it's really a double-hit on the memory.
• If there's anything sensitive in the request or response (credit card, SSN, etc.) the intention could have been to protect it via the transport (TLS/SSL) but this code will leak it into telemetry.

My general recommendation would be to not push the raw request or response into your trace, use logging for that, and only if you need to turn it on to triage something.

[makiyamad]

Thank you @CodeBlanch, great points!

[zfael]

circling back to this -- I can confirm I was able to get the response body using the approach @makiyamad shared! thanks for sharing that 🙌

[DavoBR]

The main issue reported by @zfael is about aspnet instrumentation but the solution of @CodeBlanch is for HttpClient.

Is there a way to read the response body in the enrich method? i don't want to use a middleware

[CodeBlanch]

@DavoBR

You can try the below if you want, it seems to work in my limited testing. But I cannot stress enough this is a really really bad awful idea which will destroy the throughput of your service(s) 💣

builder.AddAspNetCoreInstrumentation(options => options.Enrich = EnrichAspNetCore);

static void EnrichAspNetCore(Activity activity, string eventName, object payload)
{
    switch (eventName)
    {
        case "OnStartActivity":
            if (payload is HttpRequest request)
            {
                var context = request.HttpContext;

                var bufferedResponseStream = new MemoryStream();

                var streamResponseBodyFeature = new StreamResponseBodyFeature(
                    bufferedResponseStream,
                    context.Features.Get<IHttpResponseBodyFeature>()!);

                context.Features.Set<IHttpResponseBodyFeature>(streamResponseBodyFeature);

                context.Response.OnStarting(async () =>
                {
                    try
                    {
                        if (bufferedResponseStream.TryGetBuffer(out var data))
                        {
                            string responseBody = Encoding.UTF8.GetString(data.Array!, 0, data.Count);

                            activity.SetTag("http.response_content", responseBody);
                        }
                    }
                    finally
                    {
                        var originalStream = streamResponseBodyFeature.PriorFeature?.Stream;
                        if (originalStream != null)
                        {
                            bufferedResponseStream.Position = 0;

                            await bufferedResponseStream.CopyToAsync(originalStream).ConfigureAwait(false);
                        }
                    }
                });
            }

            break;
    }
}

[ekjuanrejon]

How to get this working on .net 6. I get an error where it says that cannot read response twice

[DavoBR]

Hi @ekjuanrejon,

This is a sample of my implementation working on net6.0, I hope it works for you

services.AddOpenTelemetryTracing(builder => {
    builder.AddAspNetCoreInstrumentation(config => {
        config.Enrich = Enrich;
        config.RecordException = true;
    });
});

void Enrich(Activity activity, string eventName, object obj)
{
    switch (eventName) {
        case "OnStartActivity" when obj is HttpRequest req:
            ReadResponseBody(req.HttpContext.Response, body => {
                activity.AddEvent("response", tags => tags.Add("body", body));
            });
            break;
    }
}

void ReadResponseBody(HttpResponse res, Action<string> onReadBody)
{
    var context = res.HttpContext;
    var priorFeature = context.Features.Get<IHttpResponseBodyFeature>();

    if (priorFeature == null) return;

    var bufferedResponseStream = RecyclableMemoryStreamManager.GetStream();
    var streamResponseBodyFeature = new StreamResponseBodyFeature(bufferedResponseStream, priorFeature);

    context.Features.Set<IHttpResponseBodyFeature>(streamResponseBodyFeature);

    context.Response.OnStarting(async () => {
        try {
            if (bufferedResponseStream.TryGetBuffer(out var data) && data.Array != null) {
                var responseBody = Encoding.UTF8.GetString(data.Array, 0, data.Count);
                onReadBody(responseBody);
            }
        } finally {
            var originalStream = streamResponseBodyFeature.PriorFeature?.Stream;
            if (originalStream is not null) {
                bufferedResponseStream.Position = 0;
                await bufferedResponseStream.CopyToAsync(originalStream).ConfigureAwait(false);
            }

            await bufferedResponseStream.DisposeAsync();
        }
    });
}

[chrisribe]

Does not work for dotnet 8 Enrich is no longer implemented :(

[cijothomas]

Does not work for dotnet 8 Enrich is no longer implemented :(

That is not true. See https://github.com/open-telemetry/opentelemetry-dotnet-contrib/tree/main/src/OpenTelemetry.Instrumentation.AspNetCore#enrich

(Enrich is renamed to more specific EnrichWith*, but all functionality remains same)

[chrisribe]

Yes I have explored these and they work great for all http request, response + exception.

But I could not figure out how to get the "eventName" from them to filter "OnStartActivity", "OnStopActivity" events.
This was available via Enrich as shown in the above example.

Any suggestions ? Thanks in advance

[Kielek]

These are no longer needed. OnStartActivity - correspond to EnrichWithRequest
OnStopActivity - EnrichWithReponse. OnException - EnrichWithcException (method names on top of my head).

[chrisribe]

Oh I was under the impression this was called multiple times (for some reason), sorry got confused there and should have tested that !

Thanks for taking my head out of the sand !
Doh