Skip to content

feat(api_core): add HTTP transport attempt logging in _TraceContext #19011

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.

Sign up for GitHub

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

Draft
chalmerlowe wants to merge 1 commit into
base: feat/otel-logging-m3-s3-grpc-attempt-logging
Choose a base branch
from
Draft

feat(api_core): add HTTP transport attempt logging in _TraceContext #19011

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
74 changes: 65 additions & 9 deletions packages/google-api-core/google/api_core/_observability.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1374,12 +1374,65 @@ def __init__(
self._parent_span: Any = None
self._cm: Any = None

def _log_http_attempt(
self,
status_code: int | str | None = None,
exc: BaseException | None = None,
status_message: str | None = None,
) -> None:
"""Emits a DEBUG transport attempt log for a failed HTTP request (fail-open).

Note:
In GAPIC REST transports (``_shared_macros.j2``), ``trace_http_request``
only wraps the raw ``session`` dispatch and ``record_response(response)``,
while HTTP status exceptions are raised outside the ``with`` block after
it exits. Because ``record_response`` and ``__exit__`` (``record_error``)
are mutually exclusive in transport execution, deduplication state is
not required here.

Args:
status_code (int | str | None): HTTP response status code or error code.
exc (BaseException | None): Exception raised during HTTP dispatch, if any.
status_message (str | None): Extracted HTTP error message fallback.
"""
try:
resolved_url = (
getattr(self._request, "url", None)
if self._request is not None
else self._url
)
resolved_method = (
getattr(self._request, "method", None)
if self._request is not None
else self._method
)
log_transport_attempt(
span=self._span,
target=resolved_url,
status_code=status_code,
kind="http",
http_method=resolved_method,
exc=exc,
client_options=self._client_options,
status_message=status_message,
)
# Intentionally catch broad Exception so telemetry logging fails open
# and never disrupts the caller's RPC flow.
except Exception:
pass
Comment on lines +1398 to +1422

@gemini-code-assist gemini-code-assist Bot Nov 6, 2026

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.

medium

There are two potential issues in _log_http_attempt:

  1. Double-logging / Duplicate attempts: Tracking the attempt status is a good approach to prevent duplicate logs.
  2. Silent failures: The use of a broad except Exception: pass block masks potential issues. Please log the exception using logger.warning instead of silencing it. Additionally, avoid using getattr for attributes that should be initialized in __init__ to keep the code clean and explicit.
        if getattr(self, "_attempt_logged", False):
            return
        self._attempt_logged = True
        try:
            request = self._request
            resolved_url = getattr(request, "url", None) if request is not None else self._url
            resolved_method = getattr(request, "method", None) if request is not None else self._method
            log_transport_attempt(
                span=self._span,
                target=resolved_url,
                status_code=status_code,
                kind="http",
                http_method=resolved_method,
                exc=exc,
                client_options=self._client_options,
                status_message=status_message,
            )
        except Exception as e:
            logger.warning("Telemetry logging failed: %s", e)
References
  1. Do not use defensive getattr checks for attributes that are guaranteed to be initialized in the class's init method.
  2. Avoid broad except Exception blocks that silently return None. Instead, log the exception to aid in debugging.

@chalmerlowe chalmerlowe Nov 6, 2026

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 for the review!

  1. In GAPIC REST transports (_shared_macros.j2), trace_http_request only wraps the raw session dispatch and record_response(response), while HTTP status exceptions are raised outside the with block after it exits. As a result, record_response and __exit__ (record_error) are mutually exclusive in transport execution and a deduplication flag is not required here.
  2. except Exception: pass is intentional and matches the fail-open observability contract across _observability.py (log_transport_attempt, record_response, record_error, and the gRPC interceptors) so internal telemetry failures never emit unexpected warnings into user logs.
  3. self._request, self._url, and self._method are accessed directly on self; getattr is only used on the external self._request object because caller-supplied request objects are not guaranteed to define .url or .method.


def record_response(self, response: Any) -> None:
"""Record HTTP response attributes on the active span.
"""Record HTTP response attributes on the active span and log failed attempts.

Args:
response (Any): The HTTP response object (e.g. requests.Response).
"""
code_int = _extract_http_status_code(response)
error_msg: str | None = None
if code_int is not None and code_int >= 400:
error_msg = self._extract_http_error_message(response)
self._log_http_attempt(status_code=code_int, status_message=error_msg)

span = self._span
if span is None or not hasattr(span, "set_attribute"):
return
Expand All @@ -1390,7 +1443,6 @@ def record_response(self, response: Any) -> None:
StatusCode,
)

code_int = _extract_http_status_code(response)
if code_int is not None:
span.set_attribute("http.response.status_code", code_int)
if self._parent_span is not None:
Expand All @@ -1400,7 +1452,6 @@ def record_response(self, response: Any) -> None:
if code_int >= 400:
span.set_status(Status(StatusCode.ERROR))
span.set_attribute("error.type", str(code_int))
error_msg = self._extract_http_error_message(response)
if error_msg:
span.set_attribute("status.message", error_msg)

Expand All @@ -1423,7 +1474,7 @@ def record_response(self, response: Any) -> None:
record_http_response = record_response

def record_error(self, exc: BaseException | None) -> None:
"""Record supplemental Cloud Observability error attributes on the active span.
"""Record supplemental Cloud Observability error attributes on the active span and log failed attempts.

Upstream OpenTelemetry's ``start_as_current_span`` context manager automatically
records the exception event and marks the span status as ERROR when an unhandled
Expand All @@ -1439,14 +1490,17 @@ def record_error(self, exc: BaseException | None) -> None:
Args:
exc (BaseException | None): The exception raised during dispatch.
"""
if exc is None:
return

status_code = getattr(exc, "code", None) or getattr(exc, "status_code", None)
self._log_http_attempt(status_code=status_code, exc=exc)

span = self._span
if span is None or exc is None:
if span is None:
return

try:
status_code = getattr(exc, "code", None) or getattr(
exc, "status_code", None
)
if status_code:
span.set_attribute("error.type", str(status_code))
else:
Expand Down Expand Up @@ -1529,10 +1583,12 @@ def __enter__(self) -> "_TraceContext":
def __exit__(self, exc_type: Any, exc_val: Any, exc_tb: Any) -> None:
if self._cm is not None:
try:
if exc_val is not None and self._span is not None:
if exc_val is not None:
self.record_error(exc_val)
finally:
self._cm.__exit__(exc_type, exc_val, exc_tb)
elif exc_val is not None:
self.record_error(exc_val)
# Always return None so caller exceptions are never suppressed
return None

Expand Down
67 changes: 67 additions & 0 deletions packages/google-api-core/tests/unit/test_observability.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2894,3 +2894,70 @@ def test_get_otel_interceptors_with_logging_enabled(
assert isinstance(
async_list[2], _observability._AsyncSuppressingClientInterceptor
)


def test_trace_context_http_logging_on_error_status_and_exception(monkeypatch):
"""Proves that _TraceContext logs HTTP error responses (>= 400) and dispatch exceptions when logging is enabled."""
monkeypatch.setenv("GOOGLE_SDK_EXPERIMENTAL_PYTHON_TRACING_ENABLED", "false")
monkeypatch.setenv("GOOGLE_SDK_EXPERIMENTAL_PYTHON_LOGGING_ENABLED", "true")

with mock.patch.object(_observability, "log_transport_attempt") as mock_log:
with _observability.trace_http_request(
method="POST", url="https://example.com/v1/echo"
) as ctx:
ctx.record_response(
mock.Mock(status_code=503, headers={}, reason="Service Unavailable")
)
mock_log.assert_called_once()
assert mock_log.call_args[1]["status_code"] == 503
assert mock_log.call_args[1]["kind"] == "http"
assert mock_log.call_args[1]["status_message"] == "Service Unavailable"

with mock.patch.object(_observability, "log_transport_attempt") as mock_log:
with pytest.raises(ConnectionError):
with _observability.trace_http_request(
method="GET", url="https://example.com/v1/echo"
) as ctx:
ctx.record_error(None)
raise ConnectionError("reset")
mock_log.assert_called_once()
assert mock_log.call_args[1]["kind"] == "http"
assert isinstance(mock_log.call_args[1]["exc"], ConnectionError)

with mock.patch.object(
_observability, "log_transport_attempt", side_effect=RuntimeError("log crash")
):
ctx_err = _observability._TraceContext(method="GET", url="https://example.com")
ctx_err.record_error(ConnectionError("fail-open"))
ctx_err.record_response(mock.Mock(status_code=500, headers={}))
ctx_err.record_response(mock.Mock(status_code="invalid", headers={}))

class BadTextResponse:
status_code = 500
headers: dict = {}

@property
def text(self):
raise RuntimeError("broken text")

reason = "Fallback Reason"

assert (
_observability._TraceContext._extract_http_error_message(BadTextResponse())
== "Fallback Reason"
)

monkeypatch.setenv("GOOGLE_SDK_EXPERIMENTAL_PYTHON_TRACING_ENABLED", "true")
mock_parent_span = mock.MagicMock()
mock_parent_span.is_recording.return_value = True
mock_parent_span.attributes = {}
mock_parent_span.set_attribute.side_effect = RuntimeError("parent attr crash")
mock_otel = mock.MagicMock()
mock_otel.trace.get_current_span.return_value = mock_parent_span
monkeypatch.setitem(sys.modules, "opentelemetry", mock_otel)
monkeypatch.setitem(sys.modules, "opentelemetry.trace", mock_otel.trace)
monkeypatch.setitem(sys.modules, "opentelemetry.instrumentation.grpc", mock.Mock())
with _observability.trace_http_request(
method="GET", url="https://example.com/v1/echo", url_template="/v1/echo"
):
pass
Loading