Fix server_name in logging context for multiple Synapse instances in one process

changelog.d/18868.misc

@@ -0,0 +1 @@
+Fix `server_name` in logging context for multiple Synapse instances in one process.

synapse/app/_base.py

@@ -599,7 +599,7 @@ def run_sighup(*args: Any, **kwargs: Any) -> None:
     hs.get_pusherpool().start()
 
     def log_shutdown() -> None:
-        with LoggingContext("log_shutdown"):
+        with LoggingContext(name="log_shutdown", server_name=server_name):
             logger.info("Shutting down...")
 
     # Log when we start the shut down process.

synapse/app/admin_cmd.py

@@ -329,7 +329,7 @@ def start(config: HomeServerConfig, args: argparse.Namespace) -> None:
     # command.
 
     async def run() -> None:
-        with LoggingContext(name="command"):
+        with LoggingContext(name="command", server_name=config.server.server_name):
             await _base.start(ss)
             await args.func(ss, args)
 
@@ -342,5 +342,5 @@ async def run() -> None:
 
 if __name__ == "__main__":
     homeserver_config, args = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config, args)

synapse/app/appservice.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/client_reader.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/event_creator.py

@@ -26,7 +26,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/federation_reader.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/federation_sender.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/frontend_proxy.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/generic_worker.py

@@ -386,7 +386,7 @@ async def start() -> None:
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/homeserver.py

@@ -429,7 +429,7 @@ def run(hs: HomeServer) -> None:
 def main() -> None:
     homeserver_config = load_or_generate_config(sys.argv[1:])
 
-    with LoggingContext("main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         # check base requirements
         check_requirements()
         hs = setup(homeserver_config)

synapse/app/media_repository.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/pusher.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/synchrotron.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/app/user_dir.py

@@ -27,7 +27,7 @@
 
 def main() -> None:
     homeserver_config = load_config(sys.argv[1:])
-    with LoggingContext(name="main"):
+    with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
         start(homeserver_config)
 
 

synapse/config/_base.py

@@ -601,7 +601,7 @@ def add_arguments_to_parser(cls, config_parser: argparse.ArgumentParser) -> None
 
     @classmethod
     def load_config_with_parser(
-        cls: Type[TRootConfig], parser: argparse.ArgumentParser, argv: List[str]
+        cls: Type[TRootConfig], parser: argparse.ArgumentParser, argv_options: List[str]
     ) -> Tuple[TRootConfig, argparse.Namespace]:
         """Parse the commandline and config files with the given parser
 
@@ -611,14 +611,14 @@ def load_config_with_parser(
 
         Args:
             parser
-            argv
+            argv_options: The options passed to Synapse. Usually `sys.argv[1:]`.
 
         Returns:
             Returns the parsed config object and the parsed argparse.Namespace
             object from parser.parse_args(..)`
         """
 
-        config_args = parser.parse_args(argv)
+        config_args = parser.parse_args(argv_options)
 
         config_files = find_config_files(search_paths=config_args.config_path)
         obj = cls(config_files)

synapse/config/logger.py

@@ -40,7 +40,6 @@
 )
 
 from synapse.logging.context import LoggingContextFilter
-from synapse.logging.filter import MetadataFilter
 from synapse.synapse_rust import reset_logging_config
 from synapse.types import JsonDict
 
@@ -213,13 +212,11 @@ def _setup_stdlib_logging(
     # writes.
 
     log_context_filter = LoggingContextFilter()
-    log_metadata_filter = MetadataFilter({"server_name": config.server.server_name})
     old_factory = logging.getLogRecordFactory()
 
     def factory(*args: Any, **kwargs: Any) -> logging.LogRecord:
         record = old_factory(*args, **kwargs)
         log_context_filter.filter(record)
-        log_metadata_filter.filter(record)
         return record
 
     logging.setLogRecordFactory(factory)

synapse/federation/federation_server.py

@@ -159,7 +159,7 @@ def __init__(self, hs: "HomeServer"):
         # with FederationHandlerRegistry.
         hs.get_directory_handler()
 
-        self._server_linearizer = Linearizer("fed_server")
+        self._server_linearizer = Linearizer(name="fed_server", clock=hs.get_clock())
 
         # origins that we are currently processing a transaction from.
         # a dict from origin to txn id.

synapse/handlers/appservice.py

@@ -98,7 +98,7 @@ def __init__(self, hs: "HomeServer"):
         self.is_processing = False
 
         self._ephemeral_events_linearizer = Linearizer(
-            name="appservice_ephemeral_events"
+            name="appservice_ephemeral_events", clock=hs.get_clock()
         )
 
     def notify_interested_services(self, max_token: RoomStreamToken) -> None:

synapse/handlers/device.py

@@ -1450,8 +1450,12 @@ def __init__(self, hs: "HomeServer", device_handler: DeviceWriterHandler):
         self.clock = hs.get_clock()  # nb must be called this for @measure_func
         self.device_handler = device_handler
 
-        self._remote_edu_linearizer = Linearizer(name="remote_device_list")
-        self._resync_linearizer = Linearizer(name="remote_device_resync")
+        self._remote_edu_linearizer = Linearizer(
+            name="remote_device_list", clock=self.clock
+        )
+        self._resync_linearizer = Linearizer(
+            name="remote_device_resync", clock=self.clock
+        )
 
         # user_id -> list of updates waiting to be handled.
         self._pending_updates: Dict[

synapse/handlers/e2e_keys.py

@@ -112,8 +112,7 @@ def __init__(self, hs: "HomeServer"):
 
         # Limit the number of in-flight requests from a single device.
         self._query_devices_linearizer = Linearizer(
-            name="query_devices",
-            max_count=10,
+            name="query_devices", max_count=10, clock=hs.get_clock()
         )
 
         self._query_appservices_for_otks = (
@@ -1765,7 +1764,9 @@ def __init__(self, hs: "HomeServer"):
         assert isinstance(device_handler, DeviceWriterHandler)
         self._device_handler = device_handler
 
-        self._remote_edu_linearizer = Linearizer(name="remote_signing_key")
+        self._remote_edu_linearizer = Linearizer(
+            name="remote_signing_key", clock=self.clock
+        )
 
         # user_id -> list of updates waiting to be handled.
         self._pending_updates: Dict[str, List[Tuple[JsonDict, JsonDict]]] = {}

synapse/handlers/federation.py

@@ -160,7 +160,7 @@ def __init__(self, hs: "HomeServer"):
         self._notifier = hs.get_notifier()
         self._worker_locks = hs.get_worker_locks_handler()
 
-        self._room_backfill = Linearizer("room_backfill")
+        self._room_backfill = Linearizer(name="room_backfill", clock=self.clock)
 
         self._third_party_event_rules = (
             hs.get_module_api_callbacks().third_party_event_rules
@@ -180,7 +180,8 @@ def __init__(self, hs: "HomeServer"):
         # When the lock is held for a given room, no other concurrent code may
         # partial state or un-partial state the room.
         self._is_partial_state_room_linearizer = Linearizer(
-            name="_is_partial_state_room_linearizer"
+            name="_is_partial_state_room_linearizer",
+            clock=self.clock,
         )
 
         # if this is the main process, fire off a background process to resume

synapse/handlers/federation_event.py

@@ -191,7 +191,7 @@ def __init__(self, hs: "HomeServer"):
         # federation event staging area.
         self.room_queues: Dict[str, List[Tuple[EventBase, str]]] = {}
 
-        self._room_pdu_linearizer = Linearizer("fed_room_pdu")
+        self._room_pdu_linearizer = Linearizer(name="fed_room_pdu", clock=self._clock)
 
     async def on_receive_pdu(self, origin: str, pdu: EventBase) -> None:
         """Process a PDU received via a federation /send/ transaction

synapse/handlers/message.py

@@ -513,7 +513,9 @@ def __init__(self, hs: "HomeServer"):
 
         # We limit concurrent event creation for a room to 1. This prevents state resolution
         # from occurring when sending bursts of events to a local room
-        self.limiter = Linearizer(max_count=1, name="room_event_creation_limit")
+        self.limiter = Linearizer(
+            max_count=1, name="room_event_creation_limit", clock=self.clock
+        )
 
         self._bulk_push_rule_evaluator = hs.get_bulk_push_rule_evaluator()
 

synapse/handlers/presence.py

@@ -872,7 +872,9 @@ def __init__(self, hs: "HomeServer"):
         ] = {}
         self.external_process_last_updated_ms: Dict[str, int] = {}
 
-        self.external_sync_linearizer = Linearizer(name="external_sync_linearizer")
+        self.external_sync_linearizer = Linearizer(
+            name="external_sync_linearizer", clock=self.clock
+        )
 
         if self._track_presence:
             # Start a LoopingCall in 30s that fires every 5s.

synapse/handlers/read_marker.py

@@ -36,7 +36,9 @@ class ReadMarkerHandler:
     def __init__(self, hs: "HomeServer"):
         self.store = hs.get_datastores().main
         self.account_data_handler = hs.get_account_data_handler()
-        self.read_marker_linearizer = Linearizer(name="read_marker")
+        self.read_marker_linearizer = Linearizer(
+            name="read_marker", clock=hs.get_clock()
+        )
 
     async def received_client_read_marker(
         self, room_id: str, user_id: str, event_id: str

synapse/handlers/room_member.py

@@ -114,8 +114,12 @@ def __init__(self, hs: "HomeServer"):
         if self.hs.config.server.include_profile_data_on_invite:
             self._membership_types_to_include_profile_data_in.add(Membership.INVITE)
 
-        self.member_linearizer: Linearizer = Linearizer(name="member")
-        self.member_as_limiter = Linearizer(max_count=10, name="member_as_limiter")
+        self.member_linearizer: Linearizer = Linearizer(
+            name="member", clock=hs.get_clock()
+        )
+        self.member_as_limiter = Linearizer(
+            max_count=10, name="member_as_limiter", clock=hs.get_clock()
+        )
 
         self.clock = hs.get_clock()
         self._spam_checker_module_callbacks = hs.get_module_api_callbacks().spam_checker

synapse/handlers/sync.py

@@ -980,7 +980,10 @@ def get_lazy_loaded_members_cache(
         )
         if cache is None:
             logger.debug("creating LruCache for %r", cache_key)
-            cache = LruCache(max_size=LAZY_LOADED_MEMBERS_CACHE_MAX_SIZE)
+            cache = LruCache(
+                max_size=LAZY_LOADED_MEMBERS_CACHE_MAX_SIZE,
+                server_name=self.server_name,
+            )
             self.lazy_loaded_members_cache[cache_key] = cache
         else:
             logger.debug("found LruCache for %r", cache_key)

synapse/http/federation/matrix_federation_agent.py

@@ -124,7 +124,7 @@ def __init__(
         # addresses, to prevent DNS rebinding.
         reactor = BlocklistingReactorWrapper(reactor, ip_allowlist, ip_blocklist)
 
-        self._clock = Clock(reactor)
+        self._clock = Clock(reactor, server_name=server_name)
         self._pool = HTTPConnectionPool(reactor)
         self._pool.retryAutomatically = False
         self._pool.maxPersistentPerHost = 5

synapse/http/federation/well_known_resolver.py

@@ -107,7 +107,7 @@ def __init__(
 
         self.server_name = server_name
         self._reactor = reactor
-        self._clock = Clock(reactor)
+        self._clock = Clock(reactor, server_name=server_name)
 
         if well_known_cache is None:
             well_known_cache = TTLCache(

synapse/http/matrixfederationclient.py

@@ -481,7 +481,9 @@ def __init__(
             use_proxy=True,
         )
 
-        self.remote_download_linearizer = Linearizer("remote_download_linearizer", 6)
+        self.remote_download_linearizer = Linearizer(
+            name="remote_download_linearizer", max_count=6, clock=self.clock
+        )
 
     def wake_destination(self, destination: str) -> None:
         """Called when the remote server may have come back online."""

synapse/http/server.py

@@ -411,8 +411,19 @@ def __init__(
         # Clock is optional as this class is exposed to the module API.
         clock: Optional[Clock] = None,
     ):
+        """
+        Args:
+            canonical_json: TODO
+            extract_context: TODO
+            clock: This is expected to be passed in by any Synapse code.
+                Only optional for the Module API.
+        """
+
         if clock is None:
-            clock = Clock(cast(ISynapseThreadlessReactor, reactor))
+            clock = Clock(
+                cast(ISynapseThreadlessReactor, reactor),
+                server_name="synapse_module_running_from_unknown_server",
+            )
 
         super().__init__(clock, extract_context)
         self.canonical_json = canonical_json
@@ -590,8 +601,17 @@ def __init__(
         # Clock is optional as this class is exposed to the module API.
         clock: Optional[Clock] = None,
     ):
+        """
+        Args:
+            extract_context: TODO
+            clock: This is expected to be passed in by any Synapse code.
+                Only optional for the Module API.
+        """
         if clock is None:
-            clock = Clock(cast(ISynapseThreadlessReactor, reactor))
+            clock = Clock(
+                cast(ISynapseThreadlessReactor, reactor),
+                server_name="synapse_module_running_from_unknown_server",
+            )
 
         super().__init__(clock, extract_context)