Skip to content

Add request/response debug logging#2266

Closed
parthea wants to merge 25 commits intomainfrom
add-debug-log-sending-request
Closed

Add request/response debug logging#2266
parthea wants to merge 25 commits intomainfrom
add-debug-log-sending-request

Conversation

@parthea
Copy link
Contributor

@parthea parthea commented Nov 29, 2024

This PR was built on top of #2265

Example debug logs

{"timestamp": "2024-11-29 12:30:05,731", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.client", "message": "Created client `google.showcase_v1beta1.EchoClient`.", "serviceName": "google.showcase.v1beta1.Echo", "universeDomain": "googleapis.com", "credentialType": "google.oauth2.credentials.Credentials", "credentialInfo": {"credential_source": "REDACTED", "credential_type": "user credentials"}}

{"timestamp": "2024-11-29 12:30:07,220", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.client", "message": "Sending request via google.showcase_v1beta1.EchoClient.echo", "rpcName": "Echo", "serviceName": "google.showcase.v1beta1.Echo", "request": "{\n  \"content\": \"The hail in Wales falls mainly on the snails.\",\n  \"requestId\": \"some_value\",\n  \"otherRequestId\": \"\",\n  \"severity\": 0,\n  \"header\": \"\",\n  \"otherHeader\": \"\"\n}", "retryAttempt": 1, "metadata": "{'some-key-bin': b'some_value', 'x-goog-api-version': 'v1_20240408'}"}

@product-auto-label product-auto-label bot added the size: s Pull request size is small. label Nov 29, 2024
@parthea parthea changed the title Add debug log when sending request Add request/response debug logging Nov 29, 2024
@product-auto-label product-auto-label bot added size: m Pull request size is medium. and removed size: s Pull request size is small. labels Nov 29, 2024
@product-auto-label product-auto-label bot added size: l Pull request size is large. and removed size: m Pull request size is medium. labels Dec 2, 2024
"serviceName": "{{ service.meta.address.proto }}",
"rpcName": "{{ method_name }}",
"retryAttempt": 1,
"request": type(request).to_json(request),
Copy link
Contributor

Choose a reason for hiding this comment

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

Does this request / metadata include request method and request url? We can extract that information out from the http_options defined above.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

No, I didn't include request method or url. We need to add those fields to google-api-core first
https://github.com/googleapis/python-api-core/blob/d18d9b5131162b44eebcc0859a7aca1198a2ac06/google/api_core/client_logging.py#L13-L24

Copy link
Contributor

Choose a reason for hiding this comment

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

Do we want the fields to just be part of metadata or request? In that case, adding these fields in google-api-core may not be required.

Adding a TODO comment here linking to an issue would be helpful to understand what's missing.

Copy link
Contributor

Choose a reason for hiding this comment

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

The structured logging fields include httpRequest which includes requestMethod and requestUrl.

So we should populate those subfields of httpRequest, which is already registered in api-core.

if CLIENT_LOGGING_SUPPORTED and _LOGGER.isEnabledFor(std_logging.DEBUG): # pragma: NO COVER
# TODO: Make this performant when logging is not enabled

credential_info = None
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
credential_info = None

if "async" not in str(self._transport):
if CLIENT_LOGGING_SUPPORTED and _LOGGER.isEnabledFor(std_logging.DEBUG): # pragma: NO COVER

credential_info = None
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
credential_info = None

Comment on lines +47 to +51
try:
from google.api_core import client_logging
CLIENT_LOGGING_SUPPORTED = True
except ImportError:
CLIENT_LOGGING_SUPPORTED = False
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
try:
from google.api_core import client_logging
CLIENT_LOGGING_SUPPORTED = True
except ImportError:
CLIENT_LOGGING_SUPPORTED = False
try: # pragma: NO COVER
from google.api_core import client_logging. # type: ignore
CLIENT_LOGGING_SUPPORTED = True
except ImportError:
CLIENT_LOGGING_SUPPORTED = False

Comment on lines +53 to +54
import logging
_LOGGER = logging.getLogger(__name__)
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
import logging
_LOGGER = logging.getLogger(__name__)
import logging as std_logging
_LOGGER = std_logging.getLogger(__name__)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

We don't need std_logging here because we don't directly import any generated types in this file

Base automatically changed from initialize-logging to main December 3, 2024 11:32
@parthea
Copy link
Contributor Author

parthea commented Dec 3, 2024

The REST specific changes were moved to a new PR: #2270

is_async (bool): Used to determine the code path i.e. whether for sync or async call. #}
{% macro rest_call_method_common(body_spec, method_name, service_name, is_async=False) %}
{% macro rest_call_method_common(body_spec, method_name, service, is_async=False) %}
{% set service_name = service.name %}
Copy link
Contributor

Choose a reason for hiding this comment

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

nit: Does using service_name instead of service.name in the template buy us anything? They read the same, they're the same number of characters. Does service change in the course of this macro?

"serviceName": "{{ service.meta.address.proto }}",
"rpcName": "{{ method_name }}",
"retryAttempt": 1,
"request": type(request).to_json(request),
Copy link
Contributor

Choose a reason for hiding this comment

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

The structured logging fields include httpRequest which includes requestMethod and requestUrl.

So we should populate those subfields of httpRequest, which is already registered in api-core.

@vchudnov-g
Copy link
Contributor

Is this PR obsolete in favor of #2270 and #2271 ?

@ohmayr ohmayr closed this Dec 11, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size: l Pull request size is large.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants