Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: add request response logging to auth #1678

Open
wants to merge 10 commits into
base: main
Choose a base branch
from
195 changes: 195 additions & 0 deletions google/auth/_helpers.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,15 +18,40 @@
import calendar
import datetime
from email.message import Message
import hashlib
import json
import logging
import sys
from typing import Any, Dict, Mapping, Optional, Union
import urllib

from google.auth import exceptions

try:
# TODO(https://github.com/googleapis/python-api-core/issues/813): Remove `# type: ignore` when
# `google-api-core` type hints issue is resolved.
from google.api_core import client_logging # type: ignore # noqa: F401

CLIENT_LOGGING_SUPPORTED = True # pragma: NO COVER
# TODO(https://github.com/googleapis/google-auth-library-python/issues/1690): Remove `pragma: NO COVER` once
# logging is supported in minimum version of google-api-core.
except ImportError: # pragma: NO COVER
CLIENT_LOGGING_SUPPORTED = False

# The smallest MDS cache used by this library stores tokens until 4 minutes from
# expiry.
REFRESH_THRESHOLD = datetime.timedelta(minutes=3, seconds=45)

# TODO(https://github.com/googleapis/google-auth-library-python/issues/1684): Audit and update the list below.
_SENSITIVE_FIELDS = {
"accessToken",
"access_token",
"id_token",
"client_id",
"refresh_token",
"client_secret",
}


def copy_docstring(source_class):
"""Decorator that copies a method's docstring from another class.
Expand Down Expand Up @@ -271,3 +296,173 @@ def is_python_3():
bool: True if the Python interpreter is Python 3 and False otherwise.
"""
return sys.version_info > (3, 0)


def _hash_sensitive_info(data: Union[dict, list]) -> Union[dict, list, str]:
"""
Hashes sensitive information within a dictionary.

Args:
data: The dictionary containing data to be processed.

Returns:
A new dictionary with sensitive values replaced by their SHA512 hashes.
If the input is a list, returns a list with each element recursively processed.
If the input is neither a dict nor a list, returns the type of the input as a string.

"""
if isinstance(data, dict):
hashed_data: Dict[Any, Union[Optional[str], dict, list]] = {}
for key, value in data.items():
if key in _SENSITIVE_FIELDS and not isinstance(value, (dict, list)):
hashed_data[key] = _hash_value(value, key)
elif isinstance(value, (dict, list)):
hashed_data[key] = _hash_sensitive_info(value)
else:
hashed_data[key] = value
return hashed_data
elif isinstance(data, list):
hashed_list = []
for val in data:
hashed_list.append(_hash_sensitive_info(val))
return hashed_list
else:
# TODO(https://github.com/googleapis/google-auth-library-python/issues/1701):
# Investigate and hash sensitive info before logging when the data type is
# not a dict or a list.
return str(type(data))


def _hash_value(value, field_name: str) -> Optional[str]:
"""Hashes a value and returns a formatted hash string."""
if value is None:
return None
encoded_value = str(value).encode("utf-8")
hash_object = hashlib.sha512()
hash_object.update(encoded_value)
hex_digest = hash_object.hexdigest()
return f"hashed_{field_name}-{hex_digest}"


def is_logging_enabled(logger: logging.Logger) -> bool:
"""
Checks if debug logging is enabled for the given logger.

Args:
logger: The logging.Logger instance to check.

Returns:
True if debug logging is enabled, False otherwise.
"""
return CLIENT_LOGGING_SUPPORTED and logger.isEnabledFor(logging.DEBUG)


def request_log(
logger: logging.Logger,
method: str,
url: str,
body: Optional[bytes],
headers: Optional[Mapping[str, str]],
) -> None:
"""
Logs an HTTP request at the DEBUG level if logging is enabled.

Args:
logger: The logging.Logger instance to use.
method: The HTTP method (e.g., "GET", "POST").
url: The URL of the request.
body: The request body (can be None).
headers: The request headers (can be None).
"""
if is_logging_enabled(logger):
content_type = (
headers["Content-Type"] if headers and "Content-Type" in headers else ""
)
json_body = _parse_request_body(body, content_type=content_type)
logged_body = _hash_sensitive_info(json_body)
logger.debug(
"Making request...",
extra={
"httpRequest": {
"method": method,
"url": url,
"body": logged_body,
"headers": headers,
}
},
)


def _parse_request_body(body: Optional[bytes], content_type: str = "") -> Any:
"""
Parses a request body, handling bytes and string types, and different content types.

Args:
body (Optional[bytes]): The request body.
content_type (str): The content type of the request body, e.g., "application/json",
"application/x-www-form-urlencoded", or "text/plain". If empty, attempts
to parse as JSON.

Returns:
Parsed body (dict, str, or None).
- JSON: Decodes if content_type is "application/json" or None (fallback).
- URL-encoded: Parses if content_type is "application/x-www-form-urlencoded".
- Plain text: Returns string if content_type is "text/plain".
- None: Returns if body is None, UTF-8 decode fails, or content_type is unknown.
"""
if body is None:
return None
try:
body_str = body.decode("utf-8")
except (UnicodeDecodeError, AttributeError):
return None
content_type = content_type.lower()
if not content_type or "application/json" in content_type:
try:
return json.loads(body_str)
except (json.JSONDecodeError, TypeError):
return body_str
if "application/x-www-form-urlencoded" in content_type:
parsed_query = urllib.parse.parse_qs(body_str)
result = {k: v[0] for k, v in parsed_query.items()}
return result
if "text/plain" in content_type:
return body_str
return None


def _parse_response(response: Any) -> Any:
"""
Parses a response, attempting to decode JSON.

Args:
response: The response object to parse. This can be any type, but
it is expected to have a `json()` method if it contains JSON.

Returns:
The parsed response. If the response contains valid JSON, the
decoded JSON object (e.g., a dictionary or list) is returned.
If the response does not have a `json()` method or if the JSON
decoding fails, the original response object is returned.
"""
try:
json_response = response.json()
return json_response
except AttributeError:
return response
except json.JSONDecodeError:
return response


def response_log(logger: logging.Logger, response: Any) -> None:
"""
Logs an HTTP response at the DEBUG level if logging is enabled.

Args:
logger: The logging.Logger instance to use.
response: The HTTP response object to log.
"""
if is_logging_enabled(logger):
json_response = _parse_response(response)
logged_response = _hash_sensitive_info(json_response)
logger.debug("Response received...", extra={"httpResponse": logged_response})
5 changes: 5 additions & 0 deletions google/auth/aio/transport/aiohttp.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
"""

import asyncio
import logging
from typing import AsyncGenerator, Mapping, Optional

try:
Expand All @@ -29,6 +30,8 @@
from google.auth import exceptions
from google.auth.aio import transport

_LOGGER = logging.getLogger(__name__)


class Response(transport.Response):
"""
Expand Down Expand Up @@ -155,6 +158,7 @@ async def __call__(
self._session = aiohttp.ClientSession()

client_timeout = aiohttp.ClientTimeout(total=timeout)
_helpers.request_log(_LOGGER, method, url, body, headers)
response = await self._session.request(
method,
url,
Expand All @@ -163,6 +167,7 @@ async def __call__(
timeout=client_timeout,
**kwargs,
)
# TODO(https://github.com/googleapis/google-auth-library-python/issues/1697): Add response log.
return Response(response)

except aiohttp.ClientError as caught_exc:
Expand Down
8 changes: 7 additions & 1 deletion google/auth/transport/_aiohttp_requests.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,14 +22,19 @@

import asyncio
import functools
import logging

import aiohttp # type: ignore
import urllib3 # type: ignore

from google.auth import _helpers
from google.auth import exceptions
from google.auth import transport
from google.auth.transport import requests


_LOGGER = logging.getLogger(__name__)

# Timeout can be re-defined depending on async requirement. Currently made 60s more than
# sync timeout.
_DEFAULT_TIMEOUT = 180 # in seconds
Expand Down Expand Up @@ -182,10 +187,11 @@ async def __call__(
self.session = aiohttp.ClientSession(
auto_decompress=False
) # pragma: NO COVER
requests._LOGGER.debug("Making request: %s %s", method, url)
_helpers.request_log(_LOGGER, method, url, body, headers)
response = await self.session.request(
method, url, data=body, headers=headers, timeout=timeout, **kwargs
)
# TODO(https://github.com/googleapis/google-auth-library-python/issues/1697): Add response log.
return _CombinedResponse(response)

except aiohttp.ClientError as caught_exc:
Expand Down
4 changes: 3 additions & 1 deletion google/auth/transport/_http_client.py
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
import socket
import urllib

from google.auth import _helpers
from google.auth import exceptions
from google.auth import transport

Expand Down Expand Up @@ -99,10 +100,11 @@ def __call__(
connection = http_client.HTTPConnection(parts.netloc, timeout=timeout)

try:
_LOGGER.debug("Making request: %s %s", method, url)

_helpers.request_log(_LOGGER, method, url, body, headers)
connection.request(method, path, body=body, headers=headers, **kwargs)
response = connection.getresponse()
_helpers.response_log(_LOGGER, response)
return Response(response)

except (http_client.HTTPException, socket.error) as caught_exc:
Expand Down
4 changes: 3 additions & 1 deletion google/auth/transport/requests.py
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@
create_urllib3_context,
) # pylint: disable=ungrouped-imports

from google.auth import _helpers
from google.auth import environment_vars
from google.auth import exceptions
from google.auth import transport
Expand Down Expand Up @@ -182,10 +183,11 @@ def __call__(
google.auth.exceptions.TransportError: If any exception occurred.
"""
try:
_LOGGER.debug("Making request: %s %s", method, url)
_helpers.request_log(_LOGGER, method, url, body, headers)
response = self.session.request(
method, url, data=body, headers=headers, timeout=timeout, **kwargs
)
_helpers.response_log(_LOGGER, response)
return _Response(response)
except requests.exceptions.RequestException as caught_exc:
new_exc = exceptions.TransportError(caught_exc)
Expand Down
4 changes: 3 additions & 1 deletion google/auth/transport/urllib3.py
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@

from packaging import version # type: ignore

from google.auth import _helpers
from google.auth import environment_vars
from google.auth import exceptions
from google.auth import transport
Expand Down Expand Up @@ -136,10 +137,11 @@ def __call__(
kwargs["timeout"] = timeout

try:
_LOGGER.debug("Making request: %s %s", method, url)
_helpers.request_log(_LOGGER, method, url, body, headers)
response = self.http.request(
method, url, body=body, headers=headers, **kwargs
)
_helpers.response_log(_LOGGER, response)
return _Response(response)
except urllib3.exceptions.HTTPError as caught_exc:
new_exc = exceptions.TransportError(caught_exc)
Expand Down
Loading