Time external cache response time (#9904)

Author: erikjohnston

changelog.d/9904.misc

@@ -0,0 +1 @@
+Time response time for external cache requests.

synapse/replication/tcp/external_cache.py

@@ -15,7 +15,7 @@
 import logging
 from typing import TYPE_CHECKING, Any, Optional
 
-from prometheus_client import Counter
+from prometheus_client import Counter, Histogram
 
 from synapse.logging.context import make_deferred_yieldable
 from synapse.util import json_decoder, json_encoder
@@ -35,6 +35,20 @@
     labelnames=["cache_name", "hit"],
 )
 
+response_timer = Histogram(
+    "synapse_external_cache_response_time_seconds",
+    "Time taken to get a response from Redis for a cache get/set request",
+    labelnames=["method"],
+    buckets=(
+        0.001,
+        0.002,
+        0.005,
+        0.01,
+        0.02,
+        0.05,
+    ),
+)
+
 
 logger = logging.getLogger(__name__)
 
@@ -72,23 +86,25 @@ async def set(self, cache_name: str, key: str, value: Any, expiry_ms: int) -> No
 
         logger.debug("Caching %s %s: %r", cache_name, key, encoded_value)
 
-        return await make_deferred_yieldable(
-            self._redis_connection.set(
-                self._get_redis_key(cache_name, key),
-                encoded_value,
-                pexpire=expiry_ms,
+        with response_timer.labels("set").time():
+            return await make_deferred_yieldable(
+                self._redis_connection.set(
+                    self._get_redis_key(cache_name, key),
+                    encoded_value,
+                    pexpire=expiry_ms,
+                )
             )
-        )
 
     async def get(self, cache_name: str, key: str) -> Optional[Any]:
         """Look up a key/value in the named cache."""
 
         if self._redis_connection is None:
             return None
 
-        result = await make_deferred_yieldable(
-            self._redis_connection.get(self._get_redis_key(cache_name, key))
-        )
+        with response_timer.labels("get").time():
+            result = await make_deferred_yieldable(
+                self._redis_connection.get(self._get_redis_key(cache_name, key))
+            )
 
         logger.debug("Got cache result %s %s: %r", cache_name, key, result)