Time get_room_members

2 files changed, 30 insertions, 1 deletions

diff --git a/synapse/app/homeserver.py b/synapse/app/homeserver.py
index d93afdc1c2..4a92cdc368 100755
--- a/synapse/app/homeserver.py
+++ b/synapse/app/homeserver.py
@@ -520,6 +520,26 @@ class SynapseSite(Site):
 
 
 def run(hs):
+    def prof(f):
+        from synapse.handlers.room import total_time
+        import time
+        def g(*args, **kwargs):
+            global total_time
+            total_time = 0
+            start = int(time.time()*1000)
+            f(*args, **kwargs)
+            end = int(time.time()*1000)
+
+            if end - start > 50:
+                logger.info(
+                    "Total time in get_room_members: %d ms / %d ms",
+                    int(total_time*1000),
+                    end - start
+                )
+        return g
+
+    reactor.runUntilCurrent = prof(reactor.runUntilCurrent)
+
     PROFILE_SYNAPSE = False
     if PROFILE_SYNAPSE:
         def profile(func):
diff --git a/synapse/handlers/room.py b/synapse/handlers/room.py
index 4bd027d9bb..bd1c20cb13 100644
--- a/synapse/handlers/room.py
+++ b/synapse/handlers/room.py
@@ -236,6 +236,8 @@ class RoomCreationHandler(BaseHandler):
             join_rules_event,
         ]
 
+import time
+total_time = 0
 
 class RoomMemberHandler(BaseHandler):
     # TODO(paul): This handler currently contains a messy conflation of
@@ -256,7 +258,14 @@ class RoomMemberHandler(BaseHandler):
     def get_room_members(self, room_id):
         users = yield self.store.get_users_in_room(room_id)
 
-        defer.returnValue([UserID.from_string(u) for u in users])
+        start = time.time()
+        users = [UserID.from_string(u) for u in users]
+        end = time.time()
+
+        global total_time
+        total_time += end-start
+
+        defer.returnValue(users)
 
     @defer.inlineCallbacks
     def fetch_room_distributions_into(self, room_id, localusers=None,