From 5b125b196a967b9e6021c8ff304a36994863a4e3 Mon Sep 17 00:00:00 2001 From: Owais Lone Date: Fri, 4 Jun 2021 22:19:07 +0530 Subject: [PATCH 1/3] Fix auto-instrumentation dependency conflict detection (#530) --- CHANGELOG.md | 4 +++ .../instrumentation/dependencies.py | 32 +++++++++++++++---- .../tests/test_dependencies.py | 27 ++++++++++++++-- 3 files changed, 54 insertions(+), 9 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 272482b72c..66d75fa655 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased](https://github.com/open-telemetry/opentelemetry-python/compare/v1.3.0-0.22b0...HEAD) +- `opentelemetry-instrumentation` Fixed cases where trying to use an instrumentation package without the + target library was crashing auto instrumentation agent. + ([#530](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/530)) + ## [0.22b0](https://github.com/open-telemetry/opentelemetry-python/releases/tag/v1.3.0-0.22b0) - 2021-06-01 ### Changed diff --git a/opentelemetry-instrumentation/src/opentelemetry/instrumentation/dependencies.py b/opentelemetry-instrumentation/src/opentelemetry/instrumentation/dependencies.py index 69cf6b3354..0cec55769c 100644 --- a/opentelemetry-instrumentation/src/opentelemetry/instrumentation/dependencies.py +++ b/opentelemetry-instrumentation/src/opentelemetry/instrumentation/dependencies.py @@ -1,12 +1,16 @@ +from logging import getLogger from typing import Collection, Optional from pkg_resources import ( Distribution, DistributionNotFound, + RequirementParseError, VersionConflict, get_distribution, ) +logger = getLogger(__file__) + class DependencyConflict: required: str = None @@ -25,12 +29,19 @@ def __str__(self): def get_dist_dependency_conflicts( dist: Distribution, ) -> Optional[DependencyConflict]: - deps = [ - dep - for dep in dist.requires(("instruments",)) - if dep not in dist.requires() - ] - return get_dependency_conflicts(deps) + main_deps = dist.requires() + instrumentation_deps = [] + for dep in dist.requires(("instruments",)): + if dep not in main_deps: + # we set marker to none so string representation of the dependency looks like + # requests ~= 1.0 + # instead of + # requests ~= 1.0; extra = "instruments" + # which does not work with `get_distribution()` + dep.marker = None + instrumentation_deps.append(str(dep)) + + return get_dependency_conflicts(instrumentation_deps) def get_dependency_conflicts( @@ -38,9 +49,16 @@ def get_dependency_conflicts( ) -> Optional[DependencyConflict]: for dep in deps: try: - get_distribution(str(dep)) + get_distribution(dep) except VersionConflict as exc: return DependencyConflict(dep, exc.dist) except DistributionNotFound: return DependencyConflict(dep) + except RequirementParseError as exc: + logger.warning( + 'error parsing dependency, reporting as a conflict: "%s" - %s', + dep, + exc, + ) + return DependencyConflict(dep) return None diff --git a/opentelemetry-instrumentation/tests/test_dependencies.py b/opentelemetry-instrumentation/tests/test_dependencies.py index 778781ee44..8b2f2e9b39 100644 --- a/opentelemetry-instrumentation/tests/test_dependencies.py +++ b/opentelemetry-instrumentation/tests/test_dependencies.py @@ -14,11 +14,13 @@ # pylint: disable=protected-access +import pkg_resources import pytest from opentelemetry.instrumentation.dependencies import ( DependencyConflict, get_dependency_conflicts, + get_dist_dependency_conflicts, ) from opentelemetry.test.test_base import TestBase @@ -37,7 +39,6 @@ def test_get_dependency_conflicts_not_installed(self): conflict = get_dependency_conflicts(["this-package-does-not-exist"]) self.assertTrue(conflict is not None) self.assertTrue(isinstance(conflict, DependencyConflict)) - print(conflict) self.assertEqual( str(conflict), 'DependencyConflict: requested: "this-package-does-not-exist" but found: "None"', @@ -47,10 +48,32 @@ def test_get_dependency_conflicts_mismatched_version(self): conflict = get_dependency_conflicts(["pytest == 5000"]) self.assertTrue(conflict is not None) self.assertTrue(isinstance(conflict, DependencyConflict)) - print(conflict) self.assertEqual( str(conflict), 'DependencyConflict: requested: "pytest == 5000" but found: "pytest {0}"'.format( pytest.__version__ ), ) + + def test_get_dist_dependency_conflicts(self): + def mock_requires(extras=()): + if "instruments" in extras: + return [ + pkg_resources.Requirement( + 'test-pkg ~= 1.0; extra == "instruments"' + ) + ] + return [] + + dist = pkg_resources.Distribution( + project_name="test-instrumentation", version="1.0" + ) + dist.requires = mock_requires + + conflict = get_dist_dependency_conflicts(dist) + self.assertTrue(conflict is not None) + self.assertTrue(isinstance(conflict, DependencyConflict)) + self.assertEqual( + str(conflict), + 'DependencyConflict: requested: "test-pkg~=1.0" but found: "None"', + ) From fe4e2d44c56cb8ca67b7374bac331873f712cb03 Mon Sep 17 00:00:00 2001 From: Peter Bwire Date: Mon, 7 Jun 2021 18:43:08 +0300 Subject: [PATCH 2/3] Reorder on_finish call order to correctly instrument all tornado work done during a request (#499) Co-authored-by: alrex --- CHANGELOG.md | 2 + .../instrumentation/tornado/__init__.py | 3 +- .../tests/test_instrumentation.py | 48 +++++++++++++++++++ .../tests/tornado_test_app.py | 12 +++++ 4 files changed, 64 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 66d75fa655..761845128a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased](https://github.com/open-telemetry/opentelemetry-python/compare/v1.3.0-0.22b0...HEAD) +- `opentelemetry-instrumentation-tornado` properly instrument work done in tornado on_finish method. + ([#499](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/499)) - `opentelemetry-instrumentation` Fixed cases where trying to use an instrumentation package without the target library was crashing auto instrumentation agent. ([#530](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/530)) diff --git a/instrumentation/opentelemetry-instrumentation-tornado/src/opentelemetry/instrumentation/tornado/__init__.py b/instrumentation/opentelemetry-instrumentation-tornado/src/opentelemetry/instrumentation/tornado/__init__.py index db37f81794..aed62eb7df 100644 --- a/instrumentation/opentelemetry-instrumentation-tornado/src/opentelemetry/instrumentation/tornado/__init__.py +++ b/instrumentation/opentelemetry-instrumentation-tornado/src/opentelemetry/instrumentation/tornado/__init__.py @@ -213,8 +213,9 @@ def _prepare(tracer, request_hook, func, handler, args, kwargs): def _on_finish(tracer, func, handler, args, kwargs): + response = func(*args, **kwargs) _finish_span(tracer, handler) - return func(*args, **kwargs) + return response def _log_exception(tracer, func, handler, args, kwargs): diff --git a/instrumentation/opentelemetry-instrumentation-tornado/tests/test_instrumentation.py b/instrumentation/opentelemetry-instrumentation-tornado/tests/test_instrumentation.py index 605dde2abc..58c0127647 100644 --- a/instrumentation/opentelemetry-instrumentation-tornado/tests/test_instrumentation.py +++ b/instrumentation/opentelemetry-instrumentation-tornado/tests/test_instrumentation.py @@ -347,6 +347,54 @@ def test_dynamic_handler(self): }, ) + def test_handler_on_finish(self): + + response = self.fetch("/on_finish") + self.assertEqual(response.code, 200) + + spans = self.sorted_spans(self.memory_exporter.get_finished_spans()) + self.assertEqual(len(spans), 3) + auditor, server, client = spans + + self.assertEqual(server.name, "FinishedHandler.get") + self.assertTrue(server.parent.is_remote) + self.assertNotEqual(server.parent, client.context) + self.assertEqual(server.parent.span_id, client.context.span_id) + self.assertEqual(server.context.trace_id, client.context.trace_id) + self.assertEqual(server.kind, SpanKind.SERVER) + self.assert_span_has_attributes( + server, + { + SpanAttributes.HTTP_METHOD: "GET", + SpanAttributes.HTTP_SCHEME: "http", + SpanAttributes.HTTP_HOST: "127.0.0.1:" + + str(self.get_http_port()), + SpanAttributes.HTTP_TARGET: "/on_finish", + SpanAttributes.NET_PEER_IP: "127.0.0.1", + SpanAttributes.HTTP_STATUS_CODE: 200, + }, + ) + + self.assertEqual(client.name, "GET") + self.assertFalse(client.context.is_remote) + self.assertIsNone(client.parent) + self.assertEqual(client.kind, SpanKind.CLIENT) + self.assert_span_has_attributes( + client, + { + SpanAttributes.HTTP_URL: self.get_url("/on_finish"), + SpanAttributes.HTTP_METHOD: "GET", + SpanAttributes.HTTP_STATUS_CODE: 200, + }, + ) + + self.assertEqual(auditor.name, "audit_task") + self.assertFalse(auditor.context.is_remote) + self.assertEqual(auditor.parent.span_id, server.context.span_id) + self.assertEqual(auditor.context.trace_id, client.context.trace_id) + + self.assertEqual(auditor.kind, SpanKind.INTERNAL) + def test_exclude_lists(self): def test_excluded(path): self.fetch(path) diff --git a/instrumentation/opentelemetry-instrumentation-tornado/tests/tornado_test_app.py b/instrumentation/opentelemetry-instrumentation-tornado/tests/tornado_test_app.py index 307dc60b76..c92acc8275 100644 --- a/instrumentation/opentelemetry-instrumentation-tornado/tests/tornado_test_app.py +++ b/instrumentation/opentelemetry-instrumentation-tornado/tests/tornado_test_app.py @@ -1,4 +1,5 @@ # pylint: disable=W0223,R0201 +import time import tornado.web from tornado import gen @@ -79,6 +80,16 @@ def get(self): self.set_status(202) +class FinishedHandler(tornado.web.RequestHandler): + def on_finish(self): + with self.application.tracer.start_as_current_span("audit_task"): + time.sleep(0.05) + + def get(self): + self.write("Test can finish") + self.set_status(200) + + class HealthCheckHandler(tornado.web.RequestHandler): def get(self): self.set_status(200) @@ -91,6 +102,7 @@ def make_app(tracer): (r"/error", BadHandler), (r"/cor", CoroutineHandler), (r"/async", AsyncHandler), + (r"/on_finish", FinishedHandler), (r"/healthz", HealthCheckHandler), (r"/ping", HealthCheckHandler), ] From b2dd4b8205deb09ea2d0608dad37cff8ce211495 Mon Sep 17 00:00:00 2001 From: Joshua Date: Mon, 7 Jun 2021 09:11:37 -0700 Subject: [PATCH 3/3] Fix pyodbc cursor error in SQLA instrumentation (#469) --- CHANGELOG.md | 3 + .../instrumentation/sqlalchemy/engine.py | 11 +- .../tests/check_availability.py | 17 +++ .../tests/docker-compose.yml | 8 ++ .../tests/sqlalchemy_tests/test_mssql.py | 107 ++++++++++++++++++ tox.ini | 1 + 6 files changed, 145 insertions(+), 2 deletions(-) create mode 100644 tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 761845128a..feb865a13c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,11 +6,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased](https://github.com/open-telemetry/opentelemetry-python/compare/v1.3.0-0.22b0...HEAD) +### Changed - `opentelemetry-instrumentation-tornado` properly instrument work done in tornado on_finish method. ([#499](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/499)) - `opentelemetry-instrumentation` Fixed cases where trying to use an instrumentation package without the target library was crashing auto instrumentation agent. ([#530](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/530)) +- Fix weak reference error for pyodbc cursor in SQLAlchemy instrumentation. + ([#469](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/469)) ## [0.22b0](https://github.com/open-telemetry/opentelemetry-python/releases/tag/v1.3.0-0.22b0) - 2021-06-01 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 018bb8ef78..e69c6dbcb4 100644 --- a/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/engine.py +++ b/instrumentation/opentelemetry-instrumentation-sqlalchemy/src/opentelemetry/instrumentation/sqlalchemy/engine.py @@ -13,7 +13,6 @@ # limitations under the License. from threading import local -from weakref import WeakKeyDictionary from sqlalchemy.event import listen # pylint: disable=no-name-in-module @@ -60,7 +59,7 @@ def __init__(self, tracer, engine): self.tracer = tracer self.engine = engine self.vendor = _normalize_vendor(engine.name) - self.cursor_mapping = WeakKeyDictionary() + self.cursor_mapping = {} self.local = local() listen(engine, "before_cursor_execute", self._before_cur_exec) @@ -116,6 +115,7 @@ def _after_cur_exec(self, conn, cursor, statement, *args): return span.end() + self._cleanup(cursor) def _handle_error(self, context): span = self.current_thread_span @@ -129,6 +129,13 @@ def _handle_error(self, context): ) finally: span.end() + self._cleanup(context.cursor) + + def _cleanup(self, cursor): + try: + del self.cursor_mapping[cursor] + except KeyError: + pass def _get_attributes_from_url(url): diff --git a/tests/opentelemetry-docker-tests/tests/check_availability.py b/tests/opentelemetry-docker-tests/tests/check_availability.py index 0e066610c9..28cd47ab79 100644 --- a/tests/opentelemetry-docker-tests/tests/check_availability.py +++ b/tests/opentelemetry-docker-tests/tests/check_availability.py @@ -18,6 +18,7 @@ import mysql.connector import psycopg2 import pymongo +import pyodbc import redis MONGODB_COLLECTION_NAME = "test" @@ -36,6 +37,11 @@ POSTGRES_USER = os.getenv("POSTGRESQL_USER", "testuser") REDIS_HOST = os.getenv("REDIS_HOST", "localhost") REDIS_PORT = int(os.getenv("REDIS_PORT ", "6379")) +MSSQL_DB_NAME = os.getenv("MSSQL_DB_NAME", "opentelemetry-tests") +MSSQL_HOST = os.getenv("MSSQL_HOST", "localhost") +MSSQL_PORT = int(os.getenv("MSSQL_PORT", "1433")) +MSSQL_USER = os.getenv("MSSQL_USER", "sa") +MSSQL_PASSWORD = os.getenv("MSSQL_PASSWORD", "yourStrong(!)Password") RETRY_COUNT = 8 RETRY_INTERVAL = 5 # Seconds @@ -104,12 +110,23 @@ def check_redis_connection(): connection.hgetall("*") +@retryable +def check_mssql_connection(): + connection = pyodbc.connect( + f"DRIVER={{ODBC Driver 17 for SQL Server}};SERVER={MSSQL_HOST}," + f"{MSSQL_PORT};DATABASE={MSSQL_DB_NAME};UID={MSSQL_USER};" + f"PWD={MSSQL_PASSWORD}" + ) + connection.close() + + def check_docker_services_availability(): # Check if Docker services accept connections check_pymongo_connection() check_mysql_connection() check_postgres_connection() check_redis_connection() + check_mssql_connection() check_docker_services_availability() diff --git a/tests/opentelemetry-docker-tests/tests/docker-compose.yml b/tests/opentelemetry-docker-tests/tests/docker-compose.yml index 7262bcc9cf..97d62522c8 100644 --- a/tests/opentelemetry-docker-tests/tests/docker-compose.yml +++ b/tests/opentelemetry-docker-tests/tests/docker-compose.yml @@ -39,3 +39,11 @@ services: - "16686:16686" - "14268:14268" - "9411:9411" + otmssql: + image: mcr.microsoft.com/mssql/server:2017-latest + ports: + - "1433:1433" + environment: + ACCEPT_EULA: "Y" + SA_PASSWORD: "yourStrong(!)Password" + command: /bin/sh -c "sleep 10s && /opt/mssql-tools/bin/sqlcmd -S localhost -U sa -P yourStrong\(!\)Password -d master -Q 'CREATE DATABASE [opentelemetry-tests]' & /opt/mssql/bin/sqlservr" \ No newline at end of file diff --git a/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py new file mode 100644 index 0000000000..ef9cac051a --- /dev/null +++ b/tests/opentelemetry-docker-tests/tests/sqlalchemy_tests/test_mssql.py @@ -0,0 +1,107 @@ +# Copyright The OpenTelemetry Authors +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import os +import unittest + +import pytest +from sqlalchemy.exc import ProgrammingError + +from opentelemetry import trace +from opentelemetry.semconv.trace import SpanAttributes + +from .mixins import Player, SQLAlchemyTestMixin + +MSSQL_CONFIG = { + "host": "127.0.0.1", + "port": int(os.getenv("TEST_MSSQL_PORT", "1433")), + "user": os.getenv("TEST_MSSQL_USER", "sa"), + "password": os.getenv("TEST_MSSQL_PASSWORD", "yourStrong(!)Password"), + "database": os.getenv("TEST_MSSQL_DATABASE", "opentelemetry-tests"), + "driver": os.getenv("TEST_MSSQL_DRIVER", "ODBC+Driver+17+for+SQL+Server"), +} + + +class MssqlConnectorTestCase(SQLAlchemyTestMixin): + """TestCase for pyodbc engine""" + + __test__ = True + + VENDOR = "mssql" + SQL_DB = "opentelemetry-tests" + ENGINE_ARGS = { + "url": "mssql+pyodbc://%(user)s:%(password)s@%(host)s:%(port)s/%(database)s?driver=%(driver)s" + % MSSQL_CONFIG + } + + def check_meta(self, span): + # check database connection tags + self.assertEqual( + span.attributes.get(SpanAttributes.NET_PEER_NAME), + MSSQL_CONFIG["host"], + ) + self.assertEqual( + span.attributes.get(SpanAttributes.NET_PEER_PORT), + MSSQL_CONFIG["port"], + ) + self.assertEqual( + span.attributes.get(SpanAttributes.DB_NAME), + MSSQL_CONFIG["database"], + ) + self.assertEqual( + span.attributes.get(SpanAttributes.DB_USER), MSSQL_CONFIG["user"] + ) + + def test_engine_execute_errors(self): + # ensures that SQL errors are reported + with pytest.raises(ProgrammingError): + with self.connection() as conn: + conn.execute("SELECT * FROM a_wrong_table").fetchall() + + spans = self.memory_exporter.get_finished_spans() + self.assertEqual(len(spans), 1) + span = spans[0] + # span fields + self.assertEqual(span.name, "SELECT opentelemetry-tests") + self.assertEqual( + span.attributes.get(SpanAttributes.DB_STATEMENT), + "SELECT * FROM a_wrong_table", + ) + self.assertEqual( + span.attributes.get(SpanAttributes.DB_NAME), self.SQL_DB + ) + self.check_meta(span) + self.assertTrue(span.end_time - span.start_time > 0) + # check the error + self.assertIs( + span.status.status_code, trace.StatusCode.ERROR, + ) + self.assertIn("a_wrong_table", span.status.description) + + def test_orm_insert(self): + # ensures that the ORM session is traced + wayne = Player(id=1, name="wayne") + self.session.add(wayne) + 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] + self._check_span(span, "INSERT") + self.assertIn( + "INSERT INTO players", + span.attributes.get(SpanAttributes.DB_STATEMENT), + ) + self.check_meta(span) diff --git a/tox.ini b/tox.ini index 14f0c656cb..bf3f289f91 100644 --- a/tox.ini +++ b/tox.ini @@ -404,6 +404,7 @@ deps = celery[pytest] >= 4.0, < 6.0 protobuf>=3.13.0 requests==2.25.0 + pyodbc~=4.0.30 changedir = tests/opentelemetry-docker-tests/tests