From a648a06d52715d0d4ad1ec72d042df1b3fd1be71 Mon Sep 17 00:00:00 2001 From: Shay Date: Wed, 3 Aug 2022 10:19:34 -0700 Subject: Add some tracing spans to give insight into local joins (#13439) --- changelog.d/13439.misc | 1 + synapse/handlers/message.py | 15 ++++++----- synapse/handlers/room_member.py | 57 ++++++++++++++++++++++------------------- 3 files changed, 40 insertions(+), 33 deletions(-) create mode 100644 changelog.d/13439.misc diff --git a/changelog.d/13439.misc b/changelog.d/13439.misc new file mode 100644 index 0000000000..4aa73d7075 --- /dev/null +++ b/changelog.d/13439.misc @@ -0,0 +1 @@ +Add some tracing to give more insight into local room joins. diff --git a/synapse/handlers/message.py b/synapse/handlers/message.py index ee0773988e..6b03603598 100644 --- a/synapse/handlers/message.py +++ b/synapse/handlers/message.py @@ -52,6 +52,7 @@ from synapse.events.builder import EventBuilder from synapse.events.snapshot import EventContext from synapse.events.validator import EventValidator from synapse.handlers.directory import DirectoryHandler +from synapse.logging import opentracing from synapse.logging.context import make_deferred_yieldable, run_in_background from synapse.metrics.background_process_metrics import run_as_background_process from synapse.replication.http.send_event import ReplicationSendEventRestServlet @@ -1374,9 +1375,10 @@ class EventCreationHandler: # and `state_groups` because they have `prev_events` that aren't persisted yet # (historical messages persisted in reverse-chronological order). if not event.internal_metadata.is_historical(): - await self._bulk_push_rule_evaluator.action_for_event_by_user( - event, context - ) + with opentracing.start_active_span("calculate_push_actions"): + await self._bulk_push_rule_evaluator.action_for_event_by_user( + event, context + ) try: # If we're a worker we need to hit out to the master. @@ -1463,9 +1465,10 @@ class EventCreationHandler: state = await state_entry.get_state( self._storage_controllers.state, StateFilter.all() ) - joined_hosts = await self.store.get_joined_hosts( - event.room_id, state, state_entry - ) + with opentracing.start_active_span("get_joined_hosts"): + joined_hosts = await self.store.get_joined_hosts( + event.room_id, state, state_entry + ) # Note that the expiry times must be larger than the expiry time in # _external_cache_joined_hosts_updates. diff --git a/synapse/handlers/room_member.py b/synapse/handlers/room_member.py index 520c52e013..70dc69c809 100644 --- a/synapse/handlers/room_member.py +++ b/synapse/handlers/room_member.py @@ -32,6 +32,7 @@ from synapse.event_auth import get_named_level, get_power_level_event from synapse.events import EventBase from synapse.events.snapshot import EventContext from synapse.handlers.profile import MAX_AVATAR_URL_LEN, MAX_DISPLAYNAME_LEN +from synapse.logging import opentracing from synapse.module_api import NOT_SPAM from synapse.storage.state import StateFilter from synapse.types import ( @@ -428,14 +429,14 @@ class RoomMemberHandler(metaclass=abc.ABCMeta): await self._join_rate_per_room_limiter.ratelimit( requester, key=room_id, update=False ) - - result_event = await self.event_creation_handler.handle_new_client_event( - requester, - event, - context, - extra_users=[target], - ratelimit=ratelimit, - ) + with opentracing.start_active_span("handle_new_client_event"): + result_event = await self.event_creation_handler.handle_new_client_event( + requester, + event, + context, + extra_users=[target], + ratelimit=ratelimit, + ) if event.membership == Membership.LEAVE: if prev_member_event_id: @@ -564,25 +565,26 @@ class RoomMemberHandler(metaclass=abc.ABCMeta): # by application services), and then by room ID. async with self.member_as_limiter.queue(as_id): async with self.member_linearizer.queue(key): - result = await self.update_membership_locked( - requester, - target, - room_id, - action, - txn_id=txn_id, - remote_room_hosts=remote_room_hosts, - third_party_signed=third_party_signed, - ratelimit=ratelimit, - content=content, - new_room=new_room, - require_consent=require_consent, - outlier=outlier, - historical=historical, - allow_no_prev_events=allow_no_prev_events, - prev_event_ids=prev_event_ids, - state_event_ids=state_event_ids, - depth=depth, - ) + with opentracing.start_active_span("update_membership_locked"): + result = await self.update_membership_locked( + requester, + target, + room_id, + action, + txn_id=txn_id, + remote_room_hosts=remote_room_hosts, + third_party_signed=third_party_signed, + ratelimit=ratelimit, + content=content, + new_room=new_room, + require_consent=require_consent, + outlier=outlier, + historical=historical, + allow_no_prev_events=allow_no_prev_events, + prev_event_ids=prev_event_ids, + state_event_ids=state_event_ids, + depth=depth, + ) return result @@ -649,6 +651,7 @@ class RoomMemberHandler(metaclass=abc.ABCMeta): Returns: A tuple of the new event ID and stream ID. """ + content_specified = bool(content) if content is None: content = {} -- cgit 1.4.1