PostgreSQL getting connection info slowing down tracing

[nijel]

How do you use Sentry?

Sentry Saas (sentry.io)

Version

2.14.0

Steps to Reproduce

1. Use sentry-sdk with Django integration.
2. Profile a view with doing several SQL queries.
3. Notice there is expanduser shown on top of “Slowest Application Functions” in Sentry.

Expected Result

We don't invoke expanduser at all, so it should not be there. Definitely it should not be on top of the list, taking more time than template rendering.

Actual Result

expanduser being identified by Sentry as the slowest thing on this view:

Profile trace:

This seems to be invoked for each SQLCompiler.execute_sql invocation, so for every SQL query.

It is invoked from here:

sentry-python/sentry_sdk/integrations/django/__init__.py

Line 705 in dce589c

connection_params = cursor_or_db.connection.info.get_parameters()

The expanduser then comes from psycopg3 via Path.home():

https://github.com/psycopg/psycopg/blob/af5bfa0ec2690571033e38205a98cfc8c6287134/psycopg/psycopg/_connection_info.py#L86

[szokeasaurusrex]

@nijel Thanks for writing in.

I am lacking full context on your problem, but from what you have shared so far, I think it is possible that what you are observing is expected. The profiler records the entire contents of the call stack over time (with a resolution of ~10ms, meaning that shorter function calls might be missed), so it is fully expected that some functions that are called not directly by you, but rather by libraries (for example, the expanduser here), could show up in your profile.

Does that make sense to you, or am I missing something here? If you still think what you are seeing is wrong, could you please provide more detail on what you are actually seeing, and what you would expect to see? It would be extremely helpful if you could link the page where you took the screenshot

[nijel]

What I think is wrong is that Sentry SDK gets PostgreSQL connection info with each SQL query executed makings it's overhead too big. Caching info per Django connection would heavily improve this (typically there is just one database connection in a request).

[szokeasaurusrex]

@nijel Ah okay, I see now. The problem is that the Sentry SDK is slowing down your app, and you discovered this through profiling, correct?

From the profile you shared, it does indeed look like the SDK is calling the slow function.