From ad48a64b71262c8df0b1bd712cac44769b4bea44 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 5 Apr 2022 16:12:03 +0100 Subject: [PATCH 1/4] Add opentracing spans to calls to external cache --- synapse/replication/tcp/external_cache.py | 25 +++++++++++++---------- 1 file changed, 14 insertions(+), 11 deletions(-) diff --git a/synapse/replication/tcp/external_cache.py b/synapse/replication/tcp/external_cache.py index bf7d017968f9..92cb1959a0ca 100644 --- a/synapse/replication/tcp/external_cache.py +++ b/synapse/replication/tcp/external_cache.py @@ -17,6 +17,7 @@ from prometheus_client import Counter, Histogram +from synapse.logging import opentracing from synapse.logging.context import make_deferred_yieldable from synapse.util import json_decoder, json_encoder @@ -93,14 +94,15 @@ 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) - 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, + with opentracing.start_active_span("ExternalCache.set"): + 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.""" @@ -108,10 +110,11 @@ async def get(self, cache_name: str, key: str) -> Optional[Any]: if self._redis_connection is None: return None - with response_timer.labels("get").time(): - result = await make_deferred_yieldable( - self._redis_connection.get(self._get_redis_key(cache_name, key)) - ) + with opentracing.start_active_span("ExternalCache.get"): + 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) From 18b1dffc5e4a841c8f83021945c735105cfbe03c Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 5 Apr 2022 16:14:22 +0100 Subject: [PATCH 2/4] Newsfile --- changelog.d/12380.misc | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/12380.misc diff --git a/changelog.d/12380.misc b/changelog.d/12380.misc new file mode 100644 index 000000000000..178a00321a16 --- /dev/null +++ b/changelog.d/12380.misc @@ -0,0 +1 @@ +Add opentracing spans to calls to external cache. From 10c065965e279f0b0497e9627a0dcfff967a23c8 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Wed, 6 Apr 2022 10:03:05 +0100 Subject: [PATCH 3/4] Add a tag with cache name --- synapse/logging/opentracing.py | 3 +++ synapse/replication/tcp/external_cache.py | 10 ++++++++-- 2 files changed, 11 insertions(+), 2 deletions(-) diff --git a/synapse/logging/opentracing.py b/synapse/logging/opentracing.py index 3ebed5c16130..f86ee9aac7a5 100644 --- a/synapse/logging/opentracing.py +++ b/synapse/logging/opentracing.py @@ -289,6 +289,9 @@ class SynapseTags: # Uniqueish ID of a database transaction DB_TXN_ID = "db.txn_id" + # The name of the external cache + CACHE_NAME = "cache.name" + class SynapseBaggage: FORCE_TRACING = "synapse-force-tracing" diff --git a/synapse/replication/tcp/external_cache.py b/synapse/replication/tcp/external_cache.py index 92cb1959a0ca..901149ffd147 100644 --- a/synapse/replication/tcp/external_cache.py +++ b/synapse/replication/tcp/external_cache.py @@ -94,7 +94,10 @@ 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) - with opentracing.start_active_span("ExternalCache.set"): + with opentracing.start_active_span( + "ExternalCache.set", + tags={opentracing.SynapseTags: cache_name}, + ): with response_timer.labels("set").time(): return await make_deferred_yieldable( self._redis_connection.set( @@ -110,7 +113,10 @@ async def get(self, cache_name: str, key: str) -> Optional[Any]: if self._redis_connection is None: return None - with opentracing.start_active_span("ExternalCache.get"): + with opentracing.start_active_span( + "ExternalCache.get", + tags={opentracing.SynapseTags: cache_name}, + ): with response_timer.labels("get").time(): result = await make_deferred_yieldable( self._redis_connection.get(self._get_redis_key(cache_name, key)) From 1dc71579d7c25ea2a49c688a6f997ef27799eccb Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Wed, 6 Apr 2022 13:13:52 +0100 Subject: [PATCH 4/4] Apply suggestions from code review Co-authored-by: Patrick Cloke --- synapse/replication/tcp/external_cache.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/synapse/replication/tcp/external_cache.py b/synapse/replication/tcp/external_cache.py index 901149ffd147..a448dd7eb148 100644 --- a/synapse/replication/tcp/external_cache.py +++ b/synapse/replication/tcp/external_cache.py @@ -96,7 +96,7 @@ async def set(self, cache_name: str, key: str, value: Any, expiry_ms: int) -> No with opentracing.start_active_span( "ExternalCache.set", - tags={opentracing.SynapseTags: cache_name}, + tags={opentracing.SynapseTags.CACHE_NAME: cache_name}, ): with response_timer.labels("set").time(): return await make_deferred_yieldable( @@ -115,7 +115,7 @@ async def get(self, cache_name: str, key: str) -> Optional[Any]: with opentracing.start_active_span( "ExternalCache.get", - tags={opentracing.SynapseTags: cache_name}, + tags={opentracing.SynapseTags.CACHE_NAME: cache_name}, ): with response_timer.labels("get").time(): result = await make_deferred_yieldable(