Add some extra logging for edge cases of federation

This commit is contained in:
Erik Johnston 2017-04-27 14:38:21 +01:00
parent 7239258ae6
commit e42b4ebf0f
1 changed files with 22 additions and 2 deletions

View File

@ -171,6 +171,12 @@ class FederationHandler(BaseHandler):
yield self._get_missing_events_for_pdu( yield self._get_missing_events_for_pdu(
origin, pdu, prevs, min_depth origin, pdu, prevs, min_depth
) )
elif prevs - seen:
logger.info(
"Not fetching %d missing events for room %r,event %s: %r...",
len(prevs - seen), pdu.room_id, pdu.event_id,
list(prevs - seen)[:5],
)
prevs = {e_id for e_id, _ in pdu.prev_events} prevs = {e_id for e_id, _ in pdu.prev_events}
seen = set(have_seen.keys()) seen = set(have_seen.keys())
@ -232,8 +238,8 @@ class FederationHandler(BaseHandler):
latest |= seen latest |= seen
logger.info( logger.info(
"Missing %d events for room %r: %r...", "Missing %d events for room %r pdy %s: %r...",
len(prevs - seen), pdu.room_id, list(prevs - seen)[:5] len(prevs - seen), pdu.room_id, pdu.event_id, list(prevs - seen)[:5]
) )
# XXX: we set timeout to 10s to help workaround # XXX: we set timeout to 10s to help workaround
@ -265,11 +271,17 @@ class FederationHandler(BaseHandler):
timeout=10000, timeout=10000,
) )
logger.info(
"Got %d events: %r...",
len(missing_events), [e.event_id for e in missing_events[:5]]
)
# We want to sort these by depth so we process them and # We want to sort these by depth so we process them and
# tell clients about them in order. # tell clients about them in order.
missing_events.sort(key=lambda x: x.depth) missing_events.sort(key=lambda x: x.depth)
for e in missing_events: for e in missing_events:
logger.info("Handling found event %s", e.event_id)
yield self.on_receive_pdu( yield self.on_receive_pdu(
origin, origin,
e, e,
@ -279,6 +291,14 @@ class FederationHandler(BaseHandler):
have_seen = yield self.store.have_events( have_seen = yield self.store.have_events(
[ev for ev, _ in pdu.prev_events] [ev for ev, _ in pdu.prev_events]
) )
seen = set(have_seen.keys())
if prevs - seen:
logger.info(
"Still missing %d prev events for %s: %r...",
len(prevs - seen), pdu.event_id, list(prevs - seen)[:5]
)
else:
logger.info("Found all missing prev events for %s", pdu.event_id)
defer.returnValue(have_seen) defer.returnValue(have_seen)
@log_function @log_function