From 10428046e4afd10bb53dc86528bda550527e8572 Mon Sep 17 00:00:00 2001
From: Erik Johnston <erikj@element.io>
Date: Tue, 20 Aug 2024 12:36:49 +0100
Subject: [PATCH] Add metrics for sliding sync processing time (#17593)

This should let us see how quickly we actually process things in
practice.
---
 changelog.d/17593.misc           |  1 +
 synapse/handlers/sliding_sync.py | 15 +++++++++++++++
 2 files changed, 16 insertions(+)
 create mode 100644 changelog.d/17593.misc

diff --git a/changelog.d/17593.misc b/changelog.d/17593.misc
new file mode 100644
index 000000000..60afc284b
--- /dev/null
+++ b/changelog.d/17593.misc
@@ -0,0 +1 @@
+Add histogram metrics for sliding sync processing time.
diff --git a/synapse/handlers/sliding_sync.py b/synapse/handlers/sliding_sync.py
index c7c81b155..14d0ecbe1 100644
--- a/synapse/handlers/sliding_sync.py
+++ b/synapse/handlers/sliding_sync.py
@@ -45,6 +45,7 @@ from typing import (
 
 import attr
 from immutabledict import immutabledict
+from prometheus_client import Histogram
 from typing_extensions import assert_never
 
 from synapse.api.constants import (
@@ -104,6 +105,13 @@ if TYPE_CHECKING:
 logger = logging.getLogger(__name__)
 
 
+sync_processing_time = Histogram(
+    "synapse_sliding_sync_processing_time",
+    "Time taken to generate a sliding sync response, ignoring wait times.",
+    ["initial"],
+)
+
+
 class Sentinel(enum.Enum):
     # defining a sentinel in this way allows mypy to correctly handle the
     # type of a dictionary lookup and subsequent type narrowing.
@@ -571,6 +579,8 @@ class SlidingSyncHandler:
             from_token: The point in the stream to sync from. Token of the end of the
                 previous batch. May be `None` if this is the initial sync request.
         """
+        start_time_s = self.clock.time()
+
         user_id = sync_config.user.to_string()
         app_service = self.store.get_app_service_by_user_id(user_id)
         if app_service:
@@ -934,6 +944,11 @@ class SlidingSyncHandler:
         set_tag(SynapseTags.RESULT_PREFIX + "result", bool(sliding_sync_result))
         set_tag(SynapseTags.FUNC_ARG_PREFIX + "sync_config.user", user_id)
 
+        end_time_s = self.clock.time()
+        sync_processing_time.labels(from_token is not None).observe(
+            end_time_s - start_time_s
+        )
+
         return sliding_sync_result
 
     @trace