diff --git a/synapse/http/site.py b/synapse/http/site.py
index 47754aff43..c0c873ce32 100644
--- a/synapse/http/site.py
+++ b/synapse/http/site.py
@@ -14,7 +14,7 @@
import contextlib
import logging
import time
-from typing import Optional, Type, Union
+from typing import Optional, Tuple, Type, Union
import attr
from zope.interface import implementer
@@ -26,7 +26,11 @@ from twisted.web.server import Request, Site
from synapse.config.server import ListenerConfig
from synapse.http import get_request_user_agent, redact_uri
from synapse.http.request_metrics import RequestMetrics, requests_counter
-from synapse.logging.context import LoggingContext, PreserveLoggingContext
+from synapse.logging.context import (
+ ContextRequest,
+ LoggingContext,
+ PreserveLoggingContext,
+)
from synapse.types import Requester
logger = logging.getLogger(__name__)
@@ -63,7 +67,7 @@ class SynapseRequest(Request):
# The requester, if authenticated. For federation requests this is the
# server name, for client requests this is the Requester object.
- self.requester = None # type: Optional[Union[Requester, str]]
+ self._requester = None # type: Optional[Union[Requester, str]]
# we can't yet create the logcontext, as we don't know the method.
self.logcontext = None # type: Optional[LoggingContext]
@@ -93,6 +97,31 @@ class SynapseRequest(Request):
self.site.site_tag,
)
+ @property
+ def requester(self) -> Optional[Union[Requester, str]]:
+ return self._requester
+
+ @requester.setter
+ def requester(self, value: Union[Requester, str]) -> None:
+ # Store the requester, and update some properties based on it.
+
+ # This should only be called once.
+ assert self._requester is None
+
+ self._requester = value
+
+ # A logging context should exist by now (and have a ContextRequest).
+ assert self.logcontext is not None
+ assert self.logcontext.request is not None
+
+ (
+ requester,
+ authenticated_entity,
+ ) = self.get_authenticated_entity()
+ self.logcontext.request.requester = requester
+ # If there's no authenticated entity, it was the requester.
+ self.logcontext.request.authenticated_entity = authenticated_entity or requester
+
def get_request_id(self):
return "%s-%i" % (self.get_method(), self.request_seq)
@@ -126,13 +155,60 @@ class SynapseRequest(Request):
return self.method.decode("ascii")
return method
+ def get_authenticated_entity(self) -> Tuple[Optional[str], Optional[str]]:
+ """
+ Get the "authenticated" entity of the request, which might be the user
+ performing the action, or a user being puppeted by a server admin.
+
+ Returns:
+ A tuple:
+ The first item is a string representing the user making the request.
+
+ The second item is a string or None representing the user who
+ authenticated when making this request. See
+ Requester.authenticated_entity.
+ """
+ # Convert the requester into a string that we can log
+ if isinstance(self._requester, str):
+ return self._requester, None
+ elif isinstance(self._requester, Requester):
+ requester = self._requester.user.to_string()
+ authenticated_entity = self._requester.authenticated_entity
+
+ # If this is a request where the target user doesn't match the user who
+ # authenticated (e.g. and admin is puppetting a user) then we return both.
+ if self._requester.user.to_string() != authenticated_entity:
+ return requester, authenticated_entity
+
+ return requester, None
+ elif self._requester is not None:
+ # This shouldn't happen, but we log it so we don't lose information
+ # and can see that we're doing something wrong.
+ return repr(self._requester), None # type: ignore[unreachable]
+
+ return None, None
+
def render(self, resrc):
# this is called once a Resource has been found to serve the request; in our
# case the Resource in question will normally be a JsonResource.
# create a LogContext for this request
request_id = self.get_request_id()
- self.logcontext = LoggingContext(request_id, request=request_id)
+ self.logcontext = LoggingContext(
+ request_id,
+ request=ContextRequest(
+ request_id=request_id,
+ ip_address=self.getClientIP(),
+ site_tag=self.site.site_tag,
+ # The requester is going to be unknown at this point.
+ requester=None,
+ authenticated_entity=None,
+ method=self.get_method(),
+ url=self.get_redacted_uri(),
+ protocol=self.clientproto.decode("ascii", errors="replace"),
+ user_agent=get_request_user_agent(self),
+ ),
+ )
# override the Server header which is set by twisted
self.setHeader("Server", self.site.server_version_string)
@@ -277,25 +353,6 @@ class SynapseRequest(Request):
# to the client (nb may be negative)
response_send_time = self.finish_time - self._processing_finished_time
- # Convert the requester into a string that we can log
- authenticated_entity = None
- if isinstance(self.requester, str):
- authenticated_entity = self.requester
- elif isinstance(self.requester, Requester):
- authenticated_entity = self.requester.authenticated_entity
-
- # If this is a request where the target user doesn't match the user who
- # authenticated (e.g. and admin is puppetting a user) then we log both.
- if self.requester.user.to_string() != authenticated_entity:
- authenticated_entity = "{},{}".format(
- authenticated_entity,
- self.requester.user.to_string(),
- )
- elif self.requester is not None:
- # This shouldn't happen, but we log it so we don't lose information
- # and can see that we're doing something wrong.
- authenticated_entity = repr(self.requester) # type: ignore[unreachable]
-
user_agent = get_request_user_agent(self, "-")
code = str(self.code)
@@ -305,6 +362,13 @@ class SynapseRequest(Request):
code += "!"
log_level = logging.INFO if self._should_log_request() else logging.DEBUG
+
+ # If this is a request where the target user doesn't match the user who
+ # authenticated (e.g. and admin is puppetting a user) then we log both.
+ requester, authenticated_entity = self.get_authenticated_entity()
+ if authenticated_entity:
+ requester = "{}.{}".format(authenticated_entity, requester)
+
self.site.access_logger.log(
log_level,
"%s - %s - {%s}"
@@ -312,7 +376,7 @@ class SynapseRequest(Request):
' %sB %s "%s %s %s" "%s" [%d dbevts]',
self.getClientIP(),
self.site.site_tag,
- authenticated_entity,
+ requester,
processing_time,
response_send_time,
usage.ru_utime,
|
