diff --git a/CHANGELOG.md b/CHANGELOG.md index a364d4d958..8bf7156099 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -61,6 +61,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ([#3936](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/3936)) - `opentelemetry-instrumentation-aiohttp-client`: Update instrumentor to respect suppressing http instrumentation ([#3957](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/3957)) +- `opentelemetry-instrumentation-django`: Fix exemplars generation for http.server.(request.)duration + ([#3945](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/3945)) ## Version 1.38.0/0.59b0 (2025-10-16) diff --git a/instrumentation/opentelemetry-instrumentation-django/src/opentelemetry/instrumentation/django/middleware/otel_middleware.py b/instrumentation/opentelemetry-instrumentation-django/src/opentelemetry/instrumentation/django/middleware/otel_middleware.py index f607046959..1b06339ab1 100644 --- a/instrumentation/opentelemetry-instrumentation-django/src/opentelemetry/instrumentation/django/middleware/otel_middleware.py +++ b/instrumentation/opentelemetry-instrumentation-django/src/opentelemetry/instrumentation/django/middleware/otel_middleware.py @@ -349,6 +349,7 @@ def process_response(self, request, response): activation = request.META.pop(self._environ_activation_key, None) span = request.META.pop(self._environ_span_key, None) + exception = None active_requests_count_attrs = request.META.pop( self._environ_active_request_attr_key, None ) @@ -417,15 +418,6 @@ def process_response(self, request, response): except Exception: # pylint: disable=broad-exception-caught _logger.exception("Exception raised by response_hook") - if exception: - activation.__exit__( - type(exception), - exception, - getattr(exception, "__traceback__", None), - ) - else: - activation.__exit__(None, None, None) - if request_start_time is not None: duration_s = default_timer() - request_start_time if self._duration_histogram_old: @@ -437,16 +429,29 @@ def process_response(self, request, response): if target: duration_attrs_old[SpanAttributes.HTTP_TARGET] = target self._duration_histogram_old.record( - max(round(duration_s * 1000), 0), duration_attrs_old + max(round(duration_s * 1000), 0), + duration_attrs_old, ) if self._duration_histogram_new: duration_attrs_new = _parse_duration_attrs( duration_attrs, _StabilityMode.HTTP ) self._duration_histogram_new.record( - max(duration_s, 0), duration_attrs_new + max(duration_s, 0), + duration_attrs_new, ) self._active_request_counter.add(-1, active_requests_count_attrs) + + if activation and span: + if exception: + activation.__exit__( + type(exception), + exception, + getattr(exception, "__traceback__", None), + ) + else: + activation.__exit__(None, None, None) + if request.META.get(self._environ_token, None) is not None: detach(request.META.get(self._environ_token)) request.META.pop(self._environ_token) diff --git a/instrumentation/opentelemetry-instrumentation-django/tests/test_middleware.py b/instrumentation/opentelemetry-instrumentation-django/tests/test_middleware.py index 960bf97bc4..2316ed9882 100644 --- a/instrumentation/opentelemetry-instrumentation-django/tests/test_middleware.py +++ b/instrumentation/opentelemetry-instrumentation-django/tests/test_middleware.py @@ -1104,3 +1104,66 @@ def test_http_custom_response_headers_not_in_span_attributes(self): for key, _ in not_expected.items(): self.assertNotIn(key, span.attributes) self.memory_exporter.clear() + + +class TestMiddlewareSpanActivationTiming(WsgiTestBase): + """Test span activation timing relative to metrics recording.""" + + @classmethod + def setUpClass(cls): + conf.settings.configure(ROOT_URLCONF=modules[__name__]) + super().setUpClass() + + def setUp(self): + super().setUp() + setup_test_environment() + _django_instrumentor.instrument() + + def tearDown(self): + super().tearDown() + teardown_test_environment() + _django_instrumentor.uninstrument() + + @classmethod + def tearDownClass(cls): + super().tearDownClass() + conf.settings = conf.LazySettings() + + def test_span_ended_after_metrics_recorded(self): + """Span activation exits after metrics recording.""" + Client().get("/traced/") + + spans = self.memory_exporter.get_finished_spans() + self.assertEqual(len(spans), 1) + + # Span properly finished + self.assertIsNotNone(spans[0].end_time) + + # Metrics recorded + metrics_list = self.memory_metrics_reader.get_metrics_data() + histogram_found = any( + "duration" in metric.name + for rm in metrics_list.resource_metrics + for sm in rm.scope_metrics + for metric in sm.metrics + ) + self.assertTrue(histogram_found) + + def test_metrics_recorded_with_exception(self): + """Metrics recorded even when request raises exception.""" + with self.assertRaises(ValueError): + Client().get("/error/") + + spans = self.memory_exporter.get_finished_spans() + self.assertEqual(len(spans), 1) + self.assertEqual(spans[0].status.status_code, StatusCode.ERROR) + + # Metrics still recorded + metrics_list = self.memory_metrics_reader.get_metrics_data() + histogram_found = any( + "duration" in metric.name + for rm in metrics_list.resource_metrics + for sm in rm.scope_metrics + for metric in sm.metrics + ) + self.assertTrue(histogram_found) diff --git a/tests/opentelemetry-docker-tests/tests/django/test_django_functional.py b/tests/opentelemetry-docker-tests/tests/django/test_django_functional.py new file mode 100644 index 0000000000..913e4fca2b --- /dev/null +++ b/tests/opentelemetry-docker-tests/tests/django/test_django_functional.py @@ -0,0 +1,161 @@ +# 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. + +from sys import modules + +from django import VERSION, conf +from django.http import HttpResponse +from django.test.client import Client +from django.test.utils import setup_test_environment, teardown_test_environment + +from opentelemetry import metrics as metrics_api +from opentelemetry.instrumentation.django import DjangoInstrumentor +from opentelemetry.sdk.metrics import AlwaysOnExemplarFilter +from opentelemetry.test.globals_test import ( + reset_metrics_globals, +) +from opentelemetry.test.test_base import TestBase +from opentelemetry.trace import ( + INVALID_SPAN_ID, + INVALID_TRACE_ID, +) + +DJANGO_2_0 = VERSION >= (2, 0) + +if DJANGO_2_0: + from django.urls import re_path +else: + from django.conf.urls import url as re_path + + +def view_test_route(request): # pylint: disable=unused-argument + return HttpResponse("Test response") + + +urlpatterns = [ + re_path(r"^test/", view_test_route), +] + + +class TestFunctionalDjango(TestBase): + def setUp(self): + super().setUp() + self.memory_exporter.clear() + # This is done because set_meter_provider cannot override the + # current meter provider. + reset_metrics_globals() + ( + self.meter_provider, + self.memory_metrics_reader, + ) = self.create_meter_provider( + exemplar_filter=AlwaysOnExemplarFilter(), + ) + metrics_api.set_meter_provider(self.meter_provider) + + conf.settings.configure( + ROOT_URLCONF=modules[__name__], + DATABASES={ + "default": {}, + }, + ) + + setup_test_environment() + self._client = Client() + + DjangoInstrumentor().instrument( + meter_provider=self.meter_provider, + ) + + def tearDown(self): + DjangoInstrumentor().uninstrument() + teardown_test_environment() + conf.settings = conf.LazySettings() + super().tearDown() + + def test_duration_metrics_exemplars(self): + """Should generate exemplars with trace and span IDs for Django HTTP requests.""" + self._client.get("/test/") + self._client.get("/test/") + self._client.get("/test/") + + metrics_data = self.memory_metrics_reader.get_metrics_data() + self.assertIsNotNone(metrics_data) + self.assertTrue(len(metrics_data.resource_metrics) > 0) + + duration_metric = None + metric_names = [] + for resource_metric in metrics_data.resource_metrics: + for scope_metric in resource_metric.scope_metrics: + for metric in scope_metric.metrics: + metric_names.append(metric.name) + if metric.name in [ + "http.server.request.duration", + "http.server.duration", + ]: + duration_metric = metric + break + if duration_metric: + break + if duration_metric: + break + + self.assertGreater( + len(metric_names), + 0, + "No metrics were generated", + ) + self.assertTrue( + any( + name + in ["http.server.request.duration", "http.server.duration"] + for name in metric_names + ), + f"Expected duration metric not found. Available metrics: {metric_names}", + ) + self.assertIn( + "http.server.active_requests", + metric_names, + f"Expected active_requests metric not found. Available metrics: {metric_names}", + ) + + self.assertIsNotNone(duration_metric) + data_points = list(duration_metric.data.data_points) + self.assertTrue(len(data_points) > 0) + + exemplar_count = 0 + for data_point in data_points: + if hasattr(data_point, "exemplars") and data_point.exemplars: + for exemplar in data_point.exemplars: + exemplar_count += 1 + # Exemplar has required fields and valid span context + self.assertIsNotNone(exemplar.value) + self.assertIsNotNone(exemplar.time_unix_nano) + self.assertIsNotNone(exemplar.span_id) + self.assertNotEqual(exemplar.span_id, INVALID_SPAN_ID) + self.assertIsNotNone(exemplar.trace_id) + self.assertNotEqual(exemplar.trace_id, INVALID_TRACE_ID) + + # Trace and span ID of exemplar are part of finished spans + finished_spans = self.memory_exporter.get_finished_spans() + finished_span_ids = [ + span.context.span_id for span in finished_spans + ] + finished_trace_ids = [ + span.context.trace_id for span in finished_spans + ] + self.assertIn(exemplar.span_id, finished_span_ids) + self.assertIn(exemplar.trace_id, finished_trace_ids) + + # At least one exemplar was generated + self.assertGreater(exemplar_count, 0) diff --git a/tests/opentelemetry-docker-tests/tests/test-requirements.txt b/tests/opentelemetry-docker-tests/tests/test-requirements.txt index 365239d960..048d35cb4c 100644 --- a/tests/opentelemetry-docker-tests/tests/test-requirements.txt +++ b/tests/opentelemetry-docker-tests/tests/test-requirements.txt @@ -17,6 +17,7 @@ click-repl==0.3.0 cryptography==44.0.1 Deprecated==1.2.14 distro==1.9.0 +Django==4.2.17 dnspython==2.6.1 docker==5.0.3 docker-compose==1.29.2 diff --git a/tox.ini b/tox.ini index d85d158529..0d1692af60 100644 --- a/tox.ini +++ b/tox.ini @@ -1008,6 +1008,7 @@ deps = -e {toxinidir}/instrumentation/opentelemetry-instrumentation-kafka-python -e {toxinidir}/instrumentation/opentelemetry-instrumentation-confluent-kafka -e {toxinidir}/instrumentation/opentelemetry-instrumentation-dbapi + -e {toxinidir}/instrumentation/opentelemetry-instrumentation-django -e {toxinidir}/instrumentation/opentelemetry-instrumentation-flask -e {toxinidir}/instrumentation/opentelemetry-instrumentation-mysql -e {toxinidir}/instrumentation/opentelemetry-instrumentation-mysqlclient