Django StreamingHttpResponse View not working as expected

[marcoaleixo]

How do you use Sentry?

Sentry Saas (sentry.io)

Version

2.18.0

Steps to Reproduce

1. Have a view like

class StreamingView(APIView):

    def post(self, request, *args, **kwargs):

        span = sentry_sdk.start_span(name=f"Log: {record.msg}", op="log.info", sampled=False)
        print(span)
        span.set_data("value", record.msg)
        span.set_data("filename", f"{record.pathname} at line {record.lineno}")
        span.finish()

        generator_streaming = dummy_function.execute(parameters=parameters)
        
        return StreamingHttpResponse(generator_streaming, content_type='text/event-stream')

Here the span.trace_id will be for instance "1234"

2. Inside the dummy_function

def execute():
        span = sentry_sdk.start_span(name=f"Log: {record.msg}", op="log.info", sampled=False)
        print(span)
        span.set_data("value", record.msg)
        span.set_data("filename", f"{record.pathname} at line {record.lineno}")
        span.finish()

In this function, the trace_id will be totally different.

I think that this is related the StreamingHttpResponse, because the Sentry is working fine for all my other views.

Feel free to ask more details to help in the investigation.

FROM python:3.9.18-slim-bullseye
Django==4.1
djangorestframework==3.14

I'm executing my server with python manage.py runserver 0.0.0.0:8000
In production we use something like gunicorn api.wsgi -b 0.0.0.0:8081

Expected Result

The trace_id should stay the same in StreamingHttpResponse views and underlying function calls.

Actual Result

The trace_id is different between the view and underlying function calls.

[marcoaleixo]

Do we have a way to set the trace_id?
Maybe an easy fix is to get the trace_id in the view level and pass as parameter to my function and do a transaction.set_trace_id(trace_id=trace_id).

But it seems that we don't have a set_trace_id thing at transaction/event level, right?

I know that we can do a Span(trace_id=myid), but passing this to ALL calls downstream is bad. 😅

[antonpirker]

Hey @marcoaleixo thanks for raising this, I will have a look!

[antonpirker]

Indeed!

I have now reproduced this with this demo application:
https://github.com/antonpirker/testing-sentry/blob/main/test-django-rest-framework-streaming/mysite/api/views.py

The first span "Streaming View" is present in the trace, but the second span "Stream Response Generator" is missing (because it has the wrong trace id)

[antonpirker]

This is a bug. I guess it has something to do with how Django handles streaming views and what we monkey patch in Django. Sentry is probably not patching the functions in Django that are handling the streaming responses.

[marcoaleixo]

hey @antonpirker - thanks for taking a look but I have a quick question: how do you prioritize those fixes?
This bug is creating a hole in the observability of one of my main endpoints :/

Just to understand if I will need to use another observability tool until you fix this.
I do have some bandwidth to work on this fix but not sure if I have enough context to work on it.

[antonpirker]

Hey! I will have some time today and tomorrow to look at this. I will keep you posted on the progress

[antonpirker]

I tested now with Uvicorn and Gunicorn.

Using Uvicorn (asgi) it works. The parent-child relationship is not correct, but at least the spans are there:

Using Gunicorn (wsgi) it does not work:

[antonpirker]

Small update: The problem is that StreamingHttpResponse() finishes right away and this leads to the transaction being closed promptly. The spans generated in the generator are outside of the transactions time span and thus not part of that trace and are lost.

[sentrivana]

Reopening since we ultimately reverted the change

[marcoaleixo]

Is the solution of this bug complicated?
Asking that because this is really making our life more difficult to debug issues related to our LLM based endpoints.

Do you think that's too risky to deploy the reverted PR? is the performance the only thing that made you revert it?
I don't have the mooost popular ( 5M spans/daily ) service out there ( yet ), so maybe I can monitor closely and rollback if needed.

[sentrivana]

Hey @marcoaleixo, it's unfortunately more tricky than we realized and there likely won't be a proper fix until after the holidays.

The PR was reverted for performance reasons, it's spawning an additional thread per request. It's hard to tell where the cutoff is when this starts being a problem since it depends on your setup etc. -- it could work fine for you. As long as you have the option to monitor it for some time I think you could go for it.

[marcoaleixo]

Just sharing that we deployed the branch on Monday and no major impact on our latency/CPU usage.
We are actually sending only < 3M spans daily.

[szokeasaurusrex]

Awesome, thanks for sharing @marcoaleixo! As @sentrivana mentioned, we hope to continue working on a proper fix after the holidays.