Merge pull request #2574 from matrix-org/erikj/room_list_fixes

Add logging and fix log contexts for publicRooms

synapse/appservice/api.py

@@ -18,6 +18,7 @@ from synapse.api.constants import ThirdPartyEntityKind
 from synapse.api.errors import CodeMessageException
 from synapse.http.client import SimpleHttpClient
 from synapse.events.utils import serialize_event
+from synapse.util.logcontext import preserve_fn, make_deferred_yieldable
 from synapse.util.caches.response_cache import ResponseCache
 from synapse.types import ThirdPartyInstanceID
 
@@ -192,9 +193,12 @@ class ApplicationServiceApi(SimpleHttpClient):
                 defer.returnValue(None)
 
         key = (service.id, protocol)
-        return self.protocol_meta_cache.get(key) or (
+        result = self.protocol_meta_cache.get(key)
-            self.protocol_meta_cache.set(key, _get())
+        if not result:
+            result = self.protocol_meta_cache.set(
+                key, preserve_fn(_get)()
             )
+        return make_deferred_yieldable(result)
 
     @defer.inlineCallbacks
     def push_bulk(self, service, events, txn_id=None):

synapse/federation/federation_server.py

@@ -18,6 +18,7 @@ from .federation_base import FederationBase
 from .units import Transaction, Edu
 
 from synapse.util import async
+from synapse.util.logcontext import make_deferred_yieldable, preserve_fn
 from synapse.util.logutils import log_function
 from synapse.util.caches.response_cache import ResponseCache
 from synapse.events import FrozenEvent
@@ -253,12 +254,13 @@ class FederationServer(FederationBase):
         result = self._state_resp_cache.get((room_id, event_id))
         if not result:
             with (yield self._server_linearizer.queue((origin, room_id))):
-                resp = yield self._state_resp_cache.set(
+                d = self._state_resp_cache.set(
                     (room_id, event_id),
-                    self._on_context_state_request_compute(room_id, event_id)
+                    preserve_fn(self._on_context_state_request_compute)(room_id, event_id)
                 )
+                resp = yield make_deferred_yieldable(d)
         else:
-            resp = yield result
+            resp = yield make_deferred_yieldable(result)
 
         defer.returnValue((200, resp))
 

synapse/handlers/room_list.py

@@ -20,6 +20,7 @@ from ._base import BaseHandler
 from synapse.api.constants import (
     EventTypes, JoinRules,
 )
+from synapse.util.logcontext import make_deferred_yieldable, preserve_fn
 from synapse.util.async import concurrently_execute
 from synapse.util.caches.descriptors import cachedInlineCallbacks
 from synapse.util.caches.response_cache import ResponseCache
@@ -70,6 +71,7 @@ class RoomListHandler(BaseHandler):
         if search_filter:
             # We explicitly don't bother caching searches or requests for
             # appservice specific lists.
+            logger.info("Bypassing cache as search request.")
             return self._get_public_room_list(
                 limit, since_token, search_filter, network_tuple=network_tuple,
             )
@@ -77,13 +79,16 @@ class RoomListHandler(BaseHandler):
         key = (limit, since_token, network_tuple)
         result = self.response_cache.get(key)
         if not result:
+            logger.info("No cached result, calculating one.")
             result = self.response_cache.set(
                 key,
-                self._get_public_room_list(
+                preserve_fn(self._get_public_room_list)(
                     limit, since_token, network_tuple=network_tuple
                 )
             )
-        return result
+        else:
+            logger.info("Using cached deferred result.")
+        return make_deferred_yieldable(result)
 
     @defer.inlineCallbacks
     def _get_public_room_list(self, limit=None, since_token=None,

synapse/handlers/sync.py

@@ -15,7 +15,7 @@
 
 from synapse.api.constants import Membership, EventTypes
 from synapse.util.async import concurrently_execute
-from synapse.util.logcontext import LoggingContext
+from synapse.util.logcontext import LoggingContext, make_deferred_yieldable, preserve_fn
 from synapse.util.metrics import Measure, measure_func
 from synapse.util.caches.response_cache import ResponseCache
 from synapse.push.clientformat import format_push_rules_for_user
@@ -184,11 +184,11 @@ class SyncHandler(object):
         if not result:
             result = self.response_cache.set(
                 sync_config.request_key,
-                self._wait_for_sync_for_user(
+                preserve_fn(self._wait_for_sync_for_user)(
                     sync_config, since_token, timeout, full_state
                 )
             )
-        return result
+        return make_deferred_yieldable(result)
 
     @defer.inlineCallbacks
     def _wait_for_sync_for_user(self, sync_config, since_token, timeout,