- Notifications
You must be signed in to change notification settings - Fork90
feat: add client debug logging support for streaming gRPC/REST calls#794
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 ourterms of service andprivacy statement. We’ll occasionally send you account related emails.
Already on GitHub?Sign in to your account
base:main
Are you sure you want to change the base?
Uh oh!
There was an error while loading.Please reload this page.
Conversation
ae07484 to3b29113Compare739a255 tofdf6bd6Compare8908765 to9fac30cCompare| @@ -97,19 +100,38 @@ def _process_chunk(self, chunk: str): | |||
| self._obj += char | |||
| self._escape_next = not self._escape_next if char == "\\" else False | |||
| def _log_response_payload(self, response_payload: str): # pragma: NO COVER | |||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
Why do we need to skip coverage here?
| _LOGGER.debug( | ||
| "Received response via REST stream", | ||
| extra={ | ||
| "response": rest_response, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
should we be usinghttpResponse here instead for structured logs?
| ) | ||
| return grab | ||
| elif issubclass(self._response_message_cls, google.protobuf.message.Message): | ||
| def grab(this): | ||
| return Parse(this._ready_objs.popleft(), this._response_message_cls()) | ||
| response_payload = this._ready_objs.popleft() | ||
| if logging_enabled: # pragma: NO COVER |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
Can we add coverage for this?
| else: | ||
| result = next(self._wrapped) | ||
| logging_enabled = _LOGGER.isEnabledFor(logging.DEBUG) | ||
| if logging_enabled: # pragma: NO COVER | ||
| if isinstance(result, proto.Message): | ||
| response_payload = type(result).to_json(result) | ||
| elif isinstance(result, google.protobuf.message.Message): | ||
| response_payload = google.protobuf.json_format.MessageToJson(result) | ||
| else: | ||
| response_payload = ( | ||
| f"{type(result).__name__}: {str(pickle.dumps(result))}" | ||
| ) | ||
| grpc_response = { | ||
| "payload": response_payload, | ||
| "status": "OK", | ||
| } | ||
| _LOGGER.debug( | ||
| f"Received response of type {type(result)} via gRPC stream", | ||
| extra={ | ||
| "response": grpc_response, | ||
| }, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
Can this be added as a helper function and re-used ingrpc_helpers_async?
| result = await self._call.read() | ||
| logging_enabled = _LOGGER.isEnabledFor(logging.DEBUG) | ||
| if logging_enabled: # pragma: NO COVER | ||
| if isinstance(result, proto.Message): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
Can you link
{# TODO(https://github.com/googleapis/gapic-generator-python/issues/2293): Investigate if we can improve this logic or wait for next gen protobuf. #}There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
Also, can the parsing logic be added as a helper function and re-used in the gapic? We can file a TODO for the latter.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
+1
This ties into the issue I still want to get back to b/382299158. Maybe we reference that issue instead of creating a new one, and in that issue we reference these changes so we have easy access.
| rest_response = { | ||
| "payload": response_payload, | ||
| "status": "OK", | ||
| } | ||
| _LOGGER.debug( | ||
| "Received response via REST stream", | ||
| extra={ | ||
| "response": rest_response, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
I'm not sure we should be using/reference any sort of HTTP response here at all. This helper is being called fromgrab, andgrab simply passes already received messages reconstituted from chunks. So what we should log ingrab is something likepassing next message to stream: <message>.
We should log http responses where we actually receive the HTTP chunks.
| grpc_response = { | ||
| "payload": response_payload, | ||
| "status": "OK", |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
As in the REST case, I don't think we should be logging things here as though we're receiving a response from the server. We should log that we're passing the next item in the stream. (Because, for example, we might be getting_stored_first_result that was received and stored earlier.)
So let's log that we're returning the next item here, but wherever we do receive the item from the server (is itnext(self.wrapped)?), we should log that wereceived X message from the server: <msg> <msg> ....
IOW, let's not conflate for ourselves or our users receiving the streaming data from the server vs passing eached streamed message to the GAPIC user. This is particularly important for async streaming.
| result = await self._call.read() | ||
| logging_enabled = _LOGGER.isEnabledFor(logging.DEBUG) | ||
| if logging_enabled: # pragma: NO COVER | ||
| if isinstance(result, proto.Message): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
+1
This ties into the issue I still want to get back to b/382299158. Maybe we reference that issue instead of creating a new one, and in that issue we reference these changes so we have easy access.
| @@ -94,7 +100,28 @@ def __init__(self): | |||
| async def read(self) -> P: | |||
| try: | |||
| return await self._call.read() | |||
| result = await self._call.read() | |||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others.Learn more.
IIUC, this gRPC doing an actual read from the network, so logging it as such below makes sense.
(just pointing this out to contrast with my other comments about logging returning previously streamed messages to the user)
Also, could you referencegoogleapis/gapic-generator-python#2289 rather than the mirrored internal issue in this PR's description? |
Uh oh!
There was an error while loading.Please reload this page.
Towards b/383403001