Add more useful logging when we block fetching events

This commit is contained in:
Mark Haines 2016-12-30 20:00:44 +00:00
parent 48c3b7dc19
commit 0aff09f6c9
2 changed files with 14 additions and 0 deletions

View File

@ -538,7 +538,16 @@ class FederationServer(FederationBase):
if get_missing and prevs - seen: if get_missing and prevs - seen:
# If we're missing stuff, ensure we only fetch stuff one # If we're missing stuff, ensure we only fetch stuff one
# at a time. # at a time.
logger.info(
"Aquiring lock for room %r to fetch %d missing events: %r...",
pdu.room_id, len(prevs - seen), list(prevs - seen)[:5],
)
with (yield self._room_pdu_linearizer.queue(pdu.room_id)): with (yield self._room_pdu_linearizer.queue(pdu.room_id)):
logger.info(
"Aquired lock for room %r to fetch %d missing events",
pdu.room_id, len(prevs - seen),
)
# We recalculate seen, since it may have changed. # We recalculate seen, since it may have changed.
have_seen = yield self.store.have_events(prevs) have_seen = yield self.store.have_events(prevs)
seen = set(have_seen.keys()) seen = set(have_seen.keys())

View File

@ -23,6 +23,10 @@ from synapse.util import unwrapFirstError
from contextlib import contextmanager from contextlib import contextmanager
import logging
logger = logging.getLogger(__name__)
@defer.inlineCallbacks @defer.inlineCallbacks
def sleep(seconds): def sleep(seconds):
@ -181,6 +185,7 @@ class Linearizer(object):
self.key_to_defer[key] = new_defer self.key_to_defer[key] = new_defer
if current_defer: if current_defer:
logger.info("Waiting to aquire linearizer lock for key %r", key)
with PreserveLoggingContext(): with PreserveLoggingContext():
yield current_defer yield current_defer