open-telemetry / open-telemetry/opentelemetry-python-contrib

Unclosed Spans and Memory Leak in SQLAlchemy Instrumentation

Open
#2,149 0 comments 4 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug
Dominant language
Python
Stars
1.1k
Forks
1.1k
Avg merge
4d 15h
Merged PRs (30d)
16

Description

The SQLAlchemy instrumentation module is currently wrapping both create_engine and create_async_engine functions. The issue arises when create_async_engine is utilized, as it internally utilizes create_engine. This results in the attachment of two instances of EngineTracer to a single engine.

Within each EngineTracer instance, two listeners are added - self._before_cur_exec and _after_cur_exec. The self._before_cur_exec is a method unique to each EngineTracer instance, called after the before_cursor_execute event. On the other hand, _after_cur_exec is a function common to both tracers, called after the after_cursor_execute event.

The expected behavior is that a span is opened in self._before_cur_exec and closed in _after_cur_exec. However, since self._before_cur_exec is a method (unique to each tracer), it is called twice. In contrast, _after_cur_exec is a function (shared between tracers), so it is only called once. This discrepancy leads to unclosed spans, causing a memory leak, especially when using a span processor like Sentry that stores all open spans.

Possible fixes are:

  • Remove wrapping of create_async_engine.
  • Check for context._otel_span inside self._before_cur_exec and don't create a new span if one already exists.

Code to reproduce:


from opentelemetry import trace
from opentelemetry.sdk.trace import SpanProcessor as _SpanProcessor
from sqlalchemy import text
from sqlalchemy.ext.asyncio import create_async_engine


class SpanProcessor(_SpanProcessor):
    def on_start(self, span, parent_context=None) -> None:
        print(f'Span {span.get_span_context().span_id} start')

    def on_end(self, span):
        print(f'Span {span.get_span_context().span_id} end')


provider = trace.get_tracer_provider()
provider.add_span_processor(SpanProcessor())
engine = create_async_engine('sqlite+aiosqlite:///:memory:')


async def main():
    async with engine.connect() as conn:
        await conn.execute(text('SELECT 1;'))


asyncio.run(main())

Output opentelemetry-instrument --traces_exporter none --metrics_exporter none python main.py:

Span 14005223274538647451 start
Span 9536965647113087503 start
Span 9536965647113087503 end
Span 14005223274538647451 end
Span 9078565121525117657 start
Span 14653102227714362230 start
Span 4038731188680273757 start
Span 4038731188680273757 end
Span 14653102227714362230 end

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in the SQLAlchemy instrumentation module by running the provided async SQLite reproduction with the custom SpanProcessor. Trace how create_async_engine and create_engine attach EngineTracer listeners, then verify that each opened span is closed exactly once and the reproduction no longer reports unmatched span starts.

Written by the indexing model from the issue text.

Assessment

Tech stack
python, sqlalchemy
Domain
observability
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.