Skip to content

feat: add client debug logging support for server side streaming REST calls #2340

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

Jump to bottom
Merged
merged 5 commits into from
May 9, 2025
Merged

feat: add client debug logging support for server side streaming REST calls #2340

merged 5 commits into from
May 9, 2025

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/requests@2.32.3 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/requests@2.32.3 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/requests@2.32.3 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/requests@2.32.3 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/google-auth@2.38.0 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/google-auth@2.38.0 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/google-auth@2.38.0 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/google-auth@2.38.0 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 vchudnov-g and ohmayr 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
vchudnov-g
vchudnov-g reviewed Apr 3, 2025
View reviewed changes
gapic/templates/%namespace/%name_%version/%sub/services/%service/transports/rest.py.j2 Outdated
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
@parthea @vchudnov-g
Update gapic/templates/%namespace/%name_%version/%sub/services/%servi…
0dda26a 
…ce/transports/rest.py.j2

Co-authored-by: Victor Chudnovsky <vchudnov@google.com>
@parthea parthea mentioned this pull request May 9, 2025
Open
@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
@release-please release-please bot mentioned this pull request May 9, 2025
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@vchudnov-g vchudnov-g vchudnov-g left review comments

@ohmayr ohmayr ohmayr approved these changes

Assignees

@parthea parthea

Labels
size: s Pull request size is small.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

[logging] Add client logging support for rest streaming
3 participants
@parthea @vchudnov-g @ohmayr