dd-trace-py is only reporting get-socket in APM spans

guyzmo commented 3 weeks ago

Summary of problem

I set up dd-trace-py following the documentation, I did patch(pymongo=True). In the APM dashboard, I have traces for the db with pymongo.get_socket but I have no other information.

What I'm expecting is to have the type of command/operator that's being used, and the full query text.

Which version of dd-trace-py are you using?

Currently I'm running 2.9.2 because of the latency bug, but I'm about to upgrade to 2.10.6.

Which version of pip are you using?

I set up my project using rye, but I deploy using pip for python 3.10.2.

Which libraries and their versions are you using?

`pip freeze`

``` altair==5.3.0 anyio==4.4.0 attrs==24.2.0 beanie==1.11.6 blinker==1.8.2 bytecode==0.15.1 cachecontrol==0.14.0 cachetools==5.4.0 cattrs==23.2.3 certifi==2024.7.4 cffi==1.17.0 chardet==5.2.0 charset-normalizer==3.3.2 click==8.1.7 cloudevents==1.11.0 contourpy==1.2.1 cryptography==43.0.0 cycler==0.12.1 ddsketch==3.0.1 ddtrace==2.10.6 deprecated==1.2.14 deprecation==2.1.0 dnspython==2.6.1 email-validator==2.2.0 envier==0.5.2 et-xmlfile==1.1.0 exceptiongroup==1.2.2 fastapi==0.111.1 fastapi-cli==0.0.5 firebase-admin==6.5.0 flask==3.0.3 flexpolyline==0.1.0 fonttools==4.53.1 functions-framework==3.5.0 geographiclib==2.0 geopandas==1.0.1 geopy==2.3.0 gitdb==4.0.11 gitpython==3.1.43 google-api-core==2.19.1 google-api-python-client==2.140.0 google-auth==2.33.0 google-auth-httplib2==0.2.0 google-auth-oauthlib==1.2.1 google-cloud-appengine-logging==1.4.5 google-cloud-audit-log==0.2.5 google-cloud-bigquery==3.25.0 google-cloud-core==2.4.1 google-cloud-firestore==2.17.0 google-cloud-logging==3.11.1 google-cloud-pubsub==2.19.0 google-cloud-storage==2.18.1 google-cloud-tasks==2.16.5 google-crc32c==1.5.0 google-events==0.12.0 google-resumable-media==2.7.1 googleapis-common-protos==1.63.2 grpc-google-iam-v1==0.13.1 grpcio==1.65.4 grpcio-status==1.62.3 gunicorn==22.0.0 h11==0.14.0 h3==3.7.7 httpcore==0.17.3 httplib2==0.22.0 httptools==0.6.1 httpx==0.24.1 idna==3.7 igraph==0.11.6 importlib-metadata==8.0.0 itsdangerous==2.2.0 jinja2==3.1.4 jsonschema==4.23.0 jsonschema-specifications==2023.12.1 kiwisolver==1.4.5 loguru==0.7.2 mangopaysdk==3.34.2 markdown-it-py==3.0.0 markupsafe==2.1.5 matplotlib==3.9.1.post1 mdurl==0.1.2 millify==0.1.1 motor==2.5.1 msgpack==1.0.8 multidict==6.0.5 names==0.3.0 networkx==3.3 notifiers==1.3.3 numpy==2.0.1 oauthlib==3.2.2 openpyxl==3.1.5 opentelemetry-api==1.26.0 packaging==24.1 pandas==2.2.2 phonenumbers==8.13.42 pillow==10.4.0 plotly==5.23.0 polycircles==0.3.7 polyline==2.0.2 proto-plus==1.24.0 protobuf==4.25.4 protobuf3==0.2.1 pyarrow==17.0.0 pyasn1==0.6.0 pyasn1-modules==0.4.0 pycparser==2.22 pydantic==1.10.16 pydeck==0.9.1 pygments==2.18.0 pyinstrument==4.7.2 pyjwt==2.9.0 pymongo==3.13.0 pyogrio==0.9.0 pyparsing==3.1.2 pypdf==4.3.1 pyproj==3.6.1 python-dateutil==2.9.0.post0 python-dotenv==1.0.0 python-http-client==3.3.7 python-multipart==0.0.9 pytz==2023.3 pyyaml==6.0.2 referencing==0.35.1 reportlab==4.2.2 requests==2.32.3 requests-oauthlib==2.0.0 retrying==1.3.4 rich==13.7.1 rpds-py==0.20.0 rsa==4.9 scipy==1.14.0 sendgrid==6.11.0 sentry-sdk==2.10.0 shapely==2.0.5 shellingham==1.5.4 sib-api-v3-sdk==7.6.0 simplejson==3.19.2 six==1.16.0 smmap==5.0.1 sniffio==1.3.1 starkbank-ecdsa==2.2.0 starlette==0.37.2 streamlit==1.37.1 streamlit-autorefresh==1.0.1 streamlit-javascript==0.1.5 tenacity==8.5.0 texttable==1.7.0 toml==0.10.2 toolz==0.12.1 tornado==6.4.1 typer==0.12.3 typing-extensions==4.12.2 tzdata==2024.1 unidecode==1.3.8 uritemplate==4.1.1 urllib3==2.2.2 uvicorn==0.30.5 uvloop==0.19.0 watchdog==4.0.1 watchfiles==0.23.0 websockets==12.0 werkzeug==3.0.3 wrapt==1.16.0 xmltodict==0.13.0 yarl==1.9.4 zipp==3.19.2 ```

How can we reproduce your problem?

I'm running within Docker, datadog-init being pulled from datadog/serverless-init:1:

/datadog-init /dd_tracer/python/bin/ddtrace-run my-python-app

Within the codebase, I have added as first import:

import ddtrace.auto

as I'm connecting to the database I do:

import pymongo
from ddtrace import Pin, patch

db_client = pymongo.MongoClient(
    connection_settings.DB_URL,
    tlsAllowInvalidCertificates=True,
    tz_aware=tz_aware,
    **kwargs,
)
Pin.override(db_client, service="main-mongo")

What is the result that you get?

an image is worth 1000 words:

What is the result that you expected?

I'm expecting to get at least details of the mongo query :

what command was it? (insert, find, update…)
what is the query that's being sent?
what are the values of the query?

N.B.: I also opened a ticket on the support's zendesk

emmettbutler commented 3 weeks ago

Thank you for the report, @guyzmo. From my read of the code, it looks like the behavior you're looking for is the intended behavior, so this could be a bug in the library. We'll look into it.

cc @mabdinur

guyzmo commented 3 weeks ago

Thank you @emmettbutler 🙏

if there's anything I can do to help/test I'm all yours! Also, I'm available on the DD public slack as well, so don't hesitate to @ me over there.

mabdinur commented 2 weeks ago

Hi @guyzmo,

Thanks for the detailed report! ddtrace traces pymongo by replacing the following components with ddtrace-aware implementations: 1) pymongo.server.Server.get_socket method 2) replacing pymongo.pool.SocketInfo.validate_session method 3) pymongo.MongoClient class

Patching for these objects must be applied before they are imported. From the snippet you shared it seems like MongoClient is imported before the pymongo integration is enabled via import ddtrace.auto or ddtrace.patch_all().

Can you add the following code snippet to check the type of pymongo clients used in your application: from ddtrace.contrib.pymongo.client import TracedMongoClient; assert isinstance(mongo_client, TracedMongoClient), f"MongoClient is not a Traced Mongo Client, it has the type {mongo_client.__class__}". This will allow us to confirm whether or not the ddtrace patching was applied to the problematic clients. If ddtrace patching is applied and you're still not receiving spans we can look into your sampling configurations. Can you open a support ticket [here],(https://help.datadoghq.com/hc/en-us/requests/new) this will allow us to collect information about this case.

guyzmo commented 2 weeks ago

Throughout the whole codebase the first import is import ddtrace.auto. Isn't that supposed to be doing patch(pymongo=True)? (I've added it manually just in doubt, and because the doc is unclear on what's the best way to do that, I'm also running it with ddtrace-run and datadog-init).

Otherwise, we're using motor which is itself implementing pymongo.

I tried your snippet, and I'm not finding a direct link between the motor client and the mongodb client. I supposed I could try ASyncIOMotorClient.delegate (which is an instance of __delegate_class__ that's straight from pymongo.mongo_client.MongoClient, but no luck.

it looks like pymongo's client is used here:

AgnosticClient
implemented here: AsyncIOMotorClient

Looking at the code, AgnosticClient is wrapping the same interface as pymongo and is delegating all methods to pymongo itself.

But sadly, it looks like the pymongo import within agnosticclient is not being patched ☹

I just pushed a patch where I'll monkey patch motor to replace __delegate_class__ = pymongo.mongo_client.MongoClient with __delegate_class__ = ddtrace.contrib.pymongo.client.TracedMongoClient.

This does work to get mongo_client.delegate instance of TracedMongoClient.

Who knows that might work 🤞 I'll check tomorrow to see if it did work ☺

guyzmo commented 2 weeks ago

That strategy did work!

At least partially!

For the statement part I'm getting {...
I have no information on the parameters to the mongo query
I'm getting a bunch of pymongo.get_socket (which gives no real actionable details, besides maybe the delta of time between the time the socket is opened and when the DB is ready to do stuff).

DataDog / dd-trace-py