From d802c7c28200de8dceae8fcab441048c66d3ce68 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 29 Jun 2023 13:57:36 -0500 Subject: [PATCH 1/3] Add tracing to media `/upload` To investigate https://github.com/matrix-org/synapse/issues/15841 --- synapse/media/media_repository.py | 2 ++ synapse/media/media_storage.py | 6 ++++++ synapse/media/storage_provider.py | 4 ++++ synapse/media/thumbnailer.py | 3 +++ synapse/module_api/callbacks/spamchecker_callbacks.py | 1 + synapse/storage/databases/main/media_repository.py | 4 ++++ 6 files changed, 20 insertions(+) diff --git a/synapse/media/media_repository.py b/synapse/media/media_repository.py index e81c987b10be..ea97c9a37ee4 100644 --- a/synapse/media/media_repository.py +++ b/synapse/media/media_repository.py @@ -174,6 +174,7 @@ def mark_recently_accessed(self, server_name: Optional[str], media_id: str) -> N else: self.recently_accessed_locals.add(media_id) + @trace async def create_content( self, media_type: str, @@ -710,6 +711,7 @@ async def generate_remote_exact_thumbnail( # Could not generate thumbnail. return None + @trace async def _generate_thumbnails( self, server_name: Optional[str], diff --git a/synapse/media/media_storage.py b/synapse/media/media_storage.py index a819d954070a..70da696e7c4c 100644 --- a/synapse/media/media_storage.py +++ b/synapse/media/media_storage.py @@ -76,6 +76,7 @@ def __init__( self._spam_checker_module_callbacks = hs.get_module_api_callbacks().spam_checker self.clock = hs.get_clock() + @trace async def store_file(self, source: IO, file_info: FileInfo) -> str: """Write `source` to the on disk media store, and also any other configured storage providers @@ -95,10 +96,12 @@ async def store_file(self, source: IO, file_info: FileInfo) -> str: return fname + @trace async def write_to_file(self, source: IO, output: IO) -> None: """Asynchronously write the `source` to `output`.""" await defer_to_thread(self.reactor, _write_file_synchronously, source, output) + @trace @contextlib.contextmanager def store_into_file( self, file_info: FileInfo @@ -214,6 +217,7 @@ async def fetch_media(self, file_info: FileInfo) -> Optional[Responder]: return None + @trace async def ensure_media_is_in_local_cache(self, file_info: FileInfo) -> str: """Ensures that the given file is in the local cache. Attempts to download it from storage providers if it isn't. @@ -259,6 +263,7 @@ async def ensure_media_is_in_local_cache(self, file_info: FileInfo) -> str: raise NotFoundError() + @trace def _file_info_to_path(self, file_info: FileInfo) -> str: """Converts file_info into a relative path. @@ -301,6 +306,7 @@ def _file_info_to_path(self, file_info: FileInfo) -> str: return self.filepaths.local_media_filepath_rel(file_info.file_id) +@trace def _write_file_synchronously(source: IO, dest: IO) -> None: """Write `source` to the file like `dest` synchronously. Should be called from a thread. diff --git a/synapse/media/storage_provider.py b/synapse/media/storage_provider.py index 1c9b71d69c77..06e235803c56 100644 --- a/synapse/media/storage_provider.py +++ b/synapse/media/storage_provider.py @@ -86,6 +86,7 @@ def __init__( def __str__(self) -> str: return "StorageProviderWrapper[%s]" % (self.backend,) + @trace async def store_file(self, path: str, file_info: FileInfo) -> None: if not file_info.server_name and not self.store_local: return None @@ -114,6 +115,7 @@ async def store() -> None: run_in_background(store) + @trace async def fetch(self, path: str, file_info: FileInfo) -> Optional[Responder]: if file_info.url_cache: # Files in the URL preview cache definitely aren't stored here, @@ -141,6 +143,7 @@ def __init__(self, hs: "HomeServer", config: str): def __str__(self) -> str: return "FileStorageProviderBackend[%s]" % (self.base_directory,) + @trace async def store_file(self, path: str, file_info: FileInfo) -> None: """See StorageProvider.store_file""" @@ -159,6 +162,7 @@ async def store_file(self, path: str, file_info: FileInfo) -> None: backup_fname, ) + @trace async def fetch(self, path: str, file_info: FileInfo) -> Optional[Responder]: """See StorageProvider.fetch""" diff --git a/synapse/media/thumbnailer.py b/synapse/media/thumbnailer.py index f909a4fb9a19..de5a5aa50fb0 100644 --- a/synapse/media/thumbnailer.py +++ b/synapse/media/thumbnailer.py @@ -82,6 +82,7 @@ def __init__(self, input_path: str): # A lot of parsing errors can happen when parsing EXIF logger.info("Error parsing image EXIF information: %s", e) + @trace def transpose(self) -> Tuple[int, int]: """Transpose the image using its EXIF Orientation tag @@ -133,6 +134,7 @@ def _resize(self, width: int, height: int) -> Image.Image: self.image = self.image.convert("RGB") return self.image.resize((width, height), Image.ANTIALIAS) + @trace def scale(self, width: int, height: int, output_type: str) -> BytesIO: """Rescales the image to the given dimensions. @@ -142,6 +144,7 @@ def scale(self, width: int, height: int, output_type: str) -> BytesIO: with self._resize(width, height) as scaled: return self._encode_image(scaled, output_type) + @trace def crop(self, width: int, height: int, output_type: str) -> BytesIO: """Rescales and crops the image to the given dimensions preserving aspect:: diff --git a/synapse/module_api/callbacks/spamchecker_callbacks.py b/synapse/module_api/callbacks/spamchecker_callbacks.py index 7cee442145b9..e19145032389 100644 --- a/synapse/module_api/callbacks/spamchecker_callbacks.py +++ b/synapse/module_api/callbacks/spamchecker_callbacks.py @@ -788,6 +788,7 @@ async def check_registration_for_spam( return RegistrationBehaviour.ALLOW + @trace async def check_media_file_for_spam( self, file_wrapper: ReadableFileWrapper, file_info: FileInfo ) -> Union[Tuple[Codes, dict], Literal["NOT_SPAM"]]: diff --git a/synapse/storage/databases/main/media_repository.py b/synapse/storage/databases/main/media_repository.py index fa8be214ce90..aa256ebe653a 100644 --- a/synapse/storage/databases/main/media_repository.py +++ b/synapse/storage/databases/main/media_repository.py @@ -328,6 +328,7 @@ def _get_local_media_ids_txn(txn: LoggingTransaction) -> List[str]: "get_local_media_ids", _get_local_media_ids_txn ) + @trace async def store_local_media( self, media_id: str, @@ -447,6 +448,7 @@ async def get_local_media_thumbnails(self, media_id: str) -> List[Dict[str, Any] desc="get_local_media_thumbnails", ) + @trace async def store_local_thumbnail( self, media_id: str, @@ -568,6 +570,7 @@ async def get_remote_media_thumbnails( desc="get_remote_media_thumbnails", ) + @trace async def get_remote_media_thumbnail( self, origin: str, @@ -599,6 +602,7 @@ async def get_remote_media_thumbnail( desc="get_remote_media_thumbnail", ) + @trace async def store_remote_media_thumbnail( self, origin: str, From 5d9a10ff29d83a95a83639cb61852f0ce427f982 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 29 Jun 2023 13:59:55 -0500 Subject: [PATCH 2/3] Add changelog --- changelog.d/15850.misc | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/15850.misc diff --git a/changelog.d/15850.misc b/changelog.d/15850.misc new file mode 100644 index 000000000000..0e49ab23fed3 --- /dev/null +++ b/changelog.d/15850.misc @@ -0,0 +1 @@ +Add tracing to media `/upload` code paths. From df7e5cb5daf6127682e85046588dd9fbec7af012 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 29 Jun 2023 14:04:31 -0500 Subject: [PATCH 3/3] Add imports --- synapse/media/media_repository.py | 1 + synapse/media/media_storage.py | 1 + synapse/media/storage_provider.py | 1 + synapse/media/thumbnailer.py | 2 ++ synapse/storage/databases/main/media_repository.py | 1 + 5 files changed, 6 insertions(+) diff --git a/synapse/media/media_repository.py b/synapse/media/media_repository.py index ea97c9a37ee4..4b750c700b89 100644 --- a/synapse/media/media_repository.py +++ b/synapse/media/media_repository.py @@ -35,6 +35,7 @@ from synapse.config.repository import ThumbnailRequirement from synapse.http.site import SynapseRequest from synapse.logging.context import defer_to_thread +from synapse.logging.opentracing import trace from synapse.media._base import ( FileInfo, Responder, diff --git a/synapse/media/media_storage.py b/synapse/media/media_storage.py index 70da696e7c4c..eebcbc48e8c9 100644 --- a/synapse/media/media_storage.py +++ b/synapse/media/media_storage.py @@ -38,6 +38,7 @@ from synapse.api.errors import NotFoundError from synapse.logging.context import defer_to_thread, make_deferred_yieldable +from synapse.logging.opentracing import trace from synapse.util import Clock from synapse.util.file_consumer import BackgroundFileConsumer diff --git a/synapse/media/storage_provider.py b/synapse/media/storage_provider.py index 06e235803c56..0aea3a7a0d87 100644 --- a/synapse/media/storage_provider.py +++ b/synapse/media/storage_provider.py @@ -20,6 +20,7 @@ from synapse.config._base import Config from synapse.logging.context import defer_to_thread, run_in_background +from synapse.logging.opentracing import trace from synapse.util.async_helpers import maybe_awaitable from ._base import FileInfo, Responder diff --git a/synapse/media/thumbnailer.py b/synapse/media/thumbnailer.py index de5a5aa50fb0..2ab792ac2478 100644 --- a/synapse/media/thumbnailer.py +++ b/synapse/media/thumbnailer.py @@ -19,6 +19,8 @@ from PIL import Image +from synapse.logging.opentracing import trace + logger = logging.getLogger(__name__) EXIF_ORIENTATION_TAG = 0x0112 diff --git a/synapse/storage/databases/main/media_repository.py b/synapse/storage/databases/main/media_repository.py index aa256ebe653a..8cebeb51893e 100644 --- a/synapse/storage/databases/main/media_repository.py +++ b/synapse/storage/databases/main/media_repository.py @@ -27,6 +27,7 @@ ) from synapse.api.constants import Direction +from synapse.logging.opentracing import trace from synapse.storage._base import SQLBaseStore from synapse.storage.database import ( DatabasePool,