diff options
| author | Richard van der Hoff <1389908+richvdh@users.noreply.github.com> | 2022-05-03 16:32:40 +0100 |
|---|---|---|
| committer | GitHub <noreply@github.com> | 2022-05-03 16:32:40 +0100 |
| commit | d66d68f9177d3addc32f6ab02458e3620f5ffc1f (patch) | |
| tree | 4d6ea0325d9d12d84a3f7f64ef0ce70cb908f1bb | |
| parent | Add missing space before 'docker' link in release announcement script (#12612) (diff) | |
| download | synapse-d66d68f9177d3addc32f6ab02458e3620f5ffc1f.tar.xz | |
Add extra debug logging to federation sender (#12614)
... in order to debug some problems we've been having with certain events not being sent when expected.
| -rw-r--r-- | changelog.d/12614.misc | 1 | ||||
| -rw-r--r-- | synapse/federation/sender/__init__.py | 20 |
2 files changed, 19 insertions, 2 deletions
diff --git a/changelog.d/12614.misc b/changelog.d/12614.misc new file mode 100644 index 0000000000..79022df127 --- /dev/null +++ b/changelog.d/12614.misc @@ -0,0 +1 @@ +Add extra debug logging to federation sender. diff --git a/synapse/federation/sender/__init__.py b/synapse/federation/sender/__init__.py index d795b7b26b..6d2f46318b 100644 --- a/synapse/federation/sender/__init__.py +++ b/synapse/federation/sender/__init__.py @@ -343,9 +343,16 @@ class FederationSender(AbstractFederationSender): last_token, self._last_poked_id, limit=100 ) - logger.debug("Handling %s -> %s", last_token, next_token) + logger.debug( + "Handling %i -> %i: %i events to send (current id %i)", + last_token, + next_token, + len(events), + self._last_poked_id, + ) if not events and next_token >= self._last_poked_id: + logger.debug("All events processed") break async def handle_event(event: EventBase) -> None: @@ -353,6 +360,7 @@ class FederationSender(AbstractFederationSender): send_on_behalf_of = event.internal_metadata.get_send_on_behalf_of() is_mine = self.is_mine_id(event.sender) if not is_mine and send_on_behalf_of is None: + logger.debug("Not sending remote-origin event %s", event) return # We also want to not send out-of-band membership events. @@ -389,12 +397,16 @@ class FederationSender(AbstractFederationSender): # above). # if event.internal_metadata.is_out_of_band_membership(): + logger.debug("Not sending OOB membership event %s", event) return # Finally, there are some other events that we should not send out # until someone asks for them. They are explicitly flagged as such # with `proactively_send: False`. if not event.internal_metadata.should_proactively_send(): + logger.debug( + "Not sending event with proactively_send=false: %s", event + ) return destinations: Optional[Set[str]] = None @@ -458,7 +470,10 @@ class FederationSender(AbstractFederationSender): "federation_sender" ).observe((now - ts) / 1000) - async def handle_room_events(events: Iterable[EventBase]) -> None: + async def handle_room_events(events: List[EventBase]) -> None: + logger.debug( + "Handling %i events in room %s", len(events), events[0].room_id + ) with Measure(self.clock, "handle_room_events"): for event in events: await handle_event(event) @@ -477,6 +492,7 @@ class FederationSender(AbstractFederationSender): ) ) + logger.debug("Successfully handled up to %i", next_token) await self.store.update_federation_out_pos("events", next_token) if events: |