Skip to content

Commit fd79ae9

Browse files
Fix DjangoInstrumentor exemplars generation for http.server.(request.)duration (#3945)
* Add manual context recreation for Django duration exemplars * Changelog * Update unit test * Add docker test_django_functional * Deps * Simpler metrics_context assignment * Django activation exit after metrics record/add * Add more asserts * Rm first assn * Update CHANGELOG.md --------- Co-authored-by: Riccardo Magliocchetti <[email protected]>
1 parent 4f4afd5 commit fd79ae9

File tree

6 files changed

+244
-12
lines changed

6 files changed

+244
-12
lines changed

CHANGELOG.md

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,8 +11,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
1111
1212
## Unreleased
1313

14-
### Fixed
14+
### Fixed
1515

16+
- `opentelemetry-instrumentation-django`: Fix exemplars generation for `http.server.(request.)duration`
17+
([#3945](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/3945))
1618
- `opentelemetry-util-http`, `opentelemetry-instrumentation-requests`, `opentelemetry-instrumentation-wsgi`, `opentelemetry-instrumentation-asgi`: normalize byte-valued user-agent headers before detecting synthetic sources so attributes are recorded reliably.
1719
([#4001](https://github.com/open-telemetry/opentelemetry-python-contrib/issues/4001))
1820

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

Lines changed: 15 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -417,15 +417,6 @@ def process_response(self, request, response):
417417
except Exception: # pylint: disable=broad-exception-caught
418418
_logger.exception("Exception raised by response_hook")
419419

420-
if exception:
421-
activation.__exit__(
422-
type(exception),
423-
exception,
424-
getattr(exception, "__traceback__", None),
425-
)
426-
else:
427-
activation.__exit__(None, None, None)
428-
429420
if request_start_time is not None:
430421
duration_s = default_timer() - request_start_time
431422
if self._duration_histogram_old:
@@ -437,16 +428,29 @@ def process_response(self, request, response):
437428
if target:
438429
duration_attrs_old[SpanAttributes.HTTP_TARGET] = target
439430
self._duration_histogram_old.record(
440-
max(round(duration_s * 1000), 0), duration_attrs_old
431+
max(round(duration_s * 1000), 0),
432+
duration_attrs_old,
441433
)
442434
if self._duration_histogram_new:
443435
duration_attrs_new = _parse_duration_attrs(
444436
duration_attrs, _StabilityMode.HTTP
445437
)
446438
self._duration_histogram_new.record(
447-
max(duration_s, 0), duration_attrs_new
439+
max(duration_s, 0),
440+
duration_attrs_new,
448441
)
449442
self._active_request_counter.add(-1, active_requests_count_attrs)
443+
444+
if activation and span:
445+
if exception:
446+
activation.__exit__(
447+
type(exception),
448+
exception,
449+
getattr(exception, "__traceback__", None),
450+
)
451+
else:
452+
activation.__exit__(None, None, None)
453+
450454
if request.META.get(self._environ_token, None) is not None:
451455
detach(request.META.get(self._environ_token))
452456
request.META.pop(self._environ_token)

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

Lines changed: 63 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1104,3 +1104,66 @@ def test_http_custom_response_headers_not_in_span_attributes(self):
11041104
for key, _ in not_expected.items():
11051105
self.assertNotIn(key, span.attributes)
11061106
self.memory_exporter.clear()
1107+
1108+
1109+
class TestMiddlewareSpanActivationTiming(WsgiTestBase):
1110+
"""Test span activation timing relative to metrics recording."""
1111+
1112+
@classmethod
1113+
def setUpClass(cls):
1114+
conf.settings.configure(ROOT_URLCONF=modules[__name__])
1115+
super().setUpClass()
1116+
1117+
def setUp(self):
1118+
super().setUp()
1119+
setup_test_environment()
1120+
_django_instrumentor.instrument()
1121+
1122+
def tearDown(self):
1123+
super().tearDown()
1124+
teardown_test_environment()
1125+
_django_instrumentor.uninstrument()
1126+
1127+
@classmethod
1128+
def tearDownClass(cls):
1129+
super().tearDownClass()
1130+
conf.settings = conf.LazySettings()
1131+
1132+
def test_span_ended_after_metrics_recorded(self):
1133+
"""Span activation exits after metrics recording."""
1134+
Client().get("/traced/")
1135+
1136+
spans = self.memory_exporter.get_finished_spans()
1137+
self.assertEqual(len(spans), 1)
1138+
1139+
# Span properly finished
1140+
self.assertIsNotNone(spans[0].end_time)
1141+
1142+
# Metrics recorded
1143+
metrics_list = self.memory_metrics_reader.get_metrics_data()
1144+
histogram_found = any(
1145+
"duration" in metric.name
1146+
for rm in metrics_list.resource_metrics
1147+
for sm in rm.scope_metrics
1148+
for metric in sm.metrics
1149+
)
1150+
self.assertTrue(histogram_found)
1151+
1152+
def test_metrics_recorded_with_exception(self):
1153+
"""Metrics recorded even when request raises exception."""
1154+
with self.assertRaises(ValueError):
1155+
Client().get("/error/")
1156+
1157+
spans = self.memory_exporter.get_finished_spans()
1158+
self.assertEqual(len(spans), 1)
1159+
self.assertEqual(spans[0].status.status_code, StatusCode.ERROR)
1160+
1161+
# Metrics still recorded
1162+
metrics_list = self.memory_metrics_reader.get_metrics_data()
1163+
histogram_found = any(
1164+
"duration" in metric.name
1165+
for rm in metrics_list.resource_metrics
1166+
for sm in rm.scope_metrics
1167+
for metric in sm.metrics
1168+
)
1169+
self.assertTrue(histogram_found)
Lines changed: 161 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,161 @@
1+
# Copyright The OpenTelemetry Authors
2+
#
3+
# Licensed under the Apache License, Version 2.0 (the "License");
4+
# you may not use this file except in compliance with the License.
5+
# You may obtain a copy of the License at
6+
#
7+
# http://www.apache.org/licenses/LICENSE-2.0
8+
#
9+
# Unless required by applicable law or agreed to in writing, software
10+
# distributed under the License is distributed on an "AS IS" BASIS,
11+
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
# See the License for the specific language governing permissions and
13+
# limitations under the License.
14+
15+
from sys import modules
16+
17+
from django import VERSION, conf
18+
from django.http import HttpResponse
19+
from django.test.client import Client
20+
from django.test.utils import setup_test_environment, teardown_test_environment
21+
22+
from opentelemetry import metrics as metrics_api
23+
from opentelemetry.instrumentation.django import DjangoInstrumentor
24+
from opentelemetry.sdk.metrics import AlwaysOnExemplarFilter
25+
from opentelemetry.test.globals_test import (
26+
reset_metrics_globals,
27+
)
28+
from opentelemetry.test.test_base import TestBase
29+
from opentelemetry.trace import (
30+
INVALID_SPAN_ID,
31+
INVALID_TRACE_ID,
32+
)
33+
34+
DJANGO_2_0 = VERSION >= (2, 0)
35+
36+
if DJANGO_2_0:
37+
from django.urls import re_path
38+
else:
39+
from django.conf.urls import url as re_path
40+
41+
42+
def view_test_route(request): # pylint: disable=unused-argument
43+
return HttpResponse("Test response")
44+
45+
46+
urlpatterns = [
47+
re_path(r"^test/", view_test_route),
48+
]
49+
50+
51+
class TestFunctionalDjango(TestBase):
52+
def setUp(self):
53+
super().setUp()
54+
self.memory_exporter.clear()
55+
# This is done because set_meter_provider cannot override the
56+
# current meter provider.
57+
reset_metrics_globals()
58+
(
59+
self.meter_provider,
60+
self.memory_metrics_reader,
61+
) = self.create_meter_provider(
62+
exemplar_filter=AlwaysOnExemplarFilter(),
63+
)
64+
metrics_api.set_meter_provider(self.meter_provider)
65+
66+
conf.settings.configure(
67+
ROOT_URLCONF=modules[__name__],
68+
DATABASES={
69+
"default": {},
70+
},
71+
)
72+
73+
setup_test_environment()
74+
self._client = Client()
75+
76+
DjangoInstrumentor().instrument(
77+
meter_provider=self.meter_provider,
78+
)
79+
80+
def tearDown(self):
81+
DjangoInstrumentor().uninstrument()
82+
teardown_test_environment()
83+
conf.settings = conf.LazySettings()
84+
super().tearDown()
85+
86+
def test_duration_metrics_exemplars(self):
87+
"""Should generate exemplars with trace and span IDs for Django HTTP requests."""
88+
self._client.get("/test/")
89+
self._client.get("/test/")
90+
self._client.get("/test/")
91+
92+
metrics_data = self.memory_metrics_reader.get_metrics_data()
93+
self.assertIsNotNone(metrics_data)
94+
self.assertTrue(len(metrics_data.resource_metrics) > 0)
95+
96+
duration_metric = None
97+
metric_names = []
98+
for resource_metric in metrics_data.resource_metrics:
99+
for scope_metric in resource_metric.scope_metrics:
100+
for metric in scope_metric.metrics:
101+
metric_names.append(metric.name)
102+
if metric.name in [
103+
"http.server.request.duration",
104+
"http.server.duration",
105+
]:
106+
duration_metric = metric
107+
break
108+
if duration_metric:
109+
break
110+
if duration_metric:
111+
break
112+
113+
self.assertGreater(
114+
len(metric_names),
115+
0,
116+
"No metrics were generated",
117+
)
118+
self.assertTrue(
119+
any(
120+
name
121+
in ["http.server.request.duration", "http.server.duration"]
122+
for name in metric_names
123+
),
124+
f"Expected duration metric not found. Available metrics: {metric_names}",
125+
)
126+
self.assertIn(
127+
"http.server.active_requests",
128+
metric_names,
129+
f"Expected active_requests metric not found. Available metrics: {metric_names}",
130+
)
131+
132+
self.assertIsNotNone(duration_metric)
133+
data_points = list(duration_metric.data.data_points)
134+
self.assertTrue(len(data_points) > 0)
135+
136+
exemplar_count = 0
137+
for data_point in data_points:
138+
if hasattr(data_point, "exemplars") and data_point.exemplars:
139+
for exemplar in data_point.exemplars:
140+
exemplar_count += 1
141+
# Exemplar has required fields and valid span context
142+
self.assertIsNotNone(exemplar.value)
143+
self.assertIsNotNone(exemplar.time_unix_nano)
144+
self.assertIsNotNone(exemplar.span_id)
145+
self.assertNotEqual(exemplar.span_id, INVALID_SPAN_ID)
146+
self.assertIsNotNone(exemplar.trace_id)
147+
self.assertNotEqual(exemplar.trace_id, INVALID_TRACE_ID)
148+
149+
# Trace and span ID of exemplar are part of finished spans
150+
finished_spans = self.memory_exporter.get_finished_spans()
151+
finished_span_ids = [
152+
span.context.span_id for span in finished_spans
153+
]
154+
finished_trace_ids = [
155+
span.context.trace_id for span in finished_spans
156+
]
157+
self.assertIn(exemplar.span_id, finished_span_ids)
158+
self.assertIn(exemplar.trace_id, finished_trace_ids)
159+
160+
# At least one exemplar was generated
161+
self.assertGreater(exemplar_count, 0)

tests/opentelemetry-docker-tests/tests/test-requirements.txt

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ click-repl==0.3.0
1717
cryptography==44.0.1
1818
Deprecated==1.2.14
1919
distro==1.9.0
20+
Django==4.2.17
2021
dnspython==2.6.1
2122
docker==5.0.3
2223
docker-compose==1.29.2

tox.ini

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1022,6 +1022,7 @@ deps =
10221022
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-kafka-python
10231023
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-confluent-kafka
10241024
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-dbapi
1025+
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-django
10251026
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-flask
10261027
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-mysql
10271028
-e {toxinidir}/instrumentation/opentelemetry-instrumentation-mysqlclient

0 commit comments

Comments
 (0)