Sanic integration does not send any errors outside a request (like in a background task)

[cnicodeme]

How do you use Sentry?

Sentry Saas (sentry.io)

Version

1.9.9

Steps to Reproduce

Sanic is using Sentry Hub by plugging the 'http.lifecycle.request' signal to start the Hub, and the 'http.lifecycle.response' to exit it.

The problem is that when errors occurs outside the HTTP lifecycle request, like in a background task, no errors are reported by Sentry/Sanic.

Here's a reproducible bug:

from sanic import Sanic
from sanic.response import text
import asyncio, sentry_sdk
from sentry_sdk.integrations.sanic import SanicIntegration

app = Sanic("Sanic-Sentry-Test")


async def fail_later(*args, **kwargs):
    print('Starting task, might take a while...')
    await asyncio.sleep(5)
    value = 0
    print('Value is: {}'.format(value))
    print('Output is {}'.format(5/value))  # This should raise a ZeroDivisionError exception, but nothing
    print('Done task.')


@app.get("/")
async def hello_world(request):
    request.app.add_task(fail_later(), name="fail_later")
    return text("Hello, world.")


sentry_sdk.init('...url', integrations=[SanicIntegration()])

if __name__ == "__main__":
    app.run()

Of course, the same code, but with the ZeroDivisionError directly on hello_world properly appears at Sentry, which means the integration is working as expected when inside a request, but not when outside.

I've seen with the team at Sanic, including @ahopkins about this on sanic-org/sanic#2576.

Expected Result

The exception should be logged at Sentry

Actual Result

Nothing is logged

[ahopkins]

How do other integrations handle exception handling outside the request/response cycle? I'm happy to work on this, but I guess the question really is what is the expected behavior for the SDK? Once an operation is outside the framework, the question becomes whether the integration should handle this or an api should be exposed for the developer to catch on their own.

[cnicodeme]

I was thinking about the same thing, since Sentry shows a lot of Request information. Then I realized it also has a Celery integration, which works outside the request process. Maybe it would be a good example?

[cnicodeme]

(I'm trying to understand what is going on at the Celery Integration. From my quick review, it wraps the call to the Task with a Sentry "kind-of" decorator. Maybe it would be interesting to do the same on any added background task?)

[ahopkins]

Yeah, if the whole thing should be handled and transparent, I was thinking we'd monkey patch add_task.

Will checkout how the other integrations handle similar issues.

[sl0thentr0py]

@antonpirker maybe we should also add a capture_exception around our new task factory in #1689

[antonpirker]

Yes, good idea.

For context. We are developing a low level ayncio integration that creates spans for every background task that is created in asyncio.

In this integration we also can capture exceptions.
(similar is done in the ThreadingIntegration)

[ahopkins]

Ahh, okay. So this ticket should probably wait for that.

[cnicodeme]

@antonpirker Do you have an ETA on when this will be published? Not pushing or anything, just to know what to expect here.

I plan to work on a wrapper this afternoon to have a quick fix until the release. I'll post the code here once it's done.

[antonpirker]

I hope to get something out today. We have a PR ready for the change: #1695
Some work still needs to be done. But if this is merged we are ready for a release and will deploy a new version of the SDK today.

[cnicodeme]

Wow! That fast ?! That's awesome!
I guess I won't have to work on quick fix this afternoon then :D

Can you ping here once the SDK is released? I'll update it right away.

Thank you!

[antonpirker]

The new release is out: https://github.com/getsentry/sentry-python/releases/tag/1.10.0

You probably have to manually enable the new asyncio integration to have the errors show up.

Something like this:

from sentry_sdk.integrations.asyncio import AsyncioIntegration

sentry_sdk.init(
  dsn="...",
  integrations=[
    AsyncioIntegration(),
  ]
)

hope this helps

[antonpirker]

Currently we are not auto-enabling the AsyncioIntegration(). We want to see how it is doing in the next couple of weeks and then we will think about auto enabling it.

[cnicodeme]

Thank you! I'll update this soon.

One question; when you'll enable it automatically, will it cause problems on my code since I'm also enabling it manually?

[antonpirker]

No

[cnicodeme]

Ok, thank you :)

[antonpirker]

Could you test the new version and see if this fixes your problem?

[cnicodeme]

Easy! I just updated my code by adding your "AsyncioIntegration":

from sanic import Sanic
from sanic.response import text
import asyncio, sentry_sdk
from sentry_sdk.integrations.sanic import SanicIntegration
from sentry_sdk.integrations.asyncio import AsyncioIntegration


app = Sanic("Sanic-Sentry-Test")


async def fail_later(*args, **kwargs):
    print('Starting task, might take a while...')
    await asyncio.sleep(5)
    value = 0
    print('Value is: {}'.format(value))
    print('Output is {}'.format(5/value))  # This should raise a ZeroDivisionError exception, but nothing
    print('Done task.')


@app.get("/")
async def hello_world(request):
    request.app.add_task(fail_later(), name="fail_later")
    return text("Hello, world.")


sentry_sdk.init('...url, integrations=[SanicIntegration(), AsyncioIntegration()])

if __name__ == "__main__":
    app.run()

Ran it.

I got no errors at all at Sentry :/

[szokeasaurusrex]

It appears that this issue is caused by an Asyncio integration bug documented in #2328 and #2333, rather than a problem with the Sanic integration. To work around the issue, whenever you are using the Sentry SDK in an async application, the Sentry SDK needs to be initialized from within an async function. We would eventually like to fix this behavior so that the Asyncio integration can still work when the SDK is initialized from outside an async function, but because fixing this bug would likely require us to rewrite significant portions of our Asyncio integration, it will likely take some time before we get around to fixing this issue.

In this case (and with Sanic apps generally), you can work around the bug by initializing the SDK from within a "before_server_start" listener, like so:

from sanic import Sanic
import asyncio, sentry_sdk
from sentry_sdk.integrations.sanic import SanicIntegration
from sentry_sdk.integrations.asyncio import AsyncioIntegration

app = Sanic("<your_app_name>")

# ...

@app.listener("before_server_start")
async def init_sentry(_):
    sentry_sdk.init(
        dsn="<your_dsn>",
        integrations=[SanicIntegration(), AsyncioIntegration()],
    )

@cnicodeme Please let us know if you have any questions, or if you encounter any difficulties while implementing the workaround.

[cnicodeme]

That's quite an interesting approach!
Thank you for providing a solution to this issue!

I've done the code you recommended (well, excepted that I'm calling the before_server_start via app.register_listener(init_sentry, "before_server_start")

I'll try to bring some news in a few weeks to let you know if this resolved the issue. Don't hesitate to ping me if I forgot ;)

[cnicodeme]

Just out of curiosity, is there a specific reason to use "before_server_start" instead of "main_process_start" ?

[szokeasaurusrex]

I've done the code you recommended (well, excepted that I'm calling the before_server_start via app.register_listener(init_sentry, "before_server_start")

Okay, just please make sure that your init_sentry function is an async function. The Sentry SDK needs to be initialized from an async function in order for it to instrument the asyncio event loop and enable the Asyncio integration to work properly.

Just out of curiosity, is there a specific reason to use "before_server_start" instead of "main_process_start" ?

Yes, there is -- if you use main_process_start, it seems like the SDK fails to capture any errors at all. Just speculating here, but my guess for why only before_server_start works is that the before_server_start takes place in the same event loop as the event handling, where main_process_start is in its own event loop according to this diagram (if I am understanding the diagram correctly).

[cnicodeme]

A month after having implemented it, I can confirm that this resolves the issue. I stopped having the "types.SimpleNamespace" object has no attribute "_sentry_hub".

I'll close this ticket.

Thanks for your help!