Django activation exit after metrics record/add

Author: tammy-baylis-swi

instrumentation/opentelemetry-instrumentation-django/src/opentelemetry/instrumentation/django/middleware/otel_middleware.py

@@ -55,7 +55,7 @@
 )
 from opentelemetry.semconv.attributes.http_attributes import HTTP_ROUTE
 from opentelemetry.semconv.trace import SpanAttributes
-from opentelemetry.trace import Span, SpanKind, set_span_in_context, use_span
+from opentelemetry.trace import Span, SpanKind, use_span
 from opentelemetry.util.http import (
     OTEL_INSTRUMENTATION_HTTP_CAPTURE_HEADERS_SANITIZE_FIELDS,
     OTEL_INSTRUMENTATION_HTTP_CAPTURE_HEADERS_SERVER_REQUEST,
@@ -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,20 +418,7 @@ 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:
-            # Get the span and re-create context manually to pass to
-            # histogram for exemplars generation
-            metrics_context = set_span_in_context(span)
-
             duration_s = default_timer() - request_start_time
             if self._duration_histogram_old:
                 duration_attrs_old = _parse_duration_attrs(
@@ -443,7 +431,6 @@ def process_response(self, request, response):
                 self._duration_histogram_old.record(
                     max(round(duration_s * 1000), 0),
                     duration_attrs_old,
-                    context=metrics_context,
                 )
             if self._duration_histogram_new:
                 duration_attrs_new = _parse_duration_attrs(
@@ -452,9 +439,19 @@ def process_response(self, request, response):
                 self._duration_histogram_new.record(
                     max(duration_s, 0),
                     duration_attrs_new,
-                    context=metrics_context,
                 )
         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)

instrumentation/opentelemetry-instrumentation-django/tests/test_middleware.py

@@ -917,29 +917,6 @@ def test_wsgi_metrics_both_semconv(self):
                             )
         self.assertTrue(histrogram_data_point_seen and number_data_point_seen)
 
-    def test_wsgi_metrics_context_propagation(self):
-        with (
-            patch.object(
-                _DjangoMiddleware,
-                "_duration_histogram_old",
-            ) as mock_histogram_old,
-            patch.object(
-                _DjangoMiddleware,
-                "_duration_histogram_new",
-            ) as mock_histogram_new,
-        ):
-            mock_histogram_old.record = Mock()
-            mock_histogram_new.record = Mock()
-
-            Client().get("/traced/")
-
-            self.assertTrue(mock_histogram_old.record.called)
-            call_args = mock_histogram_old.record.call_args
-            self.assertIsNotNone(call_args)
-            self.assertIn("context", call_args.kwargs)
-            context_arg = call_args.kwargs["context"]
-            self.assertIsNotNone(context_arg)
-
     def test_wsgi_metrics_unistrument(self):
         Client().get("/span_name/1234/")
         _django_instrumentor.uninstrument()
@@ -1127,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)