Skip to content

Commit 5143f93

Browse files
Fix server_name in logging context for multiple Synapse instances in one process (#18868)
### Background As part of Element's plan to support a light form of vhosting (virtual host) (multiple instances of Synapse in the same Python process), we're currently diving into the details and implications of running multiple instances of Synapse in the same Python process. "Per-tenant logging" tracked internally by element-hq/synapse-small-hosts#48 ### Prior art Previously, we exposed `server_name` by providing a static logging `MetadataFilter` that injected the values: https://github.com/element-hq/synapse/blob/205d9e4fc4774850f34971469ae500e70119d17a/synapse/config/logger.py#L216 While this can work fine for the normal case of one Synapse instance per Python process, this configures things globally and isn't compatible when we try to start multiple Synapse instances because each subsequent tenant will overwrite the previous tenant. ### What does this PR do? We remove the `MetadataFilter` and replace it by tracking the `server_name` in the `LoggingContext` and expose it with our existing [`LoggingContextFilter`](https://github.com/element-hq/synapse/blob/205d9e4fc4774850f34971469ae500e70119d17a/synapse/logging/context.py#L584-L622) that we already use to expose information about the `request`. This means that the `server_name` value follows wherever we log as expected even when we have multiple Synapse instances running in the same process. ### A note on logcontext Anywhere, Synapse mistakenly uses the `sentinel` logcontext to log something, we won't know which server sent the log. We've been fixing up `sentinel` logcontext usage as tracked by #18905 Any further `sentinel` logcontext usage we find in the future can be fixed piecemeal as normal. https://github.com/element-hq/synapse/blob/d2a966f922fdc95bc86f7fe55b7b54a9ab3f25c1/docs/log_contexts.md#L71-L81 ### Testing strategy 1. Adjust your logging config to include `%(server_name)s` in the format ```yaml formatters: precise: format: '%(asctime)s - %(server_name)s - %(name)s - %(lineno)d - %(levelname)s - %(request)s - %(message)s' ``` 1. Start Synapse: `poetry run synapse_homeserver --config-path homeserver.yaml` 1. Make some requests (`curl http://localhost:8008/_matrix/client/versions`, etc) 1. Open the homeserver logs and notice the `server_name` in the logs as expected. `unknown_server_from_sentinel_context` is expected for the `sentinel` logcontext (things outside of Synapse).
1 parent 2f2b854 commit 5143f93

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

72 files changed

+433
-315
lines changed

changelog.d/18868.misc

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Fix `server_name` in logging context for multiple Synapse instances in one process.

synapse/app/_base.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -599,7 +599,7 @@ def run_sighup(*args: Any, **kwargs: Any) -> None:
599599
hs.get_pusherpool().start()
600600

601601
def log_shutdown() -> None:
602-
with LoggingContext("log_shutdown"):
602+
with LoggingContext(name="log_shutdown", server_name=server_name):
603603
logger.info("Shutting down...")
604604

605605
# Log when we start the shut down process.

synapse/app/admin_cmd.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -329,7 +329,7 @@ def start(config: HomeServerConfig, args: argparse.Namespace) -> None:
329329
# command.
330330

331331
async def run() -> None:
332-
with LoggingContext(name="command"):
332+
with LoggingContext(name="command", server_name=config.server.server_name):
333333
await _base.start(ss)
334334
await args.func(ss, args)
335335

@@ -342,5 +342,5 @@ async def run() -> None:
342342

343343
if __name__ == "__main__":
344344
homeserver_config, args = load_config(sys.argv[1:])
345-
with LoggingContext(name="main"):
345+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
346346
start(homeserver_config, args)

synapse/app/appservice.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@
2727

2828
def main() -> None:
2929
homeserver_config = load_config(sys.argv[1:])
30-
with LoggingContext(name="main"):
30+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
3131
start(homeserver_config)
3232

3333

synapse/app/client_reader.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@
2727

2828
def main() -> None:
2929
homeserver_config = load_config(sys.argv[1:])
30-
with LoggingContext(name="main"):
30+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
3131
start(homeserver_config)
3232

3333

synapse/app/event_creator.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -26,7 +26,7 @@
2626

2727
def main() -> None:
2828
homeserver_config = load_config(sys.argv[1:])
29-
with LoggingContext(name="main"):
29+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
3030
start(homeserver_config)
3131

3232

synapse/app/federation_reader.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@
2727

2828
def main() -> None:
2929
homeserver_config = load_config(sys.argv[1:])
30-
with LoggingContext(name="main"):
30+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
3131
start(homeserver_config)
3232

3333

synapse/app/federation_sender.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@
2727

2828
def main() -> None:
2929
homeserver_config = load_config(sys.argv[1:])
30-
with LoggingContext(name="main"):
30+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
3131
start(homeserver_config)
3232

3333

synapse/app/frontend_proxy.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@
2727

2828
def main() -> None:
2929
homeserver_config = load_config(sys.argv[1:])
30-
with LoggingContext(name="main"):
30+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
3131
start(homeserver_config)
3232

3333

synapse/app/generic_worker.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -386,7 +386,7 @@ async def start() -> None:
386386

387387
def main() -> None:
388388
homeserver_config = load_config(sys.argv[1:])
389-
with LoggingContext(name="main"):
389+
with LoggingContext(name="main", server_name=homeserver_config.server.server_name):
390390
start(homeserver_config)
391391

392392

0 commit comments

Comments
 (0)