diff --git a/CHANGELOG.md b/CHANGELOG.md index 545183b786..20cdb6cb5f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added - `opentelemetry-instrumentation-redis` add support to instrument RedisCluster clients ([#1177](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/1177)) +- `opentelemetry-instrumentation-sqlalchemy` Added span for the connection phase ([#1133](https://github.com/open-telemetry/opentelemetry-python-contrib/issues/1133)) ## [1.12.0rc2-0.32b0](https://github.com/open-telemetry/opentelemetry-python/releases/tag/v1.12.0rc2-0.32b0) - 2022-07-01 diff --git a/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/__init__.py b/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/__init__.py index 0e1d7b266a..bc438c609a 100644 --- a/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/__init__.py +++ b/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/__init__.py @@ -56,12 +56,14 @@ import sqlalchemy from packaging.version import parse as parse_version +from sqlalchemy.engine.base import Engine from wrapt import wrap_function_wrapper as _w from opentelemetry.instrumentation.instrumentor import BaseInstrumentor from opentelemetry.instrumentation.sqlalchemy.engine import ( EngineTracer, _get_tracer, + _wrap_connect, _wrap_create_async_engine, _wrap_create_engine, ) @@ -97,13 +99,17 @@ def _instrument(self, **kwargs): "create_engine", _wrap_create_engine(tracer_provider), ) + _w( + "sqlalchemy.engine.base", + "Engine.connect", + _wrap_connect(tracer_provider), + ) if parse_version(sqlalchemy.__version__).release >= (1, 4): _w( "sqlalchemy.ext.asyncio", "create_async_engine", _wrap_create_async_engine(tracer_provider), ) - if kwargs.get("engine") is not None: return EngineTracer( _get_tracer(tracer_provider), @@ -127,5 +133,6 @@ def _instrument(self, **kwargs): def _uninstrument(self, **kwargs): unwrap(sqlalchemy, "create_engine") unwrap(sqlalchemy.engine, "create_engine") + unwrap(Engine, "connect") if parse_version(sqlalchemy.__version__).release >= (1, 4): unwrap(sqlalchemy.ext.asyncio, "create_async_engine") diff --git a/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/engine.py b/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/engine.py index 910ff7c4f6..8121c99d13 100644 --- a/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/engine.py +++ b/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/engine.py @@ -77,6 +77,23 @@ def _wrap_create_engine_internal(func, module, args, kwargs): return _wrap_create_engine_internal +def _wrap_connect(tracer_provider=None): + tracer = trace.get_tracer( + _instrumenting_module_name, + __version__, + tracer_provider=tracer_provider, + ) + + # pylint: disable=unused-argument + def _wrap_connect_internal(func, module, args, kwargs): + with tracer.start_as_current_span( + "connect", kind=trace.SpanKind.CLIENT + ): + return func(*args, **kwargs) + + return _wrap_connect_internal + + class EngineTracer: def __init__(self, tracer, engine, enable_commenter=False): self.tracer = tracer diff --git a/instrumentation/opentelemetry-instrumentation-sqlalchemy/tests/test_sqlalchemy.py b/instrumentation/opentelemetry-instrumentation-sqlalchemy/tests/test_sqlalchemy.py index 3b3c6d735b..0f45fa77eb 100644 --- a/instrumentation/opentelemetry-instrumentation-sqlalchemy/tests/test_sqlalchemy.py +++ b/instrumentation/opentelemetry-instrumentation-sqlalchemy/tests/test_sqlalchemy.py @@ -46,9 +46,13 @@ def test_trace_integration(self): cnx.execute("SELECT 1 + 1;").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - self.assertEqual(spans[0].name, "SELECT :memory:") + self.assertEqual(len(spans), 2) + # first span - the connection to the db + self.assertEqual(spans[0].name, "connect") self.assertEqual(spans[0].kind, trace.SpanKind.CLIENT) + # second span - the query itself + self.assertEqual(spans[1].name, "SELECT :memory:") + self.assertEqual(spans[1].kind, trace.SpanKind.CLIENT) def test_instrument_two_engines(self): engine_1 = create_engine("sqlite:///:memory:") @@ -65,8 +69,20 @@ def test_instrument_two_engines(self): cnx_2.execute("SELECT 1 + 1;").fetchall() spans = self.memory_exporter.get_finished_spans() + # 2 queries + 2 engine connect + self.assertEqual(len(spans), 4) - self.assertEqual(len(spans), 2) + def test_instrument_engine_connect(self): + engine = create_engine("sqlite:///:memory:") + + SQLAlchemyInstrumentor().instrument( + engine=engine, + tracer_provider=self.tracer_provider, + ) + + engine.connect() + spans = self.memory_exporter.get_finished_spans() + self.assertEqual(len(spans), 1) @pytest.mark.skipif( not sqlalchemy.__version__.startswith("1.4"), @@ -85,11 +101,15 @@ async def run(): async with engine.connect() as cnx: await cnx.execute(sqlalchemy.text("SELECT 1 + 1;")) spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - self.assertEqual(spans[0].name, "SELECT :memory:") + self.assertEqual(len(spans), 2) + # first span - the connection to the db + self.assertEqual(spans[0].name, "connect") self.assertEqual(spans[0].kind, trace.SpanKind.CLIENT) + # second span - the query + self.assertEqual(spans[1].name, "SELECT :memory:") + self.assertEqual(spans[1].kind, trace.SpanKind.CLIENT) self.assertEqual( - spans[0].instrumentation_scope.name, + spans[1].instrumentation_scope.name, "opentelemetry.instrumentation.sqlalchemy", ) @@ -99,7 +119,10 @@ def test_not_recording(self): mock_tracer = mock.Mock() mock_span = mock.Mock() mock_span.is_recording.return_value = False + mock_span.__enter__ = mock.Mock(return_value=(mock.Mock(), None)) + mock_span.__exit__ = mock.Mock(return_value=None) mock_tracer.start_span.return_value = mock_span + mock_tracer.start_as_current_span.return_value = mock_span with mock.patch("opentelemetry.trace.get_tracer") as tracer: tracer.return_value = mock_tracer engine = create_engine("sqlite:///:memory:") @@ -123,11 +146,15 @@ def test_create_engine_wrapper(self): cnx.execute("SELECT 1 + 1;").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - self.assertEqual(spans[0].name, "SELECT :memory:") + self.assertEqual(len(spans), 2) + # first span - the connection to the db + self.assertEqual(spans[0].name, "connect") self.assertEqual(spans[0].kind, trace.SpanKind.CLIENT) + # second span - the query + self.assertEqual(spans[1].name, "SELECT :memory:") + self.assertEqual(spans[1].kind, trace.SpanKind.CLIENT) self.assertEqual( - spans[0].instrumentation_scope.name, + spans[1].instrumentation_scope.name, "opentelemetry.instrumentation.sqlalchemy", ) @@ -153,7 +180,7 @@ def test_custom_tracer_provider(self): cnx.execute("SELECT 1 + 1;").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) + self.assertEqual(len(spans), 2) self.assertEqual(spans[0].resource.attributes["service.name"], "test") self.assertEqual( spans[0].resource.attributes["deployment.environment"], "env" @@ -177,11 +204,15 @@ async def run(): async with engine.connect() as cnx: await cnx.execute(sqlalchemy.text("SELECT 1 + 1;")) spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - self.assertEqual(spans[0].name, "SELECT :memory:") + self.assertEqual(len(spans), 2) + # first span - the connection to the db + self.assertEqual(spans[0].name, "connect") self.assertEqual(spans[0].kind, trace.SpanKind.CLIENT) + # second span - the query + self.assertEqual(spans[1].name, "SELECT :memory:") + self.assertEqual(spans[1].kind, trace.SpanKind.CLIENT) self.assertEqual( - spans[0].instrumentation_scope.name, + spans[1].instrumentation_scope.name, "opentelemetry.instrumentation.sqlalchemy", ) @@ -199,8 +230,8 @@ def test_generate_commenter(self): cnx = engine.connect() cnx.execute("SELECT 1 + 1;").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + self.assertEqual(len(spans), 2) + span = spans[1] self.assertIn( EngineTracer._generate_comment(span), self.caplog.records[-2].getMessage(), diff --git a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/mixins.py b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/mixins.py index 084b8114a1..57317b76c6 100644 --- a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/mixins.py +++ b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/mixins.py @@ -128,8 +128,9 @@ def test_orm_insert(self): self.session.commit() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one for the query + self.assertEqual(len(spans), 2) + span = spans[1] stmt = "INSERT INTO players (id, name) VALUES " if span.attributes.get(SpanAttributes.DB_SYSTEM) == "sqlite": stmt += "(?, ?)" @@ -148,8 +149,9 @@ def test_session_query(self): self.assertEqual(len(out), 0) spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one for the query + self.assertEqual(len(spans), 2) + span = spans[1] stmt = "SELECT players.id AS players_id, players.name AS players_name \nFROM players \nWHERE players.name = " if span.attributes.get(SpanAttributes.DB_SYSTEM) == "sqlite": stmt += "?" @@ -170,8 +172,9 @@ def test_engine_connect_execute(self): self.assertEqual(len(rows), 0) spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one for the query + self.assertEqual(len(spans), 2) + span = spans[1] self._check_span(span, "SELECT") self.assertEqual( span.attributes.get(SpanAttributes.DB_STATEMENT), @@ -190,8 +193,9 @@ def test_parent(self): self.assertEqual(len(rows), 0) spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 2) - child_span, parent_span = spans + # one span for the connection and two for the queries + self.assertEqual(len(spans), 3) + _, child_span, parent_span = spans # confirm the parenting self.assertIsNone(parent_span.parent) @@ -247,5 +251,5 @@ def insert_players(session): # batch inserts together which means `insert_players` only generates one span. # See https://docs.sqlalchemy.org/en/14/changelog/migration_14.html#orm-batch-inserts-with-psycopg2-now-batch-statements-with-returning-in-most-cases self.assertEqual( - len(spans), 5 if self.VENDOR not in ["postgresql"] else 3 + len(spans), 8 if self.VENDOR not in ["postgresql"] else 6 ) diff --git a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py index e3a1aae2ef..fef1bf7b7b 100644 --- a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py +++ b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py @@ -69,8 +69,9 @@ def test_engine_execute_errors(self): conn.execute("SELECT * FROM a_wrong_table").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one for the query + self.assertEqual(len(spans), 2) + span = spans[1] # span fields self.assertEqual(span.name, "SELECT opentelemetry-tests") self.assertEqual( @@ -96,9 +97,9 @@ def test_orm_insert(self): self.session.commit() spans = self.memory_exporter.get_finished_spans() - # identity insert on before the insert, insert, and identity insert off after the insert - self.assertEqual(len(spans), 3) - span = spans[1] + # connect, identity insert on before the insert, insert, and identity insert off after the insert + self.assertEqual(len(spans), 4) + span = spans[2] self._check_span(span, "INSERT") self.assertIn( "INSERT INTO players", diff --git a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mysql.py b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mysql.py index 69b3c26286..ceebe78ef5 100644 --- a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mysql.py +++ b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mysql.py @@ -68,8 +68,9 @@ def test_engine_execute_errors(self): conn.execute("SELECT * FROM a_wrong_table").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one for the query + self.assertEqual(len(spans), 2) + span = spans[1] # span fields self.assertEqual(span.name, "SELECT opentelemetry-tests") self.assertEqual( diff --git a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_postgres.py b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_postgres.py index 2893a5fd19..bbc62bfbbf 100644 --- a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_postgres.py +++ b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_postgres.py @@ -62,8 +62,9 @@ def test_engine_execute_errors(self): conn.execute("SELECT * FROM a_wrong_table").fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one for the query + self.assertEqual(len(spans), 2) + span = spans[1] # span fields self.assertEqual(span.name, "SELECT opentelemetry-tests") self.assertEqual( diff --git a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_sqlite.py b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_sqlite.py index 2197028266..884e3a37c2 100644 --- a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_sqlite.py +++ b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_sqlite.py @@ -38,8 +38,9 @@ def test_engine_execute_errors(self): conn.execute(stmt).fetchall() spans = self.memory_exporter.get_finished_spans() - self.assertEqual(len(spans), 1) - span = spans[0] + # one span for the connection and one span for the query + self.assertEqual(len(spans), 2) + span = spans[1] # span fields self.assertEqual(span.name, "SELECT :memory:") self.assertEqual(