fix(access-logs): filter out 'None' values from access logs (#97649)

We're currently logging a lot of 'None's in our access logs, which add
to storage costs, so we should filter them out.

`api.access` cost can be seen
[here](https://console.cloud.google.com/monitoring/dashboards/builder/2fac5642-c4b9-4359-8f84-fb9065a40cbe;duration=P1D?invt=Ab5OsA&project=internal-sentry&pageState=(%22eventTypes%22:(%22selected%22:%5B%22CLOUD_ALERTING_ALERT%22,%22SERVICE_HEALTH_INCIDENT%22%5D))&rapt=AEjHL4NL5TS0_HZRIGGC_2egzRlxKZeImiELNSwRDfxXfNQQK4cOqTRpTFVtft8OU7vUwd3dNvnbTsF2fvAcTLuuObMcjhsxVKQ9VKqesD5qpM3kuqYnWG0&inv=1)
— some more notes on cost in [my ticket comment
here](https://linear.app/getsentry/issue/ID-819/remove-none-values-from-access-logs#comment-9b40f675)

[Query showing that every log has the required access log
fields](https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Alabels.name%3D%22sentry.access.api%22%0AjsonPayload.method%3D%22None%22%20OR%20jsonPayload.view%3D%22None%22%20OR%20jsonPayload.response%20%3D%22None%22%20OR%20jsonPayload.path%3D%22None%22%20OR%20jsonPayload.rate_limit_type%3D%22None%22%20OR%20jsonPayload.rate_limited%3D%22None%22%20OR%20jsonPayload.caller_ip%3D%22None%22%20OR%20jsonPayload.request_duration_seconds%3D%22None%22%20%0A--%20jsonPayload.organization_id%3D%22None%22%0A--%20jsonPayload.response%3D%22429%22;summaryFields=jsonPayload%252Fsnuba_policy:true:32:beginning;cursorTimestamp=2025-08-11T23:13:43.985230382Z;duration=P1D?project=internal-sentry&inv=1&invt=Ab5O6A&rapt=AEjHL4O_3xg8i0ALGUrkxIfT6o5Gkmflt3EqYTMyq8xfsGOFMgTSfVgDVyRvp-Tx-8R6m26gf2gLcvF1Hwars-j7jZMXtWqcY_CWrv2Wi1QqK7QbyGDVxAs&pli=1)

Closes
https://linear.app/getsentry/issue/ID-819/remove-none-values-from-access-logs

Author: cvxluo

src/sentry/middleware/access_log.py

@@ -47,7 +47,7 @@ def _get_token_name(auth: AuthenticatedToken | None) -> str | None:
         raise AssertionError(f"unreachable: {auth}")
 
 
-def _get_rate_limit_stats_dict(request: Request) -> dict[str, str]:
+def _get_rate_limit_stats_dict(request: Request) -> dict[str, str | int | None]:
 
     rate_limit_metadata: RateLimitMeta | None = getattr(request, "rate_limit_metadata", None)
     snuba_rate_limit_metadata: SnubaRateLimitMeta | None = getattr(
@@ -62,20 +62,20 @@ def _get_rate_limit_stats_dict(request: Request) -> dict[str, str]:
 
     rate_limit_stats = {
         "rate_limit_type": rate_limit_type,
-        "concurrent_limit": str(getattr(rate_limit_metadata, "concurrent_limit", None)),
-        "concurrent_requests": str(getattr(rate_limit_metadata, "concurrent_requests", None)),
-        "reset_time": str(getattr(rate_limit_metadata, "reset_time", None)),
-        "group": str(getattr(rate_limit_metadata, "group", None)),
-        "limit": str(getattr(rate_limit_metadata, "limit", None)),
-        "remaining": str(getattr(rate_limit_metadata, "remaining", None)),
+        "concurrent_limit": getattr(rate_limit_metadata, "concurrent_limit", None),
+        "concurrent_requests": getattr(rate_limit_metadata, "concurrent_requests", None),
+        "reset_time": getattr(rate_limit_metadata, "reset_time", None),
+        "group": getattr(rate_limit_metadata, "group", None),
+        "limit": getattr(rate_limit_metadata, "limit", None),
+        "remaining": getattr(rate_limit_metadata, "remaining", None),
         # We prefix the snuba fields with snuba_ to avoid confusion with the standard rate limit metadata
-        "snuba_policy": str(getattr(snuba_rate_limit_metadata, "policy", None)),
-        "snuba_quota_unit": str(getattr(snuba_rate_limit_metadata, "quota_unit", None)),
-        "snuba_quota_used": str(getattr(snuba_rate_limit_metadata, "quota_used", None)),
-        "snuba_rejection_threshold": str(
-            getattr(snuba_rate_limit_metadata, "rejection_threshold", None)
+        "snuba_policy": getattr(snuba_rate_limit_metadata, "policy", None),
+        "snuba_quota_unit": getattr(snuba_rate_limit_metadata, "quota_unit", None),
+        "snuba_quota_used": getattr(snuba_rate_limit_metadata, "quota_used", None),
+        "snuba_rejection_threshold": getattr(
+            snuba_rate_limit_metadata, "rejection_threshold", None
         ),
-        "snuba_storage_key": str(getattr(snuba_rate_limit_metadata, "storage_key", None)),
+        "snuba_storage_key": getattr(snuba_rate_limit_metadata, "storage_key", None),
     }
 
     return rate_limit_stats
@@ -94,7 +94,7 @@ def _create_api_access_log(
             view = request.resolver_match._func_path
 
         request_auth = _get_request_auth(request)
-        token_type = str(_get_token_name(request_auth))
+        token_type = _get_token_name(request_auth)
         if token_type == "system":
             # if its an internal request, no need to log
             return
@@ -108,26 +108,30 @@ def _create_api_access_log(
         entity_id = getattr(request_auth, "entity_id", None)
         status_code = getattr(response, "status_code", 500)
         log_metrics = dict(
-            method=str(request.method),
+            method=request.method,
             view=view,
             response=status_code,
-            user_id=str(user_id),
-            is_app=str(is_app),
+            user_id=user_id,
+            is_app=is_app,
             token_type=token_type,
-            is_frontend_request=str(is_frontend_request(request)),
-            organization_id=str(org_id),
-            entity_id=str(entity_id),
-            path=str(request.path),
-            caller_ip=str(request.META.get("REMOTE_ADDR")),
-            user_agent=str(request.META.get("HTTP_USER_AGENT")),
-            rate_limited=str(getattr(request, "will_be_rate_limited", False)),
-            rate_limit_category=str(getattr(request, "rate_limit_category", None)),
+            is_frontend_request=is_frontend_request(request),
+            organization_id=org_id,
+            entity_id=entity_id,
+            path=request.path,
+            caller_ip=request.META.get("REMOTE_ADDR"),
+            user_agent=request.META.get("HTTP_USER_AGENT"),
+            rate_limited=getattr(request, "will_be_rate_limited", False),
+            rate_limit_category=getattr(request, "rate_limit_category", None),
             request_duration_seconds=access_log_metadata.get_request_duration(),
             **_get_rate_limit_stats_dict(request),
         )
         auth = get_authorization_header(request).split()
         if len(auth) == 2:
             log_metrics["token_last_characters"] = force_str(auth[1])[-4:]
+
+        # Filter out None values and convert remaining values to string
+        log_metrics = {k: str(v) for k, v in log_metrics.items() if v is not None}
+
         api_access_logger.info("api.access", extra=log_metrics)
         metrics.incr("middleware.access_log.created")
 

tests/sentry/middleware/test_access_log_middleware.py

@@ -141,23 +141,27 @@ def get(self, request, organization_context, organization):
     ),
 ]
 
-access_log_fields = (
+required_access_log_fields = (
     "method",
     "view",
     "response",
-    "user_id",
+    "path",
+    "rate_limit_type",
+    "rate_limited",
+    "caller_ip",
+    "request_duration_seconds",
+)
+
+# All of these fields may be None, and thus may not appear in every access log
+optional_access_log_fields = (
+    "organization_id",
     "is_app",
+    "user_id",
     "token_type",
-    "organization_id",
     "entity_id",
-    "path",
-    "caller_ip",
     "user_agent",
-    "rate_limited",
     "rate_limit_category",
-    "request_duration_seconds",
     "group",
-    "rate_limit_type",
     "concurrent_limit",
     "concurrent_requests",
     "reset_time",
@@ -168,6 +172,7 @@ def get(self, request, organization_context, organization):
     "snuba_storage_key",
     "snuba_quota_used",
     "snuba_rejection_threshold",
+    "token_last_characters",
 )
 
 
@@ -181,7 +186,7 @@ def inject_fixtures(self, caplog):
     def assert_access_log_recorded(self):
         sentinel = object()
         for record in self.captured_logs:
-            for field in access_log_fields:
+            for field in required_access_log_fields:
                 assert getattr(record, field, sentinel) != sentinel, field
 
     @property
@@ -231,7 +236,7 @@ def test_access_log_rate_limited(self) -> None:
         self.get_error_response(status_code=429)
         self.assert_access_log_recorded()
         # no token because the endpoint was not hit
-        assert self.captured_logs[0].token_type == "None"
+        assert not hasattr(self.captured_logs[0], "token_type")
         assert self.captured_logs[0].limit == "0"
         assert self.captured_logs[0].remaining == "0"
         assert self.captured_logs[0].group == RateLimitedEndpoint.rate_limits.group
@@ -250,7 +255,7 @@ def test_concurrent_request_finishes(self) -> None:
         # rate limiting
         self.assert_access_log_recorded()
         for i in range(10):
-            assert self.captured_logs[i].token_type == "None"
+            assert not hasattr(self.captured_logs[i], "token_type")
             assert self.captured_logs[0].group == RateLimitedEndpoint.rate_limits.group
             assert self.captured_logs[i].concurrent_requests == "1"
             assert self.captured_logs[i].concurrent_limit == "1"