Refactor Histogram metrics to be homeserver-scoped

changelog.d/18724.misc

@@ -0,0 +1 @@
+Refactor `Histogram` metrics to be homeserver-scoped.

scripts-dev/mypy_synapse_plugin.py

@@ -61,6 +61,7 @@ def get_function_signature_hook(
     ) -> Optional[Callable[[FunctionSigContext], FunctionLike]]:
         if fullname in (
             "prometheus_client.metrics.Counter",
+            "prometheus_client.metrics.Histogram",
             "prometheus_client.metrics.Gauge",
             # TODO: Add other prometheus_client metrics that need checking as we
             # refactor, see https://github.com/element-hq/synapse/issues/18592

synapse/_scripts/review_recent_signups.py

@@ -29,19 +29,21 @@
 
 from synapse.config._base import (
     Config,
+    ConfigError,
     RootConfig,
     find_config_files,
     read_config_files,
 )
 from synapse.config.database import DatabaseConfig
+from synapse.config.server import ServerConfig
 from synapse.storage.database import DatabasePool, LoggingTransaction, make_conn
 from synapse.storage.engines import create_engine
 
 
 class ReviewConfig(RootConfig):
-    "A config class that just pulls out the database config"
+    "A config class that just pulls out the server and database config"
 
-    config_classes = [DatabaseConfig]
+    config_classes = [ServerConfig, DatabaseConfig]
 
 
 @attr.s(auto_attribs=True)
@@ -148,6 +150,10 @@ def main() -> None:
     config_dict = read_config_files(config_files)
     config.parse_config_dict(config_dict, "", "")
 
+    server_name = config.server.server_name
+    if not isinstance(server_name, str):
+        raise ConfigError("Must be a string", ("server_name",))
+
     since_ms = time.time() * 1000 - Config.parse_duration(config_args.since)
     exclude_users_with_email = config_args.exclude_emails
     exclude_users_with_appservice = config_args.exclude_app_service
@@ -159,7 +165,12 @@ def main() -> None:
 
     engine = create_engine(database_config.config)
 
-    with make_conn(database_config, engine, "review_recent_signups") as db_conn:
+    with make_conn(
+        db_config=database_config,
+        engine=engine,
+        default_txn_name="review_recent_signups",
+        server_name=server_name,
+    ) as db_conn:
         # This generates a type of Cursor, not LoggingTransaction.
         user_infos = get_recent_users(
             db_conn.cursor(),

synapse/_scripts/synapse_port_db.py

@@ -672,8 +672,14 @@ def build_db_store(
         engine = create_engine(db_config.config)
 
         hs = MockHomeserver(self.hs_config)
-
-        with make_conn(db_config, engine, "portdb") as db_conn:
+        server_name = hs.hostname
+
+        with make_conn(
+            db_config=db_config,
+            engine=engine,
+            default_txn_name="portdb",
+            server_name=server_name,
+        ) as db_conn:
             engine.check_database(
                 db_conn, allow_outdated_version=allow_outdated_version
             )

synapse/api/auth/msc3861_delegated.py

@@ -47,6 +47,7 @@
     inject_request_headers,
     start_active_span,
 )
+from synapse.metrics import SERVER_NAME_LABEL
 from synapse.synapse_rust.http_client import HttpClient
 from synapse.types import Requester, UserID, create_requester
 from synapse.util import json_decoder
@@ -62,7 +63,7 @@
 introspection_response_timer = Histogram(
     "synapse_api_auth_delegated_introspection_response",
     "Time taken to get a response for an introspection request",
-    ["code"],
+    labelnames=["code", SERVER_NAME_LABEL],
 )
 
 
@@ -341,17 +342,23 @@ async def _introspect_token(
                     )
         except HttpResponseException as e:
             end_time = self._clock.time()
-            introspection_response_timer.labels(e.code).observe(end_time - start_time)
+            introspection_response_timer.labels(
+                code=e.code, **{SERVER_NAME_LABEL: self.server_name}
+            ).observe(end_time - start_time)
             raise
         except Exception:
             end_time = self._clock.time()
-            introspection_response_timer.labels("ERR").observe(end_time - start_time)
+            introspection_response_timer.labels(
+                code="ERR", **{SERVER_NAME_LABEL: self.server_name}
+            ).observe(end_time - start_time)
             raise
 
         logger.debug("Fetched token from MAS")
 
         end_time = self._clock.time()
-        introspection_response_timer.labels(200).observe(end_time - start_time)
+        introspection_response_timer.labels(
+            code=200, **{SERVER_NAME_LABEL: self.server_name}
+        ).observe(end_time - start_time)
 
         resp = json_decoder.decode(resp_body.decode("utf-8"))
 

synapse/federation/federation_server.py

@@ -122,6 +122,7 @@
 pdu_process_time = Histogram(
     "synapse_federation_server_pdu_process_time",
     "Time taken to process an event",
+    labelnames=[SERVER_NAME_LABEL],
 )
 
 last_pdu_ts_metric = Gauge(
@@ -1324,9 +1325,9 @@ async def _process_incoming_pdus_in_room_inner(
                     origin, event.event_id
                 )
                 if received_ts is not None:
-                    pdu_process_time.observe(
-                        (self._clock.time_msec() - received_ts) / 1000
-                    )
+                    pdu_process_time.labels(
+                        **{SERVER_NAME_LABEL: self.server_name}
+                    ).observe((self._clock.time_msec() - received_ts) / 1000)
 
             next = await self._get_next_nonspam_staged_event_for_room(
                 room_id, room_version

synapse/federation/sender/__init__.py

@@ -667,7 +667,8 @@ async def handle_event(event: EventBase) -> None:
                         ts = event_to_received_ts[event.event_id]
                         assert ts is not None
                         synapse.metrics.event_processing_lag_by_event.labels(
-                            "federation_sender"
+                            name="federation_sender",
+                            **{SERVER_NAME_LABEL: self.server_name},
                         ).observe((now - ts) / 1000)
 
                 async def handle_room_events(events: List[EventBase]) -> None:

synapse/handlers/appservice.py

@@ -187,7 +187,8 @@ async def start_scheduler() -> None:
                         assert ts is not None
 
                         synapse.metrics.event_processing_lag_by_event.labels(
-                            "appservice_sender"
+                            name="appservice_sender",
+                            **{SERVER_NAME_LABEL: self.server_name},
                         ).observe((now - ts) / 1000)
 
                     async def handle_room_events(events: Iterable[EventBase]) -> None:

synapse/handlers/federation.py

@@ -71,6 +71,7 @@
 from synapse.http.servlet import assert_params_in_dict
 from synapse.logging.context import nested_logging_context
 from synapse.logging.opentracing import SynapseTags, set_tag, tag_args, trace
+from synapse.metrics import SERVER_NAME_LABEL
 from synapse.metrics.background_process_metrics import run_as_background_process
 from synapse.module_api import NOT_SPAM
 from synapse.storage.databases.main.events_worker import EventRedactBehaviour
@@ -90,7 +91,7 @@
 backfill_processing_before_timer = Histogram(
     "synapse_federation_backfill_processing_before_time_seconds",
     "sec",
-    [],
+    labelnames=[SERVER_NAME_LABEL],
     buckets=(
         0.1,
         0.5,
@@ -533,9 +534,9 @@ async def try_backfill(domains: StrCollection) -> bool:
         # backfill points regardless of `current_depth`.
         if processing_start_time is not None:
             processing_end_time = self.clock.time_msec()
-            backfill_processing_before_timer.observe(
-                (processing_end_time - processing_start_time) / 1000
-            )
+            backfill_processing_before_timer.labels(
+                **{SERVER_NAME_LABEL: self.server_name}
+            ).observe((processing_end_time - processing_start_time) / 1000)
 
         success = await try_backfill(likely_domains)
         if success:

synapse/handlers/federation_event.py

@@ -113,7 +113,7 @@
 backfill_processing_after_timer = Histogram(
     "synapse_federation_backfill_processing_after_time_seconds",
     "sec",
-    [],
+    labelnames=[SERVER_NAME_LABEL],
     buckets=(
         0.1,
         0.25,
@@ -692,7 +692,9 @@ async def backfill(
         if not events:
             return
 
-        with backfill_processing_after_timer.time():
+        with backfill_processing_after_timer.labels(
+            **{SERVER_NAME_LABEL: self.server_name}
+        ).time():
             # if there are any events in the wrong room, the remote server is buggy and
             # should not be trusted.
             for ev in events:

synapse/handlers/sliding_sync/__init__.py

@@ -38,6 +38,7 @@
     tag_args,
     trace,
 )
+from synapse.metrics import SERVER_NAME_LABEL
 from synapse.storage.databases.main.roommember import extract_heroes_from_room_summary
 from synapse.storage.databases.main.state_deltas import StateDelta
 from synapse.storage.databases.main.stream import PaginateFunction
@@ -79,7 +80,7 @@
 sync_processing_time = Histogram(
     "synapse_sliding_sync_processing_time",
     "Time taken to generate a sliding sync response, ignoring wait times.",
-    ["initial"],
+    labelnames=["initial", SERVER_NAME_LABEL],
 )
 
 # Limit the number of state_keys we should remember sending down the connection for each
@@ -94,6 +95,7 @@
 
 class SlidingSyncHandler:
     def __init__(self, hs: "HomeServer"):
+        self.server_name = hs.hostname
         self.clock = hs.get_clock()
         self.store = hs.get_datastores().main
         self.storage_controllers = hs.get_storage_controllers()
@@ -368,9 +370,9 @@ async def handle_room(room_id: str) -> None:
         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
-        )
+        sync_processing_time.labels(
+            initial=from_token is not None, **{SERVER_NAME_LABEL: self.server_name}
+        ).observe(end_time_s - start_time_s)
 
         return sliding_sync_result
 

synapse/http/request_metrics.py

@@ -240,9 +240,11 @@ def stop(self, time_sec: float, response_code: int, sent_bytes: int) -> None:
 
         response_count.labels(**response_base_labels).inc()
 
-        response_timer.labels(code=response_code_str, **response_base_labels).observe(
-            time_sec - self.start_ts
-        )
+        response_timer.labels(
+            code=response_code_str,
+            **response_base_labels,
+            **{SERVER_NAME_LABEL: self.our_server_name},
+        ).observe(time_sec - self.start_ts)
 
         resource_usage = context.get_resource_usage()
 

synapse/metrics/__init__.py

@@ -583,7 +583,7 @@ def collect(self) -> Iterable[Metric]:
 event_processing_lag_by_event = Histogram(
     "synapse_event_processing_lag_by_event",
     "Time between an event being persisted and it being queued up to be sent to the relevant remote servers",
-    ["name"],
+    labelnames=["name", SERVER_NAME_LABEL],
 )
 
 # Build info of the running server.
@@ -607,7 +607,7 @@ def collect(self) -> Iterable[Metric]:
     " there is a request with try count of 4, then there would have been one"
     " each for 1, 2 and 3",
     buckets=(1, 2, 3, 4, 5, 10),
-    labelnames=("type", "reason"),
+    labelnames=("type", "reason", SERVER_NAME_LABEL),
 )
 
 threadpool_total_threads = Gauge(

synapse/metrics/_gc.py

@@ -54,9 +54,9 @@
 # Python GC metrics
 #
 
-# This is a process-level metric, so it does not have the `SERVER_NAME_LABEL`.
+# These are process-level metrics, so they do not have the `SERVER_NAME_LABEL`.
 gc_unreachable = Gauge("python_gc_unreachable_total", "Unreachable GC objects", ["gen"])  # type: ignore[missing-server-name-label]
-gc_time = Histogram(
+gc_time = Histogram(  # type: ignore[missing-server-name-label]
     "python_gc_time",
     "Time taken to GC (sec)",
     ["gen"],

synapse/metrics/_reactor_metrics.py

@@ -62,7 +62,8 @@ class PollReactor:  # type: ignore[no-redef]
 # Twisted reactor metrics
 #
 
-tick_time = Histogram(
+# This is a process-level metric, so it does not have the `SERVER_NAME_LABEL`.
+tick_time = Histogram(  # type: ignore[missing-server-name-label]
     "python_twisted_reactor_tick_time",
     "Tick time of the Twisted reactor (sec)",
     buckets=[0.001, 0.002, 0.005, 0.01, 0.025, 0.05, 0.1, 0.2, 0.5, 1, 2, 5],

synapse/replication/tcp/external_cache.py

@@ -49,7 +49,7 @@
 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"],
+    labelnames=["method", SERVER_NAME_LABEL],
     buckets=(
         0.001,
         0.002,
@@ -110,7 +110,9 @@ async def set(self, cache_name: str, key: str, value: Any, expiry_ms: int) -> No
             "ExternalCache.set",
             tags={opentracing.SynapseTags.CACHE_NAME: cache_name},
         ):
-            with response_timer.labels("set").time():
+            with response_timer.labels(
+                method="set", **{SERVER_NAME_LABEL: self.server_name}
+            ).time():
                 return await make_deferred_yieldable(
                     self._redis_connection.set(
                         self._get_redis_key(cache_name, key),
@@ -129,7 +131,9 @@ async def get(self, cache_name: str, key: str) -> Optional[Any]:
             "ExternalCache.get",
             tags={opentracing.SynapseTags.CACHE_NAME: cache_name},
         ):
-            with response_timer.labels("get").time():
+            with response_timer.labels(
+                method="get", **{SERVER_NAME_LABEL: self.server_name}
+            ).time():
                 result = await make_deferred_yieldable(
                     self._redis_connection.get(self._get_redis_key(cache_name, key))
                 )