From e2096c14c22b93a3a31f62b33b1e7a65f2fc2940 Mon Sep 17 00:00:00 2001 From: jonathan343 Date: Fri, 28 Feb 2025 10:58:23 -0500 Subject: [PATCH 1/4] Add basic debug log statements; Remove lazy string evaluation --- .../python/codegen/ClientGenerator.java | 39 ++++++++++++++----- .../generators/StructureGenerator.java | 2 +- .../codegen/generators/UnionGenerator.java | 2 +- 3 files changed, 31 insertions(+), 12 deletions(-) diff --git a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java index e24305226..9e020feeb 100644 --- a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java +++ b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java @@ -229,7 +229,7 @@ async def _handle_execution( event_response_deserializer: DeserializeableShape | None = None, ${/hasEventStream} ) -> Output: - logger.debug(f"Making request for operation {operation_name} with parameters: {input}") + logger.debug('Making request for operation "%s" with parameters: %s', operation_name, input) context: InterceptorContext[Input, None, None, None] = InterceptorContext( request=input, response=None, @@ -326,17 +326,26 @@ async def _handle_execution( ) except SmithyRetryException: raise context_with_response.response + logger.debug( + "Retry needed. Attempting request #%s in %s seconds.", + retry_token.retry_count + 1, + retry_token.retry_delay + ) await sleep(retry_token.retry_delay) current_body = context_with_transport_request.transport_request.body if (seek := getattr(current_body, "seek", None)) is not None: await seek(0) else: # Step 8: Invoke record_success + logger.debug( + "Attempt %s succeeded. Not retrying request.", + retry_token.retry_count + 1 + ) retry_strategy.record_success(token=retry_token) break except Exception as e: if context.response is not None: - logger.exception(f"Exception occurred while handling: {context.response}") + logger.exception("Exception occurred while handling: %s", context.response) pass context._response = e @@ -443,10 +452,12 @@ async def _handle_attempt( raise $1T( "No endpoint_uri found on the operation config." ) - + endpoint_resolver_parameters = StaticEndpointParams(uri=config.endpoint_uri) + logger.debug("Calling endpoint resolver with parameters: %s", endpoint_resolver_parameters) endpoint = await config.endpoint_resolver.resolve_endpoint( - StaticEndpointParams(uri=config.endpoint_uri) + endpoint_resolver_parameters ) + logger.debug("Endpoint resolver result: %s", endpoint) if not endpoint.uri.path: path = "" elif endpoint.uri.path.endswith("/"): @@ -484,6 +495,11 @@ async def _handle_attempt( writer.write(""" # Step 7i: sign the request if auth_option and signer: + logger.debug("HTTP request to sign: %s", context.transport_request) + logger.debug( + "Signer properties: %s", + auth_option.signer_properties + ) context._transport_request = await signer.sign( http_request=context.transport_request, identity=identity, @@ -518,10 +534,13 @@ async def _handle_attempt( context_with_response = cast( InterceptorContext[Input, None, $1T, $2T], context ) + logger.debug("HTTP request config: %s", request_config) + logger.debug("Sending HTTP request: %s", context_with_response.transport_request) context_with_response._transport_response = await config.http_client.send( request=context_with_response.transport_request, request_config=request_config, ) + logger.debug("Received HTTP response: %s", context_with_response.transport_response) """, transportRequest, transportResponse); } @@ -556,7 +575,7 @@ async def _handle_attempt( interceptor.read_after_deserialization(context_with_output) except Exception as e: if context.response is not None: - logger.exception(f"Exception occurred while handling: {context.response}") + logger.exception("Exception occurred while handling: %s", context.response) pass context._response = e @@ -582,7 +601,7 @@ async def _finalize_attempt( ) except Exception as e: if context.response is not None: - logger.exception(f"Exception occurred while handling: {context.response}") + logger.exception("Exception occurred while handling: %s", context.response) pass context._response = e @@ -592,7 +611,7 @@ async def _finalize_attempt( interceptor.read_after_attempt(context) except Exception as e: if context.response is not None: - logger.exception(f"Exception occurred while handling: {context.response}") + logger.exception("Exception occurred while handling: %s", context.response) pass context._response = e @@ -613,11 +632,11 @@ async def _finalize_execution( pass except Exception as e: # log and ignore exceptions - logger.exception(f"Exception occurred while dispatching trace events: {e}") + logger.exception("Exception occurred while dispatching trace events: %s", e) pass except Exception as e: if context.response is not None: - logger.exception(f"Exception occurred while handling: {context.response}") + logger.exception("Exception occurred while handling: %s", context.response) pass context._response = e @@ -627,7 +646,7 @@ async def _finalize_execution( interceptor.read_after_execution(context) except Exception as e: if context.response is not None: - logger.exception(f"Exception occurred while handling: {context.response}") + logger.exception("Exception occurred while handling: %s", context.response) pass context._response = e diff --git a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java index a1d5658ad..4d082e81d 100644 --- a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java +++ b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java @@ -412,7 +412,7 @@ def _consumer(schema: Schema, de: ShapeDeserializer) -> None: match schema.expect_member_index(): ${C|} case _: - logger.debug(f"Unexpected member schema: {schema}") + logger.debug("Unexpected member schema: %s", schema) deserializer.read_struct($T, consumer=_consumer) return kwargs diff --git a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/UnionGenerator.java b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/UnionGenerator.java index 7996375d0..e592460d9 100644 --- a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/UnionGenerator.java +++ b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/UnionGenerator.java @@ -162,7 +162,7 @@ def _consumer(self, schema: Schema, de: ShapeDeserializer) -> None: match schema.expect_member_index(): ${4C|} case _: - logger.debug(f"Unexpected member schema: {schema}") + logger.debug("Unexpected member schema: %s", schema) def _set_result(self, value: $2T) -> None: if self._result is not None: From 36b28c71fa60e109aa90b1bf5088509a8ecd6ca6 Mon Sep 17 00:00:00 2001 From: jonathan343 Date: Fri, 28 Feb 2025 15:28:56 -0500 Subject: [PATCH 2/4] only print 4 decimal values for retry delay --- .../software/amazon/smithy/python/codegen/ClientGenerator.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java index 9e020feeb..ec56b822d 100644 --- a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java +++ b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java @@ -327,7 +327,7 @@ async def _handle_execution( except SmithyRetryException: raise context_with_response.response logger.debug( - "Retry needed. Attempting request #%s in %s seconds.", + "Retry needed. Attempting request #%s in %.4f seconds.", retry_token.retry_count + 1, retry_token.retry_delay ) From c9ff85cc879e76af5ead63370dd2f529be22f989 Mon Sep 17 00:00:00 2001 From: jonathan343 Date: Mon, 3 Mar 2025 00:42:50 -0500 Subject: [PATCH 3/4] Check structure members targeted shape for sensitive trait --- .../codegen/generators/StructureGenerator.java | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java index 4d082e81d..a91d63000 100644 --- a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java +++ b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/generators/StructureGenerator.java @@ -158,14 +158,16 @@ class $1L($2T): private void writeProperties() { for (MemberShape member : requiredMembers) { writer.pushState(); - writer.putContext("sensitive", false); - if (member.hasTrait(SensitiveTrait.class)) { + var target = model.expectShape(member.getTarget()); + + if (target.hasTrait(SensitiveTrait.class)) { writer.addStdlibImport("dataclasses", "field"); writer.putContext("sensitive", true); + } else { + writer.putContext("sensitive", false); } var memberName = symbolProvider.toMemberName(member); - var target = model.expectShape(member.getTarget()); writer.putContext("quote", recursiveShapes.contains(target) ? "'" : ""); writer.write(""" $L: ${quote:L}$T${quote:L}\ @@ -178,9 +180,10 @@ private void writeProperties() { for (MemberShape member : optionalMembers) { writer.pushState(); + var target = model.expectShape(member.getTarget()); var requiresField = false; - if (member.hasTrait(SensitiveTrait.class)) { + if (target.hasTrait(SensitiveTrait.class)) { writer.putContext("sensitive", true); writer.addStdlibImport("dataclasses", "field"); requiresField = true; @@ -191,7 +194,7 @@ private void writeProperties() { var defaultValue = "None"; var defaultKey = "default"; if (member.hasTrait(DefaultTrait.class)) { - var target = model.expectShape(member.getTarget()); + defaultValue = getDefaultValue(writer, member); if (target.isDocumentShape() || Set.of("list", "dict").contains(defaultValue)) { writer.addStdlibImport("dataclasses", "field"); @@ -206,7 +209,6 @@ private void writeProperties() { writer.putContext("defaultValue", defaultValue); writer.putContext("useField", requiresField); - var target = model.expectShape(member.getTarget()); writer.putContext("quote", recursiveShapes.contains(target) ? "'" : ""); var memberName = symbolProvider.toMemberName(member); From 7d90ac5ff71221af5b51649ea9b9a12adb739193 Mon Sep 17 00:00:00 2001 From: jonathan343 Date: Mon, 3 Mar 2025 00:44:09 -0500 Subject: [PATCH 4/4] Add more log messages --- .../amazon/smithy/python/codegen/ClientGenerator.java | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java index ec56b822d..5aa42d257 100644 --- a/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java +++ b/codegen/core/src/main/java/software/amazon/smithy/python/codegen/ClientGenerator.java @@ -153,6 +153,7 @@ def _classify_error( error: Exception, context: InterceptorContext[Input, Output, $1T, $2T | None] ) -> RetryErrorInfo: + logger.debug("Classifying error: %s", error) """, transportRequest, transportResponse); writer.indent(); @@ -276,9 +277,11 @@ async def _handle_execution( context_with_transport_request = cast( InterceptorContext[Input, None, $2T, None], context ) + logger.debug("Serializing request for: %s", context_with_transport_request.request) context_with_transport_request._transport_request = await serialize( context_with_transport_request.request, config ) + logger.debug("Serialization complete. Transport request: %s", context_with_transport_request._transport_request) # Step 5: Invoke read_after_serialization for interceptor in interceptors: @@ -337,10 +340,6 @@ await sleep(retry_token.retry_delay) await seek(0) else: # Step 8: Invoke record_success - logger.debug( - "Attempt %s succeeded. Not retrying request.", - retry_token.retry_count + 1 - ) retry_strategy.record_success(token=retry_token) break except Exception as e: @@ -505,6 +504,7 @@ async def _handle_attempt( identity=identity, signing_properties=auth_option.signer_properties, ) + logger.debug("Signed HTTP request: %s", context._transport_request) """); } writer.popState(); @@ -566,9 +566,11 @@ async def _handle_attempt( InterceptorContext[Input, Output, $1T, $2T], context_with_response, ) + logger.debug("Deserializing transport response: %s", context_with_output._transport_response) context_with_output._response = await deserialize( context_with_output._transport_response, config ) + logger.debug("Deserialization complete. Response: %s", context_with_output._response) # Step 7r: Invoke read_after_deserialization for interceptor in interceptors: