Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .changelog/4656.fixed
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
`opentelemetry-instrumentation-asgi`: Fix HTTP server duration metrics to exclude background task execution time
Original file line number Diff line number Diff line change
Expand Up @@ -795,12 +795,14 @@ async def __call__(
span_name, scope, receive
)

response_complete_time: list[float] = []
otel_send = self._get_otel_send(
current_span,
span_name,
scope,
send,
attributes,
response_complete_time,
)

await self.app(scope, otel_receive, otel_send)
Expand All @@ -816,7 +818,11 @@ async def __call__(
query,
self._sem_conv_opt_in_mode,
)
duration_s = default_timer() - start
duration_s = (
response_complete_time[0] - start
if response_complete_time
else default_timer() - start
)
duration_attrs_old = _parse_duration_attrs(
attributes, _StabilityMode.DEFAULT
)
Expand Down Expand Up @@ -974,6 +980,7 @@ def _get_otel_send(
scope,
send,
duration_attrs,
response_complete_time: list[float],
):
expecting_trailers = False

Expand Down Expand Up @@ -1030,6 +1037,7 @@ async def otel_send(message: dict[str, Any]):
and message["type"] == "http.response.trailers"
and not message.get("more_trailers", False)
):
response_complete_time.append(default_timer())
server_span.end()

return otel_send
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -702,6 +702,78 @@ def add_body_and_trailer_span(expected: list):
_SIMULATED_BACKGROUND_TASK_EXECUTION_TIME_S * 10**9,
)

async def test_background_execution_metrics_duration(self):
"""Test that http.server.duration excludes background task time."""
app = otel_asgi.OpenTelemetryMiddleware(background_execution_asgi)
self.seed_app(app)
await self.send_default_request()
await self.get_all_output()

metrics = self.get_sorted_metrics(SCOPE)
duration_found = False
for metric in metrics:
if metric.name == "http.server.duration":
data_points = list(metric.data.data_points)
for point in data_points:
Comment on lines +714 to +717

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic of finding the duration data point appears to be duplicated in each of the three tests cases, could we create a small helper function to clean up these tests a bit?

if isinstance(point, HistogramDataPoint):
duration_found = True
self.assertLess(
point.sum,
_SIMULATED_BACKGROUND_TASK_EXECUTION_TIME_S * 1000,
)
self.assertTrue(
duration_found, "http.server.duration metric not found"
)

async def test_background_execution_metrics_duration_new_semconv(self):
"""Test that http.server.request.duration excludes background task time."""
app = otel_asgi.OpenTelemetryMiddleware(background_execution_asgi)
self.seed_app(app)
await self.send_default_request()
await self.get_all_output()

metrics = self.get_sorted_metrics(SCOPE)
duration_found = False
for metric in metrics:
if metric.name == "http.server.request.duration":
data_points = list(metric.data.data_points)
for point in data_points:
if isinstance(point, HistogramDataPoint):
duration_found = True
self.assertLess(
point.sum,
_SIMULATED_BACKGROUND_TASK_EXECUTION_TIME_S,
)
self.assertTrue(
duration_found,
"http.server.request.duration metric not found",
)

async def test_trailers_background_execution_metrics_duration(self):
"""Test that http.server.duration excludes background task time for trailer responses."""
app = otel_asgi.OpenTelemetryMiddleware(
background_execution_trailers_asgi
)
self.seed_app(app)
await self.send_default_request()
await self.get_all_output()

metrics = self.get_sorted_metrics(SCOPE)
duration_found = False
for metric in metrics:
if metric.name == "http.server.duration":
data_points = list(metric.data.data_points)
for point in data_points:
if isinstance(point, HistogramDataPoint):
duration_found = True
self.assertLess(
point.sum,
_SIMULATED_BACKGROUND_TASK_EXECUTION_TIME_S * 1000,
)
self.assertTrue(
duration_found, "http.server.duration metric not found"
)

async def test_override_span_name(self):
"""Test that default span_names can be overwritten by our callback function."""
span_name = "Dymaxion"
Expand Down
Loading