Post review tweaks

Author: rzats

src/server/_common.py

@@ -68,6 +68,7 @@ def log_info_with_request(message, **kwargs):
         remote_addr=request.remote_addr,
         real_remote_addr=get_real_ip_addr(request),
         user_agent=request.user_agent.string,
+        req_referrer=request.referrer or request.origin,
         api_key=resolve_auth_token(),
         user_id=(current_user and current_user.id),
         **kwargs
@@ -115,20 +116,7 @@ def before_request_execute():
     api_key = resolve_auth_token()
 
     # TODO: replace this next call with: log_info_with_request("Received API request")
-    get_structured_logger("server_api").info(
-        "Received API request",
-        method=request.method,
-        url=request.url,
-        form_args=request.form,
-        req_length=request.content_length,
-        remote_addr=request.remote_addr,
-        real_remote_addr=get_real_ip_addr(request),
-        user_agent=request.user_agent.string,
-        api_key=api_key,
-        user_id=(user and user.id),
-        req_referrer=request.referrer,
-        req_origin=request.environ.get('HTTP_ORIGIN', '')
-    )
+    log_info_with_request("Received API request")
 
     if not _is_public_route() and api_key and not user:
         # if this is a privleged endpoint, and an api key was given but it does not look up to a user, raise exception:
@@ -152,30 +140,10 @@ def after_request_execute(response):
     # Convert to milliseconds
     total_time *= 1000
 
-    api_key = resolve_auth_token()
-
     update_key_last_time_used(current_user)
 
-    # TODO: replace this next call with: log_info_with_request_and_response("Served API request", response, elapsed_time_ms=total_time)
-    get_structured_logger("server_api").info(
-        "Served API request",
-        method=request.method,
-        url=request.url,
-        form_args=request.form,
-        req_length=request.content_length,
-        remote_addr=request.remote_addr,
-        real_remote_addr=get_real_ip_addr(request),
-        user_agent=request.user_agent.string,
-        api_key=api_key,
-        values=request.values.to_dict(flat=False),
-        blueprint=request.blueprint,
-        endpoint=request.endpoint,
-        response_status=response.status,
-        content_length=response.calculate_content_length(),
-        elapsed_time_ms=total_time,
-        req_referrer=request.referrer,
-        req_origin=request.environ.get('HTTP_ORIGIN', '')
-    )
+    log_info_with_request_and_response("Served API request", response, elapsed_time_ms=total_time)
+
     return response
 
 

tests/server/test_validate.py

@@ -63,7 +63,29 @@ def test_require_any(self):
                 self.assertTrue(require_any(request, "abc", empty=True))
 
     def test_origin_headers(self):
-        with self.subTest("referer and origin"):
+        with self.subTest("referer only"):
+            with self.assertLogs("server_api", level='INFO') as logs:
+                self.client.get("/signal_dashboard_status", headers={
+                    "Referer": "https://test.com/test"
+                })
+            output = logs.output
+            self.assertEqual(len(output), 2) # [before_request, after_request]
+            self.assertIn("Received API request", output[0])
+            self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0])
+            self.assertIn("Served API request", output[1])
+            self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1])
+        with self.subTest("origin only"):
+            with self.assertLogs("server_api", level='INFO') as logs:
+                self.client.get("/signal_dashboard_status", headers={
+                    "Origin": "https://test.com"
+                })
+            output = logs.output
+            self.assertEqual(len(output), 2) # [before_request, after_request]
+            self.assertIn("Received API request", output[0])
+            self.assertIn("\"req_referrer\": \"https://test.com\"", output[0])
+            self.assertIn("Served API request", output[1])
+            self.assertIn("\"req_referrer\": \"https://test.com\"", output[1])
+        with self.subTest("referer overrides origin"):
             with self.assertLogs("server_api", level='INFO') as logs:
                 self.client.get("/signal_dashboard_status", headers={
                     "Referer": "https://test.com/test",
@@ -73,7 +95,5 @@ def test_origin_headers(self):
             self.assertEqual(len(output), 2) # [before_request, after_request]
             self.assertIn("Received API request", output[0])
             self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[0])
-            self.assertIn("\"req_origin\": \"https://test.com\"", output[0])
             self.assertIn("Served API request", output[1])
             self.assertIn("\"req_referrer\": \"https://test.com/test\"", output[1])
-            self.assertIn("\"req_origin\": \"https://test.com\"", output[1])