fix(asgi): ensure error tags are set on request spans (backport #5818 to 1.13) (#5839)

Backports: #5818

## Checklist

- [x] Change(s) are motivated and described in the PR description.
- [x] Testing strategy is described if automated tests are not included
in the PR.
- [x] Risk is outlined (performance impact, potential for breakage,
maintainability, etc).
- [x] Change is maintainable (easy to change, telemetry, documentation).
- [x] [Library release note
guidelines](https://ddtrace.readthedocs.io/en/stable/contributing.html#Release-Note-Guidelines)
are followed.
- [x] Documentation is included (in-code, generated user docs, [public
corp docs](https://github.com/DataDog/documentation/)).
- [x] OPTIONAL: PR description includes explicit acknowledgement of the
performance implications of the change as reported in the benchmarks PR
comment.

## Reviewer Checklist

- [x] Title is accurate.
- [x] No unnecessary changes are introduced.
- [x] Description motivates each change.
- [x] Avoids breaking
[API](https://ddtrace.readthedocs.io/en/stable/versioning.html#interfaces)
changes unless absolutely necessary.
- [x] Testing strategy adequately addresses listed risk(s).
- [x] Change is maintainable (easy to change, telemetry, documentation).
- [x] Release note makes sense to a user of the library.
- [x] Reviewer has explicitly acknowledged and discussed the performance
implications of this PR as reported in the benchmarks PR comment.

Author: mabdinur

ddtrace/contrib/asgi/middleware.py

@@ -213,15 +213,7 @@ async def wrapped_send(message):
                 trace_utils.set_http_meta(
                     span, self.integration_config, status_code=status_code, response_headers=response_headers
                 )
-
-                try:
-                    return await send(message)
-                finally:
-                    # Per asgi spec, "more_body" is used if there is still data to send
-                    # Close the span if "http.response.body" has no more data left to send in the
-                    # response.
-                    if message.get("type") == "http.response.body" and not message.get("more_body", False):
-                        span.finish()
+                return await send(message)
 
             async def wrapped_blocked_send(message):
                 accept_header = (
@@ -243,11 +235,7 @@ async def wrapped_blocked_send(message):
                     message["body"] = bytes(appsec_utils._get_blocked_template(accept_header), "utf-8")
                     message["more_body"] = False
 
-                try:
-                    return await send(message)
-                finally:
-                    if message.get("type") == "http.response.body":
-                        span.finish()
+                return await send(message)
 
             try:
                 if _request_blocked(span):
@@ -259,9 +247,6 @@ async def wrapped_blocked_send(message):
                 self.handle_exception_span(exc, span)
                 reraise(exc_type, exc_val, exc_tb)
             finally:
-                try:
-                    del scope["datadog"]["request_span"]
-                except KeyError:
-                    pass
-
+                if span in scope["datadog"]["request_spans"]:
+                    scope["datadog"]["request_spans"].remove(span)
                 span.finish()

releasenotes/notes/fastapi-set-error-tags-before-finishing-span-8fc48f94909251c1.yaml

@@ -0,0 +1,4 @@
+---
+fixes:
+  - |
+    asgi: Ensures ``error.message`` and ``error.stack`` tags are set when an exception is raised in a route.

tests/contrib/asgi/test_asgi.py

@@ -127,9 +127,10 @@ async def tasks_app_with_more_body(scope, receive, send):
         await send({"type": "http.response.body", "body": b"*", "more_body": True})
         assert not request_span.finished
 
-        # assert that the span has finished after more_body is False
+        # assert that the span has not finished after more_body. Span should be finished after
+        # the ddtrace trace middleware is exited.
         await send({"type": "http.response.body", "body": b"*", "more_body": False})
-        assert request_span.finished
+        assert not request_span.finished
         await asyncio.sleep(1)
 
 
@@ -524,7 +525,7 @@ async def test_tasks_asgi_without_more_body(scope, tracer, test_spans):
     assert request_span.span_type == "web"
     # typical duration without background task should be in less than 10 ms
     # duration with background task will take approximately 1.1s
-    assert request_span.duration < 1
+    assert request_span.duration < 1.1
 
 
 @pytest.mark.asyncio
@@ -547,7 +548,7 @@ async def test_tasks_asgi_with_more_body(scope, tracer, test_spans):
     assert request_span.span_type == "web"
     # typical duration without background task should be in less than 10 ms
     # duration with background task will take approximately 1.1s
-    assert request_span.duration < 1
+    assert request_span.duration < 1.1
 
 
 @pytest.mark.asyncio

tests/contrib/fastapi/test_fastapi.py

@@ -7,7 +7,6 @@
 
 import ddtrace
 from ddtrace import config
-from ddtrace.constants import ERROR_MSG
 from ddtrace.contrib.fastapi import patch as fastapi_patch
 from ddtrace.contrib.fastapi import unpatch as fastapi_unpatch
 from ddtrace.contrib.starlette.patch import patch as patch_starlette
@@ -341,27 +340,10 @@ def test_invalid_path(client, tracer, test_spans):
     assert request_span.get_tag("span.kind") == "server"
 
 
-def test_500_error_raised(client, tracer, test_spans):
+@snapshot(ignores=["meta.error.stack"])
+def test_500_error_raised(snapshot_client):
     with pytest.raises(RuntimeError):
-        client.get("/500", headers={"X-Token": "DataDog"})
-    spans = test_spans.pop_traces()
-    assert len(spans) == 1
-    assert len(spans[0]) == 1
-
-    request_span = spans[0][0]
-    assert request_span.service == "fastapi"
-    assert request_span.name == "fastapi.request"
-    assert request_span.resource == "GET /500"
-    assert request_span.get_tag("http.route") == "/500"
-    assert request_span.error == 1
-    assert request_span.get_tag("http.method") == "GET"
-    assert request_span.get_tag("http.url") == "http://testserver/500"
-    assert request_span.get_tag("http.status_code") == "500"
-    assert request_span.get_tag(ERROR_MSG) == "Server error"
-    assert request_span.get_tag("error.type") == "builtins.RuntimeError"
-    assert request_span.get_tag("component") == "fastapi"
-    assert request_span.get_tag("span.kind") == "server"
-    assert 'raise RuntimeError("Server error")' in request_span.get_tag("error.stack")
+        snapshot_client.get("/500")
 
 
 def test_streaming_response(client, tracer, test_spans):
@@ -647,7 +629,7 @@ def test_background_task(client, tracer, test_spans):
     assert request_span.resource == "GET /asynctask"
     # typical duration without background task should be in less than 10 ms
     # duration with background task will take approximately 1.1s
-    assert request_span.duration < 1
+    assert request_span.duration < 1.1
 
 
 @pytest.mark.parametrize("host", ["hostserver", "hostserver:5454"])

tests/contrib/starlette/test_starlette.py

@@ -534,4 +534,4 @@ def test_background_task(client, tracer, test_spans):
     assert request_span.resource == "GET /backgroundtask"
     # typical duration without background task should be in less than 10ms
     # duration with background task will take approximately 1.1s
-    assert request_span.duration < 1
+    assert request_span.duration < 1.1

tests/snapshots/tests.contrib.fastapi.test_fastapi.test_500_error_raised.json

@@ -0,0 +1,36 @@
+[[
+  {
+    "name": "fastapi.request",
+    "service": "fastapi",
+    "resource": "GET /500",
+    "trace_id": 0,
+    "span_id": 1,
+    "parent_id": 0,
+    "type": "web",
+    "error": 1,
+    "meta": {
+      "_dd.p.dm": "-0",
+      "component": "fastapi",
+      "error.message": "Server error",
+      "error.stack": "Traceback (most recent call last):\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/ddtrace/contrib/asgi/middleware.py\", line 243, in __call__\n    return await self.app(scope, receive, wrapped_send)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/middleware/errors.py\", line 181, in __call__\n    raise exc from None\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/middleware/errors.py\", line 159, in __call__\n    await self.app(scope, receive, _send)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/exceptions.py\", line 82, in __call__\n    raise exc from None\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/exceptions.py\", line 71, in __call__\n    await self.app(scope, receive, sender)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/routing.py\", line 566, in __call__\n    await route.handle(scope, receive, send)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/routing.py\", line 227, in handle\n    await self.app(scope, receive, send)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/starlette/routing.py\", line 41, in app\n    response = await func(request)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/fastapi/routing.py\", line 201, in app\n    raw_response = await run_endpoint_function(\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/.riot/venv_py3913_fastapi~0640/lib/python3.9/site-packages/fastapi/routing.py\", line 148, in run_endpoint_function\n    return await dependant.call(**values)\n  File \"/Users/munirabdinur/go/src/github.com/DataDog/dd-trace-py/tests/contrib/fastapi/app.py\", line 91, in error\n    raise RuntimeError(\"Server error\")\nRuntimeError: Server error\n",
+      "error.type": "builtins.RuntimeError",
+      "http.method": "GET",
+      "http.route": "/500",
+      "http.status_code": "500",
+      "http.url": "http://testserver/500",
+      "http.useragent": "testclient",
+      "http.version": "1.1",
+      "language": "python",
+      "runtime-id": "64d5226c7c7c4f79a067f32ae2c114ef",
+      "span.kind": "server"
+    },
+    "metrics": {
+      "_dd.agent_psr": 1.0,
+      "_dd.top_level": 1,
+      "_dd.tracer_kr": 1.0,
+      "_sampling_priority_v1": 1,
+      "process_id": 24153
+    },
+    "duration": 1430000,
+    "start": 1683658745856878000
+  }]]