Add debugging to sync response generation (#7929)

This commit is contained in:
Richard van der Hoff 2020-07-22 13:43:10 +01:00 committed by GitHub
parent 931b026844
commit b74919c72e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 19 additions and 2 deletions

1
changelog.d/7929.misc Normal file
View File

@ -0,0 +1 @@
Add debugging to `/sync` response generation (disabled by default).

View File

@ -283,6 +283,7 @@ class SyncHandler(object):
timeout, timeout,
full_state, full_state,
) )
logger.debug("Returning sync response for %s", user_id)
return res return res
async def _wait_for_sync_for_user( async def _wait_for_sync_for_user(
@ -990,10 +991,14 @@ class SyncHandler(object):
joined_room_ids=joined_room_ids, joined_room_ids=joined_room_ids,
) )
logger.debug("Fetching account data")
account_data_by_room = await self._generate_sync_entry_for_account_data( account_data_by_room = await self._generate_sync_entry_for_account_data(
sync_result_builder sync_result_builder
) )
logger.debug("Fetching room data")
res = await self._generate_sync_entry_for_rooms( res = await self._generate_sync_entry_for_rooms(
sync_result_builder, account_data_by_room sync_result_builder, account_data_by_room
) )
@ -1004,10 +1009,12 @@ class SyncHandler(object):
since_token is None and sync_config.filter_collection.blocks_all_presence() since_token is None and sync_config.filter_collection.blocks_all_presence()
) )
if self.hs_config.use_presence and not block_all_presence_data: if self.hs_config.use_presence and not block_all_presence_data:
logger.debug("Fetching presence data")
await self._generate_sync_entry_for_presence( await self._generate_sync_entry_for_presence(
sync_result_builder, newly_joined_rooms, newly_joined_or_invited_users sync_result_builder, newly_joined_rooms, newly_joined_or_invited_users
) )
logger.debug("Fetching to-device data")
await self._generate_sync_entry_for_to_device(sync_result_builder) await self._generate_sync_entry_for_to_device(sync_result_builder)
device_lists = await self._generate_sync_entry_for_device_list( device_lists = await self._generate_sync_entry_for_device_list(
@ -1018,6 +1025,7 @@ class SyncHandler(object):
newly_left_users=newly_left_users, newly_left_users=newly_left_users,
) )
logger.debug("Fetching OTK data")
device_id = sync_config.device_id device_id = sync_config.device_id
one_time_key_counts = {} # type: JsonDict one_time_key_counts = {} # type: JsonDict
if device_id: if device_id:
@ -1025,6 +1033,7 @@ class SyncHandler(object):
user_id, device_id user_id, device_id
) )
logger.debug("Fetching group data")
await self._generate_sync_entry_for_groups(sync_result_builder) await self._generate_sync_entry_for_groups(sync_result_builder)
# debug for https://github.com/matrix-org/synapse/issues/4422 # debug for https://github.com/matrix-org/synapse/issues/4422
@ -1035,6 +1044,7 @@ class SyncHandler(object):
"Sync result for newly joined room %s: %r", room_id, joined_room "Sync result for newly joined room %s: %r", room_id, joined_room
) )
logger.debug("Sync response calculation complete")
return SyncResult( return SyncResult(
presence=sync_result_builder.presence, presence=sync_result_builder.presence,
account_data=sync_result_builder.account_data, account_data=sync_result_builder.account_data,
@ -1407,8 +1417,9 @@ class SyncHandler(object):
newly_joined_rooms = room_changes.newly_joined_rooms newly_joined_rooms = room_changes.newly_joined_rooms
newly_left_rooms = room_changes.newly_left_rooms newly_left_rooms = room_changes.newly_left_rooms
def handle_room_entries(room_entry): async def handle_room_entries(room_entry):
return self._generate_room_entry( logger.debug("Generating room entry for %s", room_entry.room_id)
res = await self._generate_room_entry(
sync_result_builder, sync_result_builder,
ignored_users, ignored_users,
room_entry, room_entry,
@ -1417,6 +1428,8 @@ class SyncHandler(object):
account_data=account_data_by_room.get(room_entry.room_id, {}), account_data=account_data_by_room.get(room_entry.room_id, {}),
always_include=sync_result_builder.full_state, always_include=sync_result_builder.full_state,
) )
logger.debug("Generated room entry for %s", room_entry.room_id)
return res
await concurrently_execute(handle_room_entries, room_entries, 10) await concurrently_execute(handle_room_entries, room_entries, 10)

View File

@ -183,9 +183,11 @@ class SyncRestServlet(RestServlet):
time_now, sync_result, requester.access_token_id, filter_collection time_now, sync_result, requester.access_token_id, filter_collection
) )
logger.debug("Event formatting complete")
return 200, response_content return 200, response_content
async def encode_response(self, time_now, sync_result, access_token_id, filter): async def encode_response(self, time_now, sync_result, access_token_id, filter):
logger.debug("Formatting events in sync response")
if filter.event_format == "client": if filter.event_format == "client":
event_formatter = format_event_for_client_v2_without_room_id event_formatter = format_event_for_client_v2_without_room_id
elif filter.event_format == "federation": elif filter.event_format == "federation":
@ -213,6 +215,7 @@ class SyncRestServlet(RestServlet):
event_formatter, event_formatter,
) )
logger.debug("building sync response dict")
return { return {
"account_data": {"events": sync_result.account_data}, "account_data": {"events": sync_result.account_data},
"to_device": {"events": sync_result.to_device}, "to_device": {"events": sync_result.to_device},