sentry_sdk.capture_message() does nothing within a FastAPI route

[jarednieder]

How do you use Sentry?

Sentry Saas (sentry.io)

Version

1.32.0

Steps to Reproduce

I'm working with a FastAPI application and when I attempt to call sentry_sdk.capture_message() from within a request context, nothing is logged in Sentry.

Here is a minimal app to reproduce the issue:

import sentry_sdk
from fastapi import FastAPI
import os

sentry_sdk.init(
    dsn=os.getenv('SENTRY_DSN'),
)

app = FastAPI(title="Sentry Test")

sentry_sdk.capture_message("TEST MESSAGE")

@app.get('/')
def example():
    sentry_sdk.capture_message("TEST MESSAGE (IN ROUTE)")
    return 'Ok'

Running the previous snippet with SENTRY_DSN=XYZ uvicorn app:app, I notice the following:

1. TEST MESSAGE will appear in Sentry when the app starts
2. If I navigate to the configured route (http://localhost:8000/), the second message (TEST MESSAGE (IN ROUTE)) does not appear in Sentry.

I observe that the second message will appear if I set auto_enabling_integrations=False when initializing sentry_sdk, however I would prefer to gain the benefits of the FastAPI integration.

Below is the output from pip freeze --all:

annotated-types==0.6.0
anyio==3.7.1
certifi==2023.7.22
click==8.1.7
exceptiongroup==1.1.3
fastapi==0.103.2
h11==0.14.0
idna==3.4
pip==21.2.4
pydantic==2.4.2
pydantic_core==2.10.1
sentry-sdk==1.32.0
setuptools==58.1.0
sniffio==1.3.0
starlette==0.27.0
typing_extensions==4.8.0
urllib3==2.0.6
uvicorn==0.23.2

Expected Result

I expect to receive a message, TEST MESSAGE (IN ROUTE), in Sentry when a user navigates to http://localhost:8000/

Actual Result

No message appears in Sentry when a user navigates to http://localhost:8000/

[sentrivana]

Hey @jarednieder, thanks for the report!

I can't repro this, I get both messages in Sentry. Could you init the SDK with debug=True and see if there's anything suspicious in the logs when you run your example? It logs something like this for messages:

[sentry] DEBUG: Sending event, type:null level:info event_id:123456789abcdef12345467889abc project:123456 host:789123.ingest.sentry.io

You should see this at least for the module level message.

[jarednieder]

@sentrivana here is the full debug trace:

 [sentry] DEBUG: Setting up integrations (with default = True)
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.aiohttp.AioHttpIntegration: AIOHTTP not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.boto3.Boto3Integration: botocore is not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.bottle.BottleIntegration: Bottle not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.celery.CeleryIntegration: Celery not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.django.DjangoIntegration: Django not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.falcon.FalconIntegration: Falcon not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.flask.FlaskIntegration: Flask is not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.httpx.HttpxIntegration: httpx is not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.pyramid.PyramidIntegration: Pyramid not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.rq.RqIntegration: RQ not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.sanic.SanicIntegration: Sanic not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.sqlalchemy.SqlalchemyIntegration: SQLAlchemy not installed.
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.tornado.TornadoIntegration: Tornado not installed
 [sentry] DEBUG: Setting up previously not enabled integration argv
 [sentry] DEBUG: Setting up previously not enabled integration atexit
 [sentry] DEBUG: Setting up previously not enabled integration dedupe
 [sentry] DEBUG: Setting up previously not enabled integration excepthook
 [sentry] DEBUG: Setting up previously not enabled integration logging
 [sentry] DEBUG: Setting up previously not enabled integration modules
 [sentry] DEBUG: Setting up previously not enabled integration stdlib
 [sentry] DEBUG: Setting up previously not enabled integration threading
 [sentry] DEBUG: Setting up previously not enabled integration fastapi
 [sentry] DEBUG: Setting up previously not enabled integration redis
 [sentry] DEBUG: Did not enable default integration redis: Redis client not installed
 [sentry] DEBUG: Setting up previously not enabled integration starlette
 [sentry] DEBUG: Enabling integration argv
 [sentry] DEBUG: Enabling integration atexit
 [sentry] DEBUG: Enabling integration dedupe
 [sentry] DEBUG: Enabling integration excepthook
 [sentry] DEBUG: Enabling integration logging
 [sentry] DEBUG: Enabling integration modules
 [sentry] DEBUG: Enabling integration stdlib
 [sentry] DEBUG: Enabling integration threading
 [sentry] DEBUG: Enabling integration fastapi
 [sentry] DEBUG: Enabling integration redis
 [sentry] DEBUG: Enabling integration starlette
 [sentry] DEBUG: Setting SDK name to 'sentry.python.fastapi'
 [sentry] DEBUG: Sending event, type:null level:info event_id:d72189e28d1a4484af8b7e5a2d6530ae project:4505347059351552 host:o4505347056599040.ingest.sentry.io
 [sentry] DEBUG: [ASGI] Created transaction (continuing trace): <Transaction(name='http://127.0.0.1:8000/', op='http.server', trace_id='5e35bcd184a74a939070732c76bfe32c', span_id='bb3c99889c5a2ea2', parent_span_id=None, sampled=None, source='url')>
 [sentry] DEBUG: [ASGI] Set transaction name and source on transaction: 'http://127.0.0.1:8000/' / 'url'
 [sentry] DEBUG: [Profiling] Discarding profile because transaction is discarded.
 [sentry] DEBUG: [ASGI] Started transaction: <Transaction(name='http://127.0.0.1:8000/', op='http.server', trace_id='5e35bcd184a74a939070732c76bfe32c', span_id='bb3c99889c5a2ea2', parent_span_id=None, sampled=False, source='url')>
 [sentry] DEBUG: [FastAPI] Set transaction name and source on scope: / / route
 [sentry] DEBUG: [Profiling] updating active thread id to 6194491392
 [sentry] DEBUG: Sending event, type:null level:info event_id:4ca53503373b424bbc5d0124990f7a49 project:4505347059351552 host:o4505347056599040.ingest.sentry.io
 [sentry] DEBUG: Discarding transaction because sampled = False
 [sentry] INFO: Discarded session update because of missing release
 [sentry] DEBUG: [ASGI] Created transaction (continuing trace): <Transaction(name='http://127.0.0.1:8000/favicon.ico', op='http.server', trace_id='d21c6cd822b84b308ec25c5dcb1e9be3', span_id='99afbc0549a1f332', parent_span_id=None, sampled=None, source='url')>
 [sentry] DEBUG: [ASGI] Set transaction name and source on transaction: 'http://127.0.0.1:8000/favicon.ico' / 'url'
 [sentry] DEBUG: [Profiling] Discarding profile because transaction is discarded.
 [sentry] DEBUG: [ASGI] Started transaction: <Transaction(name='http://127.0.0.1:8000/favicon.ico', op='http.server', trace_id='d21c6cd822b84b308ec25c5dcb1e9be3', span_id='99afbc0549a1f332', parent_span_id=None, sampled=False, source='url')>
 [sentry] DEBUG: Discarding transaction because sampled = False
 [sentry] INFO: Discarded session update because of missing release

There are two Sending event... entries, the first corresponding to startup and the second corresponding to the endpoint message, however I still only receive the first message in Sentry

[sentrivana]

@jarednieder Thanks! Looks like the SDK is sending both messages, so it must be getting dropped somewhere further down the line.

Stupid question, but you've ruled out filters in Sentry being responsible for the second message not popping up (e.g. the issue was marked as resolved at some point and is thus not showing up as a new issue)? I don't off the top of my head see any reason why the message should be getting dropped, it's definitely not crossing any size bounds.

[jarednieder]

Stupid question, but you've ruled out filters in Sentry being responsible for the second message not popping up (e.g. the issue was marked as resolved at some point and is thus not showing up as a new issue)?

@sentrivana It turns out that this isn't a stupid question at all. There was an Inbound Data Filter that was filtering out all localhost traffic. Disabling this allowed me to test locally 🤦

Thanks a bunch for helping me debug this and apologies for the oversight on my side.

[sentrivana]

@jarednieder No worries! Happy that it's working now. 👍🏻