Opentelemetry-dotnet: 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 🙌