From 15eb781f80c84fd71a964a123d79ff5f9c59e646 Mon Sep 17 00:00:00 2001
From: Will Hunt <will@half-shot.uk>
Date: Wed, 20 Mar 2019 16:04:08 +0000
Subject: [PATCH] Log over appservice push path

---
 synapse/handlers/appservice.py | 4 ++++
 synapse/handlers/message.py    | 1 +
 synapse/notifier.py            | 4 ++++
 3 files changed, 9 insertions(+)

diff --git a/synapse/handlers/appservice.py b/synapse/handlers/appservice.py
index 17eedf4dbf..37d13c2cf9 100644
--- a/synapse/handlers/appservice.py
+++ b/synapse/handlers/appservice.py
@@ -61,12 +61,15 @@ class ApplicationServicesHandler(object):
         Args:
             current_id(int): The current maximum ID.
         """
+        logger.info("call notify_interested_services")
         services = self.store.get_app_services()
         if not services or not self.notify_appservices:
+            logger.info("ret not services or not self.notify_appservices")
             return
 
         self.current_max = max(self.current_max, current_id)
         if self.is_processing:
+            logger.info("ret self.is_processing")
             return
 
         with Measure(self.clock, "notify_interested_services"):
@@ -79,6 +82,7 @@ class ApplicationServicesHandler(object):
                     )
 
                     if not events:
+                        logger.info("ret not events")
                         break
 
                     events_by_room = {}
diff --git a/synapse/handlers/message.py b/synapse/handlers/message.py
index c762b58902..5907883c14 100644
--- a/synapse/handlers/message.py
+++ b/synapse/handlers/message.py
@@ -782,6 +782,7 @@ class EventCreationHandler(object):
 
         def _notify():
             try:
+                logger.info("call _notify")
                 self.notifier.on_new_room_event(
                     event, event_stream_id, max_stream_id,
                     extra_users=extra_users
diff --git a/synapse/notifier.py b/synapse/notifier.py
index ff589660da..f30597ce6f 100644
--- a/synapse/notifier.py
+++ b/synapse/notifier.py
@@ -222,6 +222,7 @@ class Notifier(object):
         until all previous events have been persisted before notifying
         the client streams.
         """
+        logger.info("call on_new_room_event")
         self.pending_new_room_events.append((
             room_stream_id, event, extra_users
         ))
@@ -236,6 +237,7 @@ class Notifier(object):
             max_room_stream_id(int): The highest stream_id below which all
                 events have been persisted.
         """
+        logger.info("call _notify_pending_new_room_events")
         pending = self.pending_new_room_events
         self.pending_new_room_events = []
         for room_stream_id, event, extra_users in pending:
@@ -249,6 +251,7 @@ class Notifier(object):
     def _on_new_room_event(self, event, room_stream_id, extra_users=[]):
         """Notify any user streams that are interested in this room event"""
         # poke any interested application service.
+        logger.info("call _on_new_room_event")
         run_as_background_process(
             "notify_app_services",
             self._notify_app_services, room_stream_id,
@@ -268,6 +271,7 @@ class Notifier(object):
 
     @defer.inlineCallbacks
     def _notify_app_services(self, room_stream_id):
+        logger.info("call _notify_app_services")
         try:
             yield self.appservice_handler.notify_interested_services(room_stream_id)
         except Exception: