Skip to content

Commit 41a2762

Browse files
Be mindful of other logging context filters in 3rd-party code (#19068)
Be mindful that Synapse can be run alongside other code in the same Python process. We shouldn't overwrite fields on given log record unless we know it's relevant to Synapse. (no clobber) ### 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
1 parent 3ccc518 commit 41a2762

File tree

2 files changed

+37
-4
lines changed

2 files changed

+37
-4
lines changed

changelog.d/19068.misc

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Be mindful of other logging context filters in 3rd-party code and avoid overwriting log record fields unless we know the log record is relevant to Synapse.

synapse/logging/context.py

Lines changed: 36 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -604,25 +604,57 @@ def __init__(
604604
self._default_request = request
605605

606606
def filter(self, record: logging.LogRecord) -> Literal[True]:
607-
"""Add each fields from the logging contexts to the record.
607+
"""
608+
Add each field from the logging context to the record.
609+
610+
Please be mindful of 3rd-party code outside of Synapse (like in the case of
611+
Synapse Pro for small hosts) as this is running as a global log record filter.
612+
Other code may have set their own attributes on the record and the log record
613+
may not be relevant to Synapse at all so we should not mangle it.
614+
615+
We can have some defaults but we should avoid overwriting existing attributes on
616+
any log record unless we actually have a Synapse logcontext (not just the
617+
default sentinel logcontext).
618+
608619
Returns:
609620
True to include the record in the log output.
610621
"""
611622
context = current_context()
612623
record.request = self._default_request
613-
record.server_name = "unknown_server_from_no_context"
624+
625+
# Avoid overwriting an existing `server_name` on the record. This is running in
626+
# the context of a global log record filter so there may be 3rd-party code that
627+
# adds their own `server_name` and we don't want to interfere with that
628+
# (clobber).
629+
if not hasattr(record, "server_name"):
630+
record.server_name = "unknown_server_from_no_logcontext"
614631

615632
# context should never be None, but if it somehow ends up being, then
616633
# we end up in a death spiral of infinite loops, so let's check, for
617634
# robustness' sake.
618635
if context is not None:
619-
record.server_name = context.server_name
636+
637+
def safe_set(attr: str, value: Any) -> None:
638+
"""
639+
Only write the attribute if it hasn't already been set or we actually have
640+
a Synapse logcontext (indicating that this log record is relevant to
641+
Synapse).
642+
"""
643+
if context is not SENTINEL_CONTEXT or not hasattr(record, attr):
644+
setattr(record, attr, value)
645+
646+
safe_set("server_name", context.server_name)
647+
620648
# Logging is interested in the request ID. Note that for backwards
621649
# compatibility this is stored as the "request" on the record.
622-
record.request = str(context)
650+
safe_set("request", str(context))
623651

624652
# Add some data from the HTTP request.
625653
request = context.request
654+
# The sentinel logcontext has no request so if we get past this point, we
655+
# know we have some actual Synapse logcontext and don't need to worry about
656+
# using `safe_set`. We'll consider this an optimization since this is a
657+
# pretty hot-path.
626658
if request is None:
627659
return True
628660

0 commit comments

Comments
 (0)