From b697f4ab9a3cf648ae004ef743b6e4564eaae6a2 Mon Sep 17 00:00:00 2001 From: Daniel Hochman Date: Fri, 12 Jul 2024 11:38:40 -0500 Subject: [PATCH] opentelemetry-instrumentation-asgi: always set status code on duration attributes (#2627) --- CHANGELOG.md | 2 + .../instrumentation/asgi/__init__.py | 50 +++++++-------- .../tests/test_asgi_middleware.py | 63 ++++++++++++++++++- .../opentelemetry/instrumentation/_semconv.py | 32 ++++++---- 4 files changed, 104 insertions(+), 43 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 3eddf58cb8..76d77f06e0 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 ([#2153](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2153)) - `opentelemetry-instrumentation-asgi` Removed `NET_HOST_NAME` AND `NET_HOST_PORT` from active requests count attribute ([#2610](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2610)) +- `opentelemetry-instrumentation-asgi` Bugfix: Middleware did not set status code attribute on duration metrics for non-recording spans. + ([#2627](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2627)) ## Version 1.25.0/0.46b0 (2024-05-31) diff --git a/instrumentation/opentelemetry-instrumentation-asgi/src/opentelemetry/instrumentation/asgi/__init__.py b/instrumentation/opentelemetry-instrumentation-asgi/src/opentelemetry/instrumentation/asgi/__init__.py index f006f9b0c9..7e51837d4d 100644 --- a/instrumentation/opentelemetry-instrumentation-asgi/src/opentelemetry/instrumentation/asgi/__init__.py +++ b/instrumentation/opentelemetry-instrumentation-asgi/src/opentelemetry/instrumentation/asgi/__init__.py @@ -438,8 +438,6 @@ def set_status_code( sem_conv_opt_in_mode=_HTTPStabilityMode.DEFAULT, ): """Adds HTTP response attributes to span using the status_code argument.""" - if not span.is_recording(): - return status_code_str = str(status_code) try: @@ -836,36 +834,16 @@ async def otel_send(message: dict[str, Any]): ) as send_span: if callable(self.client_response_hook): self.client_response_hook(send_span, scope, message) + + status_code = None + if message["type"] == "http.response.start": + status_code = message["status"] + elif message["type"] == "websocket.send": + status_code = 200 + if send_span.is_recording(): if message["type"] == "http.response.start": - status_code = message["status"] - # We record metrics only once - set_status_code( - server_span, - status_code, - duration_attrs, - self._sem_conv_opt_in_mode, - ) - set_status_code( - send_span, - status_code, - None, - self._sem_conv_opt_in_mode, - ) expecting_trailers = message.get("trailers", False) - elif message["type"] == "websocket.send": - set_status_code( - server_span, - 200, - duration_attrs, - self._sem_conv_opt_in_mode, - ) - set_status_code( - send_span, - 200, - None, - self._sem_conv_opt_in_mode, - ) send_span.set_attribute("asgi.event.type", message["type"]) if ( server_span.is_recording() @@ -886,6 +864,20 @@ async def otel_send(message: dict[str, Any]): server_span.set_attributes( custom_response_attributes ) + if status_code: + # We record metrics only once + set_status_code( + server_span, + status_code, + duration_attrs, + self._sem_conv_opt_in_mode, + ) + set_status_code( + send_span, + status_code, + None, + self._sem_conv_opt_in_mode, + ) propagator = get_global_response_propagator() if propagator: diff --git a/instrumentation/opentelemetry-instrumentation-asgi/tests/test_asgi_middleware.py b/instrumentation/opentelemetry-instrumentation-asgi/tests/test_asgi_middleware.py index ff266cb5bf..5bb04adb25 100644 --- a/instrumentation/opentelemetry-instrumentation-asgi/tests/test_asgi_middleware.py +++ b/instrumentation/opentelemetry-instrumentation-asgi/tests/test_asgi_middleware.py @@ -514,7 +514,9 @@ def test_asgi_not_recording(self): mock_span = mock.Mock() mock_span.is_recording.return_value = False mock_tracer.start_as_current_span.return_value = mock_span - mock_tracer.start_as_current_span.return_value.__enter__ = mock_span + mock_tracer.start_as_current_span.return_value.__enter__ = mock.Mock( + return_value=mock_span + ) mock_tracer.start_as_current_span.return_value.__exit__ = mock_span with mock.patch("opentelemetry.trace.get_tracer") as tracer: tracer.return_value = mock_tracer @@ -1342,6 +1344,65 @@ def test_basic_metric_success(self): ) self.assertEqual(point.value, 0) + def test_basic_metric_success_nonrecording_span(self): + mock_tracer = mock.Mock() + mock_span = mock.Mock() + mock_span.is_recording.return_value = False + mock_tracer.start_as_current_span.return_value = mock_span + mock_tracer.start_as_current_span.return_value.__enter__ = mock.Mock( + return_value=mock_span + ) + mock_tracer.start_as_current_span.return_value.__exit__ = mock_span + with mock.patch("opentelemetry.trace.get_tracer") as tracer: + tracer.return_value = mock_tracer + app = otel_asgi.OpenTelemetryMiddleware(simple_asgi) + self.seed_app(app) + start = default_timer() + self.send_default_request() + duration = max(round((default_timer() - start) * 1000), 0) + expected_duration_attributes = { + "http.method": "GET", + "http.host": "127.0.0.1", + "http.scheme": "http", + "http.flavor": "1.0", + "net.host.port": 80, + "http.status_code": 200, + } + expected_requests_count_attributes = { + "http.method": "GET", + "http.host": "127.0.0.1", + "http.scheme": "http", + "http.flavor": "1.0", + } + metrics_list = self.memory_metrics_reader.get_metrics_data() + # pylint: disable=too-many-nested-blocks + for resource_metric in metrics_list.resource_metrics: + for scope_metrics in resource_metric.scope_metrics: + for metric in scope_metrics.metrics: + for point in list(metric.data.data_points): + if isinstance(point, HistogramDataPoint): + self.assertDictEqual( + expected_duration_attributes, + dict(point.attributes), + ) + self.assertEqual(point.count, 1) + if metric.name == "http.server.duration": + self.assertAlmostEqual( + duration, point.sum, delta=5 + ) + elif ( + metric.name == "http.server.response.size" + ): + self.assertEqual(1024, point.sum) + elif metric.name == "http.server.request.size": + self.assertEqual(128, point.sum) + elif isinstance(point, NumberDataPoint): + self.assertDictEqual( + expected_requests_count_attributes, + dict(point.attributes), + ) + self.assertEqual(point.value, 0) + def test_basic_metric_success_new_semconv(self): app = otel_asgi.OpenTelemetryMiddleware(simple_asgi) self.seed_app(app) diff --git a/opentelemetry-instrumentation/src/opentelemetry/instrumentation/_semconv.py b/opentelemetry-instrumentation/src/opentelemetry/instrumentation/_semconv.py index 85b8e2e3ec..7e81692a98 100644 --- a/opentelemetry-instrumentation/src/opentelemetry/instrumentation/_semconv.py +++ b/opentelemetry-instrumentation/src/opentelemetry/instrumentation/_semconv.py @@ -355,29 +355,35 @@ def _set_status( sem_conv_opt_in_mode, ): if status_code < 0: - if _report_new(sem_conv_opt_in_mode): - span.set_attribute(ERROR_TYPE, status_code_str) - metrics_attributes[ERROR_TYPE] = status_code_str - - span.set_status( - Status( - StatusCode.ERROR, - "Non-integer HTTP status: " + status_code_str, + metrics_attributes[ERROR_TYPE] = status_code_str + if span.is_recording(): + if _report_new(sem_conv_opt_in_mode): + span.set_attribute(ERROR_TYPE, status_code_str) + span.set_status( + Status( + StatusCode.ERROR, + "Non-integer HTTP status: " + status_code_str, + ) ) - ) else: status = http_status_to_status_code(status_code, server_span=True) if _report_old(sem_conv_opt_in_mode): - span.set_attribute(SpanAttributes.HTTP_STATUS_CODE, status_code) + if span.is_recording(): + span.set_attribute( + SpanAttributes.HTTP_STATUS_CODE, status_code + ) metrics_attributes[SpanAttributes.HTTP_STATUS_CODE] = status_code if _report_new(sem_conv_opt_in_mode): - span.set_attribute(HTTP_RESPONSE_STATUS_CODE, status_code) + if span.is_recording(): + span.set_attribute(HTTP_RESPONSE_STATUS_CODE, status_code) metrics_attributes[HTTP_RESPONSE_STATUS_CODE] = status_code if status == StatusCode.ERROR: - span.set_attribute(ERROR_TYPE, status_code_str) + if span.is_recording(): + span.set_attribute(ERROR_TYPE, status_code_str) metrics_attributes[ERROR_TYPE] = status_code_str - span.set_status(Status(status)) + if span.is_recording(): + span.set_status(Status(status)) # Get schema version based off of opt-in mode