Skip to content

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

Merged
IzaakGough merged 8 commits into
mainfrom
fix/on-call-validation-logging
Nov 6, 2026
Merged

IzaakGough merged 8 commits into
mainfrom
fix/on-call-validation-logging

Conversation

@IzaakGough

@IzaakGough IzaakGough commented Oct 30, 2026 •

Copy link
Copy Markdown
Contributor

Fixes #328.

When an on_call function got a malformed request, its warning log could include values from the request body, before any auth check. Bodies that were not a JSON object also returned 500 instead of 400.

This logs only key names, never values or the body, and returns 400 for those bodies.

  • Key names are logged with %r, so a newline in a name cannot add fake log lines. Node also logs the names.

Tested with new unit tests, the emulator, and deployed callable and task queue functions.

Invalid callable bodies are logged before auth is checked, so log only
the count of extra fields and never the body.

@gemini-code-assist gemini-code-assist Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request updates the _on_call_valid_body function to prevent logging sensitive request body content, opting instead to log the count of extra fields. Corresponding unit tests were added to verify this behavior. The reviewer suggested adding a type check to ensure request.json is a dictionary to avoid potential runtime errors and recommended expanding test coverage to include non-dictionary JSON inputs to ensure robust error handling.

Comment thread src/firebase_functions/private/util.py Resolved
Comment thread tests/test_util.py Resolved
Matches the Node SDK. Names are logged with %r so a key cannot add log lines.
A JSON list, string or number body, an empty body, or malformed JSON returned 500 INTERNAL instead of 400 INVALID_ARGUMENT.
Comment thread src/firebase_functions/private/util.py Resolved
Comment thread src/firebase_functions/private/util.py Resolved
…body

Also removes the unreachable body checks in the auth blocking handler, one of which still passed the request body to the logger.

@ajperel ajperel left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Disclaimer: This draft review was generated by an experimental multi-perspective AI review agent. Please verify all findings before acting on them.

Code Review Summary: firebase/firebase-functions-python PR #330

🏛️ Architectural Assessment & Approach Verdict

  • Verdict: APPROVE APPROACH
  • Assessment: The PR cleanly resolves Issue #328. Switching from request.json to request.get_json(silent=True) and adding isinstance(body, dict) fixes unhandled BadRequest and TypeError exceptions on malformed or non-object payloads, properly returning HTTP 400 (INVALID_ARGUMENT) instead of HTTP 500 (INTERNAL). Crucially, it stops logging sensitive request body values before authentication.
  • Architectural Trade-Off (Key Logging vs. Count-Only Logging):
    • The author justified logging key names with %r for log-forging defense and Node SDK parity (extraKeys.join(", ") in firebase-functions/src/common/providers/https.ts).
    • Using %r format specifiers invokes Python's repr(), escaping control characters (\n, \r, \t, \x00) and preventing log line splitting in stdout and structured Cloud Logging sinks.
    • Regarding Key Limits: In the Node SDK and Python SDK, there is no precedent for capping key lists with arbitrary limits like 10—Node logs all extra keys, and platform payload limits (10MB/32MB) constrain request size. However, if maintainers wish to be completely immune to untrusted input in logs (as suggested in issue #328), logging key counts (len(body) - 1) rather than key names is the cleanest zero-allocation alternative.

🟢 Strengths & LGTM Aspects

  • Accurate HTTP Status Mapping: Replaces unhandled exceptions with clean boolean validation, allowing _on_call_handler to consistently return HTTP 400 INVALID_ARGUMENT.
  • Log Injection Hardening: Using %r format specifiers escapes control characters, neutralizing log line forging attacks.
  • Dead-Code Pruning: Safely removes redundant, buggy validation logic in _identity_fn.py that duplicated _util.valid_on_call_request and contained an unredacted logging site.
  • Comprehensive Negative Test Suite: Adds 6 unit tests in tests/test_util.py covering malformed JSON, non-object payloads, empty bodies, and newline escaping.

🔴 Overview of Findings

  • 0 Blocking Issues: The PR is safe, functionally correct, and ready to land.
  • 2 Suggestions:
    1. O(1) Extra-Key Detection: Check len(body) > 1 before list comprehension allocation once "data" in body is verified.
    2. Add Happy-Path Unit Test: All added unit tests verify rejection paths; positive assertions verifying _on_call_valid_body returns True without logging on valid bodies should be included.

Comment thread src/firebase_functions/private/util.py Outdated
Comment on lines 136 to 139
if extra_keys:
_logging.warning("Request body has extra fields: %r", extra_keys)
return False
return True

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Suggestion: O(1) extra-keys check on valid requests

Since line 131 already verifies that "data" in body, checking len(body) > 1 avoids allocating extra_keys = [key ...] on valid requests with no extra fields:

Suggested change
if extra_keys:
_logging.warning("Request body has extra fields: %r", extra_keys)
return False
return True
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

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice suggestion, saves building the list for valid requests, added in ac74442

Comment thread tests/test_util.py

def test_on_call_valid_body_rejects_malformed_json_without_logging_it(caplog):
with caplog.at_level(logging.WARNING):
assert not _valid_body("{secretValue")

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Suggestion: Add happy-path test for valid callable bodies

All 6 new unit tests assert rejection (assert not _valid_body(...)). Consider adding a positive test case verifying that valid bodies return True and produce zero warning logs:

def test_on_call_valid_body_accepts_valid_payloads(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)
        assert caplog.text == ""

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks, added in 14a9c2d

@IzaakGough
IzaakGough merged commit 356aa1c into main Nov 6, 2026
22 checks passed
@IzaakGough
IzaakGough deleted the fix/on-call-validation-logging branch November 6, 2026 06:34
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

on_call validation logs request body / extra field values before auth verification

3 participants