SQLAlchemy query span is not the parent of mysql-connector query span

[tammy-baylis-swi]

Describe your environment

OS: Ubuntu
Python version: 3.8
Package version: 0.47b0

What happened?

If a database client app uses SQLAlchemy (ORM) and mysql-connector ("mysql")(db driver) to query a MySQL database, and both components are instrumented with opentelemetry-instrumentation-sqlalchemy and opentelemetry-instrumentation-mysql (respectively), the instrumentors produce SELECT spans that are "siblings" instead of parent (sqlalchemy) and child (mysql). I'd expect them to be parent-child because mysql db driver connection is handled by SQLAlchemy under the hood as a layer of abstraction. However, I'm not sure if the current behavior is by design.

Steps to Reproduce

The db client app is Flask app and the MySQL database is a copy of the mysql-world-db. Client-server connection is set up with SQLAlchemy create_engine. I use that engine to manually instrument with the following, and set up batch span export to an Otel Collector instance (not shown):

engine = create_engine("mysql+mysqlconnector://<USER>:<PASSWORD>@mysql-world-db:3306/world")
MySQLInstrumentor().instrument()
SQLAlchemyInstrumentor().instrument(
    enable_commenter=true,
    engine=engine,
)

provider = TracerProvider()
processor = BatchSpanProcessor(
    OTLPSpanExporter(
        endpoint="http://otel-collector:4318/v1/trace"
    )
)
provider.add_span_processor(processor)
trace.set_tracer_provider(provider)
tracer = trace.get_tracer(__name__)

I set up an HTTP route to trigger query by SQLAlchemy engine Connection like this. I don't instrument Flask so I manually create a SERVER span:

@app.route("/conn/city")
def request_city_conn():
    with tracer.start_as_current_span(name="/conn/city", kind=trace.SpanKind.SERVER):
        statement = "SELECT * FROM city WHERE id = :city_id"
        city_id = request.args.get("id")
        rows = []
        with engine.connect() as conn:
            result = conn.execute(text(statement), {"city_id": city_id})
            for row in result:
                rows.append(row)
            conn.commit()
        return str(rows[0])

After HTTP request, check Otel Collector for exported spans.

Expected Result

Both SQLAlchemy and mysql instrumentors generate spans for the SELECT query, where the SQLAlchemy span is the parent of the mysql span. Using log in next section, I would expect span with id a2066974b1c5333a to have parent span id aee8939b137c8e87, not 591c8b24a2c535d5

Actual Result

The SQLAlchemy and mysql spans are siblings, i.e. they have the same parent. Here is an example Otel Collector output where the root span is Server with span ID 591c8b24a2c535d5, and the two SELECT Client spans have the same parent span ID 591c8b24a2c535d5 (see below).

Note: There is another span for Connect Client which I think is correct following #1134

2024-08-26T22:51:42.493Z	info	TracesExporter	{"kind": "exporter", "data_type": "traces", "name": "logging", "resource spans": 1, "spans": 4}
2024-08-26T22:51:42.493Z	info	ResourceSpans #0
Resource SchemaURL: 
Resource attributes:
     -> telemetry.sdk.language: Str(python)
     -> telemetry.sdk.name: Str(opentelemetry)
     -> telemetry.sdk.version: Str(1.26.0)
     -> service.name: Str(flask-mysql-connector-sqlalchemy)
ScopeSpans #0
ScopeSpans SchemaURL: 
InstrumentationScope opentelemetry.instrumentation.sqlalchemy 0.47b0
Span #0
    Trace ID       : c5b884f193b2f93439c54b964137acd2
    Parent ID      : 591c8b24a2c535d5
    ID             : a4a1b5f477bebfef
    Name           : connect
    Kind           : Client
    Start time     : 2024-08-26 22:51:40.335716001 +0000 UTC
    End time       : 2024-08-26 22:51:40.335918793 +0000 UTC
    Status code    : Unset
    Status message : 
Attributes:
     -> net.peer.name: Str(mysql-world-db)
     -> net.peer.port: Int(3306)
     -> db.name: Str(world)
     -> db.user: Str(world)
     -> db.system: Str(mysql)
Span #1
    Trace ID       : c5b884f193b2f93439c54b964137acd2
    Parent ID      : 591c8b24a2c535d5
    ID             : aee8939b137c8e87
    Name           : SELECT world
    Kind           : Client
    Start time     : 2024-08-26 22:51:40.336841084 +0000 UTC
    End time       : 2024-08-26 22:51:40.337601751 +0000 UTC
    Status code    : Unset
    Status message : 
Attributes:
     -> db.statement: Str(SELECT * FROM city WHERE id = %(city_id)s)
     -> db.system: Str(mysql)
     -> net.peer.name: Str(mysql-world-db)
     -> net.peer.port: Int(3306)
     -> db.name: Str(world)
     -> db.user: Str(world)
ScopeSpans #1
ScopeSpans SchemaURL: 
InstrumentationScope opentelemetry.instrumentation.mysql 0.47b0
Span #0
    Trace ID       : c5b884f193b2f93439c54b964137acd2
    Parent ID      : 591c8b24a2c535d5
    ID             : a2066974b1c5333a
    Name           : SELECT
    Kind           : Client
    Start time     : 2024-08-26 22:51:40.337013001 +0000 UTC
    End time       : 2024-08-26 22:51:40.337571334 +0000 UTC
    Status code    : Unset
    Status message : 
Attributes:
     -> db.system: Str(mysql)
     -> db.name: Str(world)
     -> db.statement: Str(SELECT * FROM city WHERE id = %(city_id)s /*db_driver='mysqlconnector',db_framework='sqlalchemy%%3A2.0.32',traceparent='00-c5b884f193b2f93439c54b964137acd2-aee8939b137c8e87-01'*/)
     -> db.user: Str(world)
     -> net.peer.name: Str(mysql-world-db)
     -> net.peer.port: Int(3306)
ScopeSpans #2
ScopeSpans SchemaURL: 
InstrumentationScope app 
Span #0
    Trace ID       : c5b884f193b2f93439c54b964137acd2
    Parent ID      : 
    ID             : 591c8b24a2c535d5
    Name           : /conn/city
    Kind           : Server
    Start time     : 2024-08-26 22:51:40.335614751 +0000 UTC
    End time       : 2024-08-26 22:51:40.338401668 +0000 UTC
    Status code    : Unset
    Status message : 
	{"kind": "exporter", "data_type": "traces", "name": "logging"}

Additional context

No response

Would you like to implement a fix?

None

[tammy-baylis-swi]

We discussed this in today's SIG meeting, so leaving a comment! cc @lzchen @aabmass

Regarding SpanKind of each query span: the semconv and spec 1.11.0 say db client call spans must always be Client.

We have some ideas around the 'duplication' of query spans by ORM and driver instrumentation. It's not necessarily invalid to have both SQLAlchemy and mysql-connector instrumented, which would be the default behavior with auto-instrumentation. However, a double span may not add much additional value. Users currently have the option to only instrument what they need in-code, or set OTEL_PYTHON_DISABLED_INSTRUMENTATIONS with auto-instrumentation. Similar 'duplicates' are not unique to db clients, as we also see this with e.g. urllib3 and requests, or FastAPI with ASGI. The current implementation of SQLAlchemy/other ORM instrumentors could potentially be changed to some sort of "only start span if" logic.

Regarding the ORM and driver spans being siblings vs parent-child: them being parent-child (nested) would better reflect what the instrumented db client app is actually doing. The current implementation could be changed with community discussion and review.

Regarding updating the implementation for both: there are several ways to connect a Python db client to a server that should be considered and tested. db drivers are required; ORMs are optional. Some have instrumentation while others don't. An implementation ideally would not be 100% case-by-case for every permutation so patterns for some generalization would be better.