Skip to content

Conversation

@parthea
Copy link
Contributor

@parthea parthea commented Feb 19, 2025

Fixes #2279

Also see necessary changes in googleapis/python-api-core#794 to add logging in the response iterator each time a chunk is received in the stream.

Sync Unary->Stream

tests/system/test_streams.py 
{"timestamp": "2025-02-19 15:53:40,687", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.client", "message": "Created client `google.showcase_v1beta1.EchoClient`.", "serviceName": "google.showcase.v1beta1.Echo", "credentialsType": "google.auth.credentials.AnonymousCredentials", "universeDomain": "googleapis.com"}
{"timestamp": "2025-02-19 15:53:40,696", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.transports.rest", "message": "Sending request for google.showcase_v1beta1.EchoClient.Expand", "httpRequest": {"payload": "{\n  \"content\": \"The hail in Wales falls mainly on the snails.\"\n}", "requestMethod": "post", "requestUrl": "http://localhost:7469/v1beta1/echo:expand", "headers": {"showcase-trailer": "hello world", "x-goog-api-version": "v1_20240408", "x-goog-api-client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0"}}, "rpcName": "Expand", "serviceName": "google.showcase.v1beta1.Echo", "metadata": {"showcase-trailer": "hello world", "x-goog-api-version": "v1_20240408", "x-goog-api-client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0"}}
{"timestamp": "2025-02-19 15:53:40,723", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.transports.rest", "message": "Received response for google.showcase_v1beta1.EchoClient.expand", "rpcName": "Expand", "serviceName": "google.showcase.v1beta1.Echo", "metadata": {"X-Showcase-Request-Accept": "*/*", "X-Showcase-Request-Accept-Encoding": "gzip, deflate", "X-Showcase-Request-Connection": "keep-alive", "X-Showcase-Request-Content-Length": "64", "X-Showcase-Request-Content-Type": "application/json", "X-Showcase-Request-Showcase-Trailer": "hello world", "X-Showcase-Request-User-Agent": "python-requests/2.32.3", "X-Showcase-Request-X-Goog-Api-Client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0", "X-Showcase-Request-X-Goog-Api-Version": "v1_20240408", "Date": "Wed, 19 Feb 2025 15:53:40 GMT", "Content-Type": "text/plain; charset=utf-8", "Transfer-Encoding": "chunked"}, "httpResponse": {"payload": null, "headers": {"X-Showcase-Request-Accept": "*/*", "X-Showcase-Request-Accept-Encoding": "gzip, deflate", "X-Showcase-Request-Connection": "keep-alive", "X-Showcase-Request-Content-Length": "64", "X-Showcase-Request-Content-Type": "application/json", "X-Showcase-Request-Showcase-Trailer": "hello world", "X-Showcase-Request-User-Agent": "python-requests/2.32.3", "X-Showcase-Request-X-Goog-Api-Client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0", "X-Showcase-Request-X-Goog-Api-Version": "v1_20240408", "Date": "Wed, 19 Feb 2025 15:53:40 GMT", "Content-Type": "text/plain; charset=utf-8", "Transfer-Encoding": "chunked"}, "status": 200}}
{"timestamp": "2025-02-19 15:53:40,727", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"The\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,731", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"hail\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,734", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"in\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,737", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"Wales\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,740", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"falls\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,743", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"mainly\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,746", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"on\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,750", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"the\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:53:40,753", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"snails.\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}

Async Unary->Stream

tests/system/test_streams.py 
{"timestamp": "2025-02-19 15:52:17,150", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.async_client", "message": "Created client `google.showcase_v1beta1.EchoAsyncClient`.", "serviceName": "google.showcase.v1beta1.Echo", "credentialsType": "google.auth.aio.credentials.AnonymousCredentials", "universeDomain": ""}
{"timestamp": "2025-02-19 15:52:17,159", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.transports.rest_asyncio", "message": "Sending request for google.showcase_v1beta1.EchoClient.Expand", "httpRequest": {"payload": "{\n  \"content\": \"The hail in Wales falls mainly on the snails.\"\n}", "requestMethod": "post", "requestUrl": "http://localhost:7469/v1beta1/echo:expand", "headers": {"showcase-trailer": "hello world", "x-goog-api-version": "v1_20240408", "x-goog-api-client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0"}}, "rpcName": "Expand", "serviceName": "google.showcase.v1beta1.Echo", "metadata": {"showcase-trailer": "hello world", "x-goog-api-version": "v1_20240408", "x-goog-api-client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0"}}
{"timestamp": "2025-02-19 15:52:17,189", "severity": "DEBUG", "name": "google.showcase_v1beta1.services.echo.transports.rest_asyncio", "message": "Received response for google.showcase_v1beta1.EchoAsyncClient.expand", "rpcName": "Expand", "serviceName": "google.showcase.v1beta1.Echo", "metadata": {"X-Showcase-Request-Accept": "*/*", "X-Showcase-Request-Accept-Encoding": "gzip, deflate", "X-Showcase-Request-Content-Length": "64", "X-Showcase-Request-Content-Type": "application/json", "X-Showcase-Request-Showcase-Trailer": "hello world", "X-Showcase-Request-User-Agent": "Python/3.9 aiohttp/3.10.10", "X-Showcase-Request-X-Goog-Api-Client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0", "X-Showcase-Request-X-Goog-Api-Version": "v1_20240408", "Date": "Wed, 19 Feb 2025 15:52:17 GMT", "Content-Type": "text/plain; charset=utf-8", "Transfer-Encoding": "chunked"}, "httpResponse": {"payload": null, "headers": {"X-Showcase-Request-Accept": "*/*", "X-Showcase-Request-Accept-Encoding": "gzip, deflate", "X-Showcase-Request-Content-Length": "64", "X-Showcase-Request-Content-Type": "application/json", "X-Showcase-Request-Showcase-Trailer": "hello world", "X-Showcase-Request-User-Agent": "Python/3.9 aiohttp/3.10.10", "X-Showcase-Request-X-Goog-Api-Client": "gl-python/3.9.16 rest/[email protected] gax/2.24.1 gapic/0.0.0", "X-Showcase-Request-X-Goog-Api-Version": "v1_20240408", "Date": "Wed, 19 Feb 2025 15:52:17 GMT", "Content-Type": "text/plain; charset=utf-8", "Transfer-Encoding": "chunked"}, "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,192", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"The\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,193", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"hail\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,193", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"in\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,194", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"Wales\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,194", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"falls\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,194", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"mainly\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,195", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"on\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,195", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"the\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}
{"timestamp": "2025-02-19 15:52:17,195", "severity": "DEBUG", "name": "google.api_core._rest_streaming_base", "message": "Received response via REST stream", "response": {"payload": "{\"content\":\"snails.\",\"severity\":\"UNNECESSARY\",\"requestId\":\"\",\"otherRequestId\":\"\"}", "status": "OK"}}

@product-auto-label product-auto-label bot added the size: s Pull request size is small. label Feb 19, 2025
@parthea parthea marked this pull request as ready for review February 19, 2025 16:09
@parthea parthea requested a review from a team as a code owner February 19, 2025 16:09
@parthea parthea requested review from ohmayr and vchudnov-g February 19, 2025 16:09
@parthea parthea force-pushed the add-unary-stream-logging-rest branch from 564342c to 5648ab2 Compare March 31, 2025 09:55
@parthea parthea force-pushed the add-unary-stream-logging-rest branch from 5648ab2 to 6478506 Compare March 31, 2025 10:03
{# TODO(https://github.com/googleapis/gapic-generator-python/issues/2279): Add logging support for rest streaming. #}
{% if not method.server_streaming %}
if CLIENT_LOGGING_SUPPORTED and _LOGGER.isEnabledFor(logging.DEBUG): # pragma: NO COVER
{# Logging of the streaming response payload is in `google-api-core` because the response #}
Copy link
Contributor

Choose a reason for hiding this comment

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

Depending how we want to log (a) receiving a streaming response vs (b) exposing the next streamed item to the user, we could possibly want to log something here
(a) should always happen in api-core
(b) could happen in api-core, or it could happen here when we iterate to the next streamed item that was previously received.

Ditto for async

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I filed #2389 to follow up on this and I also captured this comment in the code.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Updated comments in 58d6a89

@parthea parthea assigned parthea and unassigned vchudnov-g and ohmayr May 8, 2025
@parthea parthea changed the title feat: add client debug logging support for unary-stream REST calls feat: add client debug logging support for server side streaming REST calls May 9, 2025
…ce/transports/rest.py.j2

Co-authored-by: Victor Chudnovsky <[email protected]>
@parthea parthea enabled auto-merge (squash) May 9, 2025 14:09
@parthea parthea disabled auto-merge May 9, 2025 14:12
@parthea
Copy link
Contributor Author

parthea commented May 9, 2025

Client side streaming is not yet supported in REST transport (See #2279)

@parthea parthea enabled auto-merge (squash) May 9, 2025 14:30
@parthea parthea merged commit 8a705c5 into main May 9, 2025
122 checks passed
@parthea parthea deleted the add-unary-stream-logging-rest branch May 9, 2025 14:34
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size: s Pull request size is small.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[logging] Add client logging support for rest streaming

3 participants