From fbdeb63bc9233d5e4b7970534a9cbb41be65cb6b Mon Sep 17 00:00:00 2001 From: Tim Abbott Date: Mon, 6 Feb 2017 17:51:58 -0800 Subject: [PATCH] tornado: Add debug logging for time consumed processing an event. I've occasionally found this logging helpful. --- zerver/tornado/event_queue.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/zerver/tornado/event_queue.py b/zerver/tornado/event_queue.py index 579c23ce50..dd6b3c5ca5 100644 --- a/zerver/tornado/event_queue.py +++ b/zerver/tornado/event_queue.py @@ -907,6 +907,7 @@ def process_notification(notice): # type: (Mapping[str, Any]) -> None event = notice['event'] # type: Mapping[str, Any] users = notice['users'] # type: Union[Iterable[int], Iterable[Mapping[str, Any]]] + start_time = time.time() if event['type'] == "message": process_message_event(event, cast(Iterable[Mapping[str, Any]], users)) elif event['type'] == "update_message": @@ -915,6 +916,8 @@ def process_notification(notice): process_userdata_event(event, cast(Iterable[Mapping[str, Any]], users)) else: process_event(event, cast(Iterable[int], users)) + logging.debug("Tornado: Event %s for %s users took %sms" % ( + event['type'], len(users), int(1000 * (time.time() - start_time)))) # Runs in the Django process to send a notification to Tornado. #