middleware: Use request.user for logging when possible.

Instead of trying to set the _requestor_for_logs attribute in all the
relevant places, we try to use request.user when possible (that will be
when it's a UserProfile or RemoteZulipServer as of now). In other
places, we set _requestor_for_logs to avoid manually editing the
request.user attribute, as it should mostly be left for Django to manage
it.
In places where we remove the "request._requestor_for_logs = ..." line,
it is clearly implied by the previous code (or the current surrounding
code) that request.user is of the correct type.

zerver/decorator.py

@@ -197,7 +197,6 @@ def validate_api_key(request: HttpRequest, role: Optional[str],
         if get_subdomain(request) != Realm.SUBDOMAIN_FOR_ROOT_DOMAIN:
             raise JsonableError(_("Invalid subdomain for push notifications bouncer"))
         request.user = remote_server
-        request._requestor_for_logs = "zulip-server:" + role
         remote_server.rate_limits = ""
         # Skip updating UserActivity, since remote_server isn't actually a UserProfile object.
         process_client(request, remote_server, skip_update_user_activity=True)
@@ -208,7 +207,6 @@ def validate_api_key(request: HttpRequest, role: Optional[str],
         raise JsonableError(_("This API is not available to incoming webhook bots."))
 
     request.user = user_profile
-    request._requestor_for_logs = user_profile.format_requestor_for_logs()
     process_client(request, user_profile, client_name=client_name)
 
     return user_profile
@@ -425,7 +423,6 @@ def log_view_func(view_func: ViewFuncT) -> ViewFuncT:
 def add_logging_data(view_func: ViewFuncT) -> ViewFuncT:
     @wraps(view_func)
     def _wrapped_view_func(request: HttpRequest, *args: Any, **kwargs: Any) -> HttpResponse:
-        request._requestor_for_logs = request.user.format_requestor_for_logs()
         process_client(request, request.user, is_browser_view=True,
                        query=view_func.__name__)
         return rate_limit()(view_func)(request, *args, **kwargs)
@@ -649,7 +646,6 @@ def authenticate_log_and_execute_json(request: HttpRequest,
 
     process_client(request, user_profile, is_browser_view=True,
                    query=view_func.__name__)
-    request._requestor_for_logs = user_profile.format_requestor_for_logs()
     return limited_view_func(request, user_profile, *args, **kwargs)
 
 # Checks if the request is a POST request and that the user is logged

zerver/lib/test_helpers.py

@@ -280,7 +280,6 @@ class HostRequestMock:
         self.method = ''
         self.body = ''
         self.content_type = ''
-        self._requestor_for_logs = ''
 
     def get_host(self) -> str:
         return self.host

zerver/middleware.py

@@ -289,7 +289,10 @@ class LogRequests(MiddlewareMixin):
         try:
             requestor_for_logs = request._requestor_for_logs
         except Exception:
-            requestor_for_logs = "unauth"
+            if hasattr(request, 'user') and hasattr(request.user, 'format_requestor_for_logs'):
+                requestor_for_logs = request.user.format_requestor_for_logs()
+            else:
+                requestor_for_logs = "unauth"
         try:
             client = request.client.name
         except Exception:

zerver/tests/test_decorators.py

@@ -378,9 +378,6 @@ body:
         # Verify rate limiting was attempted.
         self.assertTrue(rate_limit_mock.called)
 
-        # Verify decorator set the magic _email field used by some of our back end logging.
-        self.assertEqual(request._requestor_for_logs, webhook_bot.format_requestor_for_logs())
-
         # Verify the main purpose of the decorator, which is that it passed in the
         # user_profile to my_webhook, allowing it return the correct
         # email for the bot (despite the API caller only knowing the API key).

zerver/tornado/handlers.py

@@ -218,7 +218,8 @@ class AsyncDjangoHandler(tornado.web.RequestHandler, base.BaseHandler):
         request._log_data = old_request._log_data
         if hasattr(request, "_rate_limit"):
             request._rate_limit = old_request._rate_limit
-        request._requestor_for_logs = old_request._requestor_for_logs
+        if hasattr(request, "_requestor_for_logs"):
+            request._requestor_for_logs = old_request._requestor_for_logs
         request.user = old_request.user
         request.client = old_request.client
 

zilencer/models.py

@@ -23,6 +23,9 @@ class RemoteZulipServer(models.Model):
     def __str__(self) -> str:
         return "<RemoteZulipServer %s %s>" % (self.hostname, self.uuid[0:12])
 
+    def format_requestor_for_logs(self) -> str:
+        return "zulip-server:" + self.uuid
+
 # Variant of PushDeviceToken for a remote server.
 class RemotePushDeviceToken(AbstractPushDeviceToken):
     server = models.ForeignKey(RemoteZulipServer, on_delete=models.CASCADE)  # type: RemoteZulipServer