From b251cff8196e4130b2a6951c8fe569ed46779443 Mon Sep 17 00:00:00 2001 From: Sean Quah <8349537+squahtx@users.noreply.github.com> Date: Thu, 18 Aug 2022 16:26:26 +0100 Subject: [PATCH] Fix incorrect juggling of logging contexts in `_PerHostRatelimiter` (#13554) Signed-off-by: Sean Quah Co-authored-by: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> --- changelog.d/13554.misc | 1 + synapse/util/ratelimitutils.py | 17 +++++++---------- 2 files changed, 8 insertions(+), 10 deletions(-) create mode 100644 changelog.d/13554.misc diff --git a/changelog.d/13554.misc b/changelog.d/13554.misc new file mode 100644 index 000000000..99dbcebec --- /dev/null +++ b/changelog.d/13554.misc @@ -0,0 +1 @@ +Instrument `FederationStateIdsServlet` (`/state_ids`) for understandable traces in Jaeger. diff --git a/synapse/util/ratelimitutils.py b/synapse/util/ratelimitutils.py index 724d39b92..f678b52cb 100644 --- a/synapse/util/ratelimitutils.py +++ b/synapse/util/ratelimitutils.py @@ -154,7 +154,9 @@ class _PerHostRatelimiter: self.host = host request_id = object() - ret = self._on_enter(request_id) + # Ideally we'd use `Deferred.fromCoroutine()` here, to save on redundant + # type-checking, but we'd need Twisted >= 21.2. + ret = defer.ensureDeferred(self._on_enter_with_tracing(request_id)) try: yield ret finally: @@ -175,6 +177,10 @@ class _PerHostRatelimiter: """ return len(self.request_times) > self.sleep_limit + async def _on_enter_with_tracing(self, request_id: object) -> None: + with start_active_span("ratelimit wait"), queue_wait_timer.time(): + await self._on_enter(request_id) + def _on_enter(self, request_id: object) -> "defer.Deferred[None]": time_now = self.clock.time_msec() @@ -257,17 +263,8 @@ class _PerHostRatelimiter: # Ensure that we've properly cleaned up. self.sleeping_requests.discard(request_id) self.ready_request_queue.pop(request_id, None) - wait_span_scope.__exit__(None, None, None) - wait_timer_cm.__exit__(None, None, None) return r - # Tracing - wait_span_scope = start_active_span("ratelimit wait") - wait_span_scope.__enter__() - # Metrics - wait_timer_cm = queue_wait_timer.time() - wait_timer_cm.__enter__() - ret_defer.addCallbacks(on_start, on_err) ret_defer.addBoth(on_both) return make_deferred_yieldable(ret_defer)