From 32222ee1ae9f3e454ebab129489e1505ad58c3ff Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Fri, 4 Nov 2022 11:39:23 -0400 Subject: [PATCH 01/10] chore(fastapi): add reproduction for fastapi bug --- tests/contrib/fastapi/test_fastapi.py | 31 +++++++++++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/tests/contrib/fastapi/test_fastapi.py b/tests/contrib/fastapi/test_fastapi.py index 4f334986e35..dc0654850a5 100644 --- a/tests/contrib/fastapi/test_fastapi.py +++ b/tests/contrib/fastapi/test_fastapi.py @@ -52,6 +52,20 @@ def application(tracer): yield application +@pytest.fixture +def app_with_middleware(application, tracer): + @application.middleware("http") + async def traced_middlware(request, call_next): + response = await call_next(request) + response.headers["MIDDLEWARE-CALLED"] = "true" + span = tracer.current_span() + if span is not None: + response.headers["DD-TRACE-CURRENT-SPAN"] = span.name + return response + + yield application + + @pytest.fixture def client(tracer): with TestClient(app.get_app()) as test_client: @@ -590,3 +604,20 @@ def test_host_header(client, tracer, test_spans, host): assert test_spans.spans request_span = test_spans.spans[0] assert request_span.get_tag("http.url") == "http://%s/asynctask" % (host,) + + +def test_tracing_in_middleware(app_with_middleware, test_spans): + """Test if fastapi middlewares are traced""" + + with TestClient(app_with_middleware) as client: + r = client.get("/", headers={"sleep": "False"}) + assert r.status_code == 200 + + spans = test_spans.pop_traces() + assert len(spans) == 1 + assert len(spans[0]) == 2 + request_span, _ = spans[0] + + assert r.headers["MIDDLEWARE-CALLED"] == "true" + assert "DD-TRACE-CURRENT-SPAN" in r.headers + assert r.headers["DD-TRACE-CURRENT-SPAN"] == request_span.name From a781b612e6a579724137618001928111c6b7307a Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Mon, 21 Nov 2022 14:33:18 -0500 Subject: [PATCH 02/10] add fix and releasenote --- ddtrace/contrib/fastapi/patch.py | 10 ++++++++++ .../fastapi-fix-middlewares-705975a535daaea8.yaml | 4 ++++ 2 files changed, 14 insertions(+) create mode 100644 releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml diff --git a/ddtrace/contrib/fastapi/patch.py b/ddtrace/contrib/fastapi/patch.py index af6fe9af5ce..6dc0131763b 100644 --- a/ddtrace/contrib/fastapi/patch.py +++ b/ddtrace/contrib/fastapi/patch.py @@ -42,6 +42,15 @@ def traced_init(wrapped, instance, args, kwargs): wrapped(*args, **kwargs) +def trace_add_middleware(wrapped, instance, args, kwargs): + # remove ddtrace trace middleware + if instance.user_middleware and instance.user_middleware[0].cls is TraceMiddleware: + instance.user_middleware.insert(1, Middleware(*args, **kwargs)) + instance.middleware_stack = instance.build_middleware_stack() + else: + wrapped(*args, **kwargs) + + async def traced_serialize_response(wrapped, instance, args, kwargs): """Wrapper for fastapi.routing.serialize_response function. @@ -74,6 +83,7 @@ def patch(): setattr(fastapi, "_datadog_patch", True) Pin().onto(fastapi) _w("fastapi.applications", "FastAPI.__init__", traced_init) + _w("fastapi.applications", "FastAPI.add_middleware", trace_add_middleware) _w("fastapi.routing", "serialize_response", traced_serialize_response) # We need to check that Starlette instrumentation hasn't already patched these diff --git a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml new file mode 100644 index 00000000000..738abb1a873 --- /dev/null +++ b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml @@ -0,0 +1,4 @@ +--- +fixes: + - | + fastapi: Ensure all user middlewares are captured in the ``fastapi.request`` span. From ef207169ce55990275c309f25c3c3d60812c5cb6 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Tue, 22 Nov 2022 10:29:18 -0500 Subject: [PATCH 03/10] Update releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml Co-authored-by: Brett Langdon --- .../notes/fastapi-fix-middlewares-705975a535daaea8.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml index 738abb1a873..29ef1c9dce3 100644 --- a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml +++ b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml @@ -1,4 +1,4 @@ --- fixes: - | - fastapi: Ensure all user middlewares are captured in the ``fastapi.request`` span. + fastapi: Ensure spans are created for all user middlewares. From e584ba9d887af43a0038f85937ba805621c9dea3 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Tue, 22 Nov 2022 11:14:14 -0500 Subject: [PATCH 04/10] make trace middleware test a snapshot test --- ddtrace/contrib/fastapi/patch.py | 5 +- tests/contrib/fastapi/test_fastapi.py | 34 ++++++------- ...st_fastapi.test_tracing_in_middleware.json | 48 +++++++++++++++++++ 3 files changed, 66 insertions(+), 21 deletions(-) create mode 100644 tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json diff --git a/ddtrace/contrib/fastapi/patch.py b/ddtrace/contrib/fastapi/patch.py index 6dc0131763b..bbdb352b82b 100644 --- a/ddtrace/contrib/fastapi/patch.py +++ b/ddtrace/contrib/fastapi/patch.py @@ -43,8 +43,11 @@ def traced_init(wrapped, instance, args, kwargs): def trace_add_middleware(wrapped, instance, args, kwargs): - # remove ddtrace trace middleware + # Ensures user_middlewares are added after ddtrace TraceMiddleware if instance.user_middleware and instance.user_middleware[0].cls is TraceMiddleware: + # Overrides FastApi.add_middlware(). Note - fastapi.applications.FastAPI is the + # child class of starlette.applications.Starlette(): + # https://github.com/encode/starlette/blob/0.13.2/starlette/applications.py#L115 instance.user_middleware.insert(1, Middleware(*args, **kwargs)) instance.middleware_stack = instance.build_middleware_stack() else: diff --git a/tests/contrib/fastapi/test_fastapi.py b/tests/contrib/fastapi/test_fastapi.py index dc0654850a5..dd2728de73a 100644 --- a/tests/contrib/fastapi/test_fastapi.py +++ b/tests/contrib/fastapi/test_fastapi.py @@ -53,18 +53,21 @@ def application(tracer): @pytest.fixture -def app_with_middleware(application, tracer): +def snapshot_app_with_middleware(): + fastapi_patch() + + application = app.get_app() + @application.middleware("http") async def traced_middlware(request, call_next): - response = await call_next(request) - response.headers["MIDDLEWARE-CALLED"] = "true" - span = tracer.current_span() - if span is not None: - response.headers["DD-TRACE-CURRENT-SPAN"] = span.name - return response + with ddtrace.tracer.trace("traced_middlware"): + response = await call_next(request) + return response yield application + fastapi_unpatch() + @pytest.fixture def client(tracer): @@ -606,18 +609,9 @@ def test_host_header(client, tracer, test_spans, host): assert request_span.get_tag("http.url") == "http://%s/asynctask" % (host,) -def test_tracing_in_middleware(app_with_middleware, test_spans): +@snapshot() +def test_tracing_in_middleware(snapshot_app_with_middleware): """Test if fastapi middlewares are traced""" - - with TestClient(app_with_middleware) as client: - r = client.get("/", headers={"sleep": "False"}) + with TestClient(snapshot_app_with_middleware) as test_client: + r = test_client.get("/", headers={"sleep": "False"}) assert r.status_code == 200 - - spans = test_spans.pop_traces() - assert len(spans) == 1 - assert len(spans[0]) == 2 - request_span, _ = spans[0] - - assert r.headers["MIDDLEWARE-CALLED"] == "true" - assert "DD-TRACE-CURRENT-SPAN" in r.headers - assert r.headers["DD-TRACE-CURRENT-SPAN"] == request_span.name diff --git a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json new file mode 100644 index 00000000000..3d01d2a64b7 --- /dev/null +++ b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json @@ -0,0 +1,48 @@ +[[ + { + "name": "fastapi.request", + "service": "fastapi", + "resource": "GET /", + "trace_id": 0, + "span_id": 1, + "parent_id": 0, + "type": "web", + "meta": { + "_dd.p.dm": "-0", + "http.method": "GET", + "http.status_code": "200", + "http.url": "http://testserver/", + "http.useragent": "testclient", + "http.version": "1.1", + "runtime-id": "7433b22c2562484081ca485a65d19945" + }, + "metrics": { + "_dd.agent_psr": 1.0, + "_dd.top_level": 1, + "_dd.tracer_kr": 1.0, + "_sampling_priority_v1": 1, + "process_id": 4144 + }, + "duration": 1034000, + "start": 1669131973327481000 + }, + { + "name": "traced_middlware", + "service": "fastapi", + "resource": "traced_middlware", + "trace_id": 0, + "span_id": 2, + "parent_id": 1, + "duration": 459000, + "start": 1669131973327931000 + }, + { + "name": "fastapi.serialize_response", + "service": "fastapi", + "resource": "fastapi.serialize_response", + "trace_id": 0, + "span_id": 3, + "parent_id": 2, + "duration": 24000, + "start": 1669131973328198000 + }]] From 68cd3fa01ea0c66f946fc7df1762b80f957c1c15 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Thu, 22 Dec 2022 16:56:23 -0500 Subject: [PATCH 05/10] Update releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml --- .../notes/fastapi-fix-middlewares-705975a535daaea8.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml index 29ef1c9dce3..6c92dff929a 100644 --- a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml +++ b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml @@ -1,4 +1,4 @@ --- fixes: - | - fastapi: Ensure spans are created for all user middlewares. + fastapi: Ensure all fastapi middlewares are captured in the `fastapi.request` span. From 019aebb6100b85f9b39ffb5650b3d2a241de0379 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Fri, 23 Dec 2022 13:23:41 -0500 Subject: [PATCH 06/10] Update releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml Co-authored-by: Yun Kim <35776586+Yun-Kim@users.noreply.github.com> --- .../notes/fastapi-fix-middlewares-705975a535daaea8.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml index 6c92dff929a..99f2ad11b9b 100644 --- a/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml +++ b/releasenotes/notes/fastapi-fix-middlewares-705975a535daaea8.yaml @@ -1,4 +1,4 @@ --- fixes: - | - fastapi: Ensure all fastapi middlewares are captured in the `fastapi.request` span. + fastapi: Previously, custom fastapi middlewares configured after application startup were not traced. This fix ensures that all fastapi middlewares are captured in the `fastapi.request` span. From 0a2f67c34334d6ae19c9103a579540b583b36061 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Fri, 30 Dec 2022 10:01:22 -0500 Subject: [PATCH 07/10] add error and span type tags to snapshot file --- ...trib.fastapi.test_fastapi.test_tracing_in_middleware.json | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json index 3d01d2a64b7..30a95014581 100644 --- a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json +++ b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json @@ -7,6 +7,7 @@ "span_id": 1, "parent_id": 0, "type": "web", + "error": 0, "meta": { "_dd.p.dm": "-0", "http.method": "GET", @@ -33,6 +34,8 @@ "trace_id": 0, "span_id": 2, "parent_id": 1, + "type": "", + "error": 0, "duration": 459000, "start": 1669131973327931000 }, @@ -43,6 +46,8 @@ "trace_id": 0, "span_id": 3, "parent_id": 2, + "type": "", + "error": 0, "duration": 24000, "start": 1669131973328198000 }]] From 0a6a7a2e372021b3e02208fddc6111c2b7082a77 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Thu, 2 Feb 2023 09:59:09 -0500 Subject: [PATCH 08/10] ensure all fastapi middlewares are traced --- ddtrace/contrib/fastapi/patch.py | 25 ++++----------------- tests/contrib/fastapi/test_fastapi_patch.py | 6 ++--- 2 files changed, 7 insertions(+), 24 deletions(-) diff --git a/ddtrace/contrib/fastapi/patch.py b/ddtrace/contrib/fastapi/patch.py index bbdb352b82b..d4dfbe4e478 100644 --- a/ddtrace/contrib/fastapi/patch.py +++ b/ddtrace/contrib/fastapi/patch.py @@ -1,5 +1,4 @@ import fastapi -from fastapi.middleware import Middleware import fastapi.routing from ddtrace import Pin @@ -35,23 +34,8 @@ def span_modifier(span, scope): span.resource = "{} {}".format(scope["method"], resource) -def traced_init(wrapped, instance, args, kwargs): - mw = kwargs.pop("middleware", []) - mw.insert(0, Middleware(TraceMiddleware, integration_config=config.fastapi)) - kwargs.update({"middleware": mw}) - wrapped(*args, **kwargs) - - -def trace_add_middleware(wrapped, instance, args, kwargs): - # Ensures user_middlewares are added after ddtrace TraceMiddleware - if instance.user_middleware and instance.user_middleware[0].cls is TraceMiddleware: - # Overrides FastApi.add_middlware(). Note - fastapi.applications.FastAPI is the - # child class of starlette.applications.Starlette(): - # https://github.com/encode/starlette/blob/0.13.2/starlette/applications.py#L115 - instance.user_middleware.insert(1, Middleware(*args, **kwargs)) - instance.middleware_stack = instance.build_middleware_stack() - else: - wrapped(*args, **kwargs) +def wrap_middleware_stack(wrapped, instance, args, kwargs): + return TraceMiddleware(app=wrapped(*args, **kwargs), integration_config=config.fastapi) async def traced_serialize_response(wrapped, instance, args, kwargs): @@ -85,8 +69,7 @@ def patch(): setattr(fastapi, "_datadog_patch", True) Pin().onto(fastapi) - _w("fastapi.applications", "FastAPI.__init__", traced_init) - _w("fastapi.applications", "FastAPI.add_middleware", trace_add_middleware) + _w("fastapi.applications", "FastAPI.build_middleware_stack", wrap_middleware_stack) _w("fastapi.routing", "serialize_response", traced_serialize_response) # We need to check that Starlette instrumentation hasn't already patched these @@ -103,7 +86,7 @@ def unpatch(): setattr(fastapi, "_datadog_patch", False) - _u(fastapi.applications.FastAPI, "__init__") + _u(fastapi.applications.FastAPI, "build_middleware_stack") _u(fastapi.routing, "serialize_response") # We need to check that Starlette instrumentation hasn't already unpatched these diff --git a/tests/contrib/fastapi/test_fastapi_patch.py b/tests/contrib/fastapi/test_fastapi_patch.py index d36a5ff147d..fa65822d175 100644 --- a/tests/contrib/fastapi/test_fastapi_patch.py +++ b/tests/contrib/fastapi/test_fastapi_patch.py @@ -10,19 +10,19 @@ class TestFastapiPatch(PatchTestCase.Base): __unpatch_func__ = unpatch def assert_module_patched(self, fastapi): - self.assert_wrapped(fastapi.applications.FastAPI.__init__) + self.assert_wrapped(fastapi.applications.FastAPI.build_middleware_stack) self.assert_wrapped(fastapi.routing.serialize_response) self.assert_wrapped(fastapi.routing.APIRoute.handle) self.assert_wrapped(fastapi.routing.Mount.handle) def assert_not_module_patched(self, fastapi): - self.assert_not_wrapped(fastapi.applications.FastAPI.__init__) + self.assert_not_wrapped(fastapi.applications.FastAPI.build_middleware_stack) self.assert_not_wrapped(fastapi.routing.serialize_response) self.assert_not_wrapped(fastapi.routing.APIRoute.handle) self.assert_not_wrapped(fastapi.routing.Mount.handle) def assert_not_module_double_patched(self, fastapi): - self.assert_not_double_wrapped(fastapi.applications.FastAPI.__init__) + self.assert_not_double_wrapped(fastapi.applications.FastAPI.build_middleware_stack) self.assert_not_double_wrapped(fastapi.routing.serialize_response) self.assert_not_double_wrapped(fastapi.routing.APIRoute.handle) self.assert_not_double_wrapped(fastapi.routing.Mount.handle) From b277e81949e8be0e73237090b5b3331898ab916c Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Thu, 2 Feb 2023 11:15:14 -0500 Subject: [PATCH 09/10] fix failing snapshot test --- ....contrib.fastapi.test_fastapi.test_tracing_in_middleware.json | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json index 30a95014581..42606eb35ba 100644 --- a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json +++ b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json @@ -15,6 +15,7 @@ "http.url": "http://testserver/", "http.useragent": "testclient", "http.version": "1.1", + "language": "python", "runtime-id": "7433b22c2562484081ca485a65d19945" }, "metrics": { From 1d4159f59905e33790b2a90c475723ec65402604 Mon Sep 17 00:00:00 2001 From: Munir Abdinur Date: Mon, 6 Feb 2023 23:15:08 -0500 Subject: [PATCH 10/10] fix 1.x conflict, add component tag to new snapshot --- ....contrib.fastapi.test_fastapi.test_tracing_in_middleware.json | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json index 42606eb35ba..55705fdf274 100644 --- a/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json +++ b/tests/snapshots/tests.contrib.fastapi.test_fastapi.test_tracing_in_middleware.json @@ -10,6 +10,7 @@ "error": 0, "meta": { "_dd.p.dm": "-0", + "component": "fastapi", "http.method": "GET", "http.status_code": "200", "http.url": "http://testserver/",