fix(https_fn): stop logging callable request contents on invalid bodies

src/firebase_functions/private/_identity_fn.py

@@ -361,12 +361,6 @@ def before_operation_handler(
         if not _util.valid_on_call_request(request):
             _logging.error("Invalid request, unable to process.")
             raise HttpsError(FunctionsErrorCode.INVALID_ARGUMENT, "Bad Request")
-        if request.json is None:
-            _logging.error("Request is missing body.")
-            raise HttpsError(FunctionsErrorCode.INVALID_ARGUMENT, "Bad Request")
-        if request.json is None or "data" not in request.json:
-            _logging.error("Request body is missing data.", request.json)
-            raise HttpsError(FunctionsErrorCode.INVALID_ARGUMENT, "Bad Request")
         jwt_token = request.json["data"]["jwt"]
         decoded_token = _token_verifier.verify_auth_blocking_token(jwt_token)
         event = _auth_blocking_event_from_token_data(event_type, decoded_token)

src/firebase_functions/private/util.py

@@ -115,21 +115,26 @@ def snake_to_camel(word: str) -> str:
 
 def _on_call_valid_body(request: _Request) -> bool:
     """The body must not be empty."""
-    if request.json is None:
-        _logging.warning("Request is missing body.")
+    body = request.get_json(silent=True)
+    if body is None:
+        if request.get_data():
+            _logging.warning("Request body is not valid JSON.")
+        else:
+            _logging.warning("Request is missing body.")
         return False
 
-    # The body must have data.
-    if "data" not in request.json:
-        _logging.warning("Request body is missing data.", request.json)
+    # Logged before auth is checked: key names only, never values. %r escapes
+    # newlines so a key cannot forge extra log lines.
+    if not isinstance(body, dict):
+        _logging.warning("Request body is missing data.")
+        return False
+    if "data" not in body:
+        _logging.warning("Request body is missing data. Fields: %r", list(body.keys()))
         return False
 
-    extra_keys = {key: request.json[key] for key in request.json.keys() if key != "data"}
-    if len(extra_keys) != 0:
-        _logging.warning(
-            "Request body has extra fields: %s",
-            "".join(f"{key}: {value}," for (key, value) in extra_keys.items()),
-        )
+    if len(body) > 1:
+        extra_keys = [key for key in body.keys() if key != "data"]
+        _logging.warning("Request body has extra fields: %r", extra_keys)
         return False
     return True
 

tests/test_util.py

@@ -16,9 +16,13 @@
 """
 
 import datetime as _dt
+import logging
 from os import environ, path
 
+from flask import Flask
+
 from firebase_functions.private.util import (
+    _on_call_valid_body,
     _unsafe_decode_id_token,
     deep_merge,
     firebase_config,
@@ -165,3 +169,72 @@ def test_unsafe_decode_token():
     result = _unsafe_decode_id_token(test_token)
     assert result["sub"] == "firebase"
     assert result["name"] == "John Doe"
+
+
+def _valid_body(body: str) -> bool:
+    with Flask(__name__).test_request_context(
+        method="POST", data=body, content_type="application/json"
+    ) as ctx:
+        return _on_call_valid_body(ctx.request)
+
+
+def test_on_call_valid_body_logs_extra_field_keys_without_values(caplog):
+    with caplog.at_level(logging.WARNING):
+        assert not _valid_body('{"data": {}, "extraKey": "secretValue"}')
+    assert "Request body has extra fields: ['extraKey']" in caplog.text
+    assert "secretValue" not in caplog.text
+
+
+def test_on_call_valid_body_escapes_newlines_in_extra_field_keys(caplog):
+    with caplog.at_level(logging.WARNING):
+        assert not _valid_body('{"data": {}, "a\\nFAKE LOG LINE": 1}')
+    assert "\n" not in caplog.text.rstrip("\n")
+
+
+def test_on_call_valid_body_logs_only_key_names_when_data_is_missing(caplog):
+    with caplog.at_level(logging.WARNING):
+        assert not _valid_body('{"secretKey": "secretValue"}')
+    assert "Request body is missing data. Fields: ['secretKey']" in caplog.text
+    assert "secretValue" not in caplog.text
+
+
+def test_on_call_valid_body_does_not_log_non_object_body_when_data_is_missing(caplog):
+    for body in (
+        '["secretValue"]',
+        '["data", "secretValue"]',
+        '"data secretValue"',
+        "123",
+    ):
+        caplog.clear()
+        with caplog.at_level(logging.WARNING):
+            assert not _valid_body(body)
+        assert "Request body is missing data." in caplog.text
+        assert "secretValue" not in caplog.text
+
+
+def test_on_call_valid_body_rejects_empty_body(caplog):
+    with caplog.at_level(logging.WARNING):
+        assert not _valid_body("")
+    assert "Request is missing body." in caplog.text
+
+
+def test_on_call_valid_body_rejects_malformed_json_without_logging_it(caplog):
+    with caplog.at_level(logging.WARNING):
+        assert not _valid_body("{secretValue")
+    assert "Request body is not valid JSON." in caplog.text
+    assert "Request is missing body." not in caplog.text
+    assert "secretValue" not in caplog.text
+
+
+def test_on_call_valid_body_accepts_any_data_value_without_logging(caplog):
+    for body in (
+        '{"data": {}}',
+        '{"data": "value"}',
+        '{"data": 123}',
+        '{"data": null}',
+        '{"data": [1, 2, 3]}',
+    ):
+        caplog.clear()
+        with caplog.at_level(logging.WARNING):
+            assert _valid_body(body), body
+        assert caplog.text == ""