Log response payload for better troubleshooting (#320)

Author: sungkkim

src/main/java/software/amazon/cloudformation/AbstractWrapper.java

@@ -231,7 +231,7 @@ public void processRequest(final InputStream inputStream, final OutputStream out
         } finally {
             // A response will be output on all paths, though CloudFormation will
             // not block on invoking the handlers, but rather listen for callbacks
-            writeResponse(outputStream, handlerResponse);
+            writeResponse(outputStream, handlerResponse, request);
             publishExceptionCodeAndCountMetrics(request == null ? null : request.getAction(), handlerResponse.getErrorCode());
         }
     }
@@ -372,7 +372,9 @@ public void processRequest(final InputStream inputStream, final OutputStream out
 
     }
 
-    protected void writeResponse(final OutputStream outputStream, final ProgressEvent<ResourceT, CallbackT> response)
+    protected void writeResponse(final OutputStream outputStream,
+                                 final ProgressEvent<ResourceT, CallbackT> response,
+                                 final HandlerRequest<ResourceT, CallbackT> request)
         throws IOException {
         if (response.getResourceModel() != null) {
             // strip write only properties on final results, we will need the intact model
@@ -383,10 +385,21 @@ protected void writeResponse(final OutputStream outputStream, final ProgressEven
         }
 
         String output = this.serializer.serialize(response);
+        if (response.getStatus() != OperationStatus.IN_PROGRESS) {
+            // if status is not IN_PROGRESS, it means the response has been sanitized
+            final String logicalResourceId = getLogicalResourceId(request);
+            final String stackId = getStackId(request);
+            this.log(String.format("StackId=%s LogicalResourceId=%s Response=%s", stackId, logicalResourceId, output));
+        }
         outputStream.write(output.getBytes(StandardCharsets.UTF_8));
         outputStream.flush();
     }
 
+    protected void writeResponse(final OutputStream outputStream, final ProgressEvent<ResourceT, CallbackT> response)
+        throws IOException {
+        this.writeResponse(outputStream, response, null);
+    }
+
     protected ResourceT sanitizeModel(final ResourceT model) throws IOException {
         // strip write only properties on final results, we will need the intact model
         // while provisioning
@@ -570,6 +583,15 @@ protected String getStackId(final HandlerRequest<ResourceT, CallbackT> request)
         return null;
     }
 
+    @VisibleForTesting
+    protected String getLogicalResourceId(final HandlerRequest<ResourceT, CallbackT> request) {
+        if (request != null && request.getRequestData() != null) {
+            return request.getRequestData().getLogicalResourceId();
+        }
+
+        return null;
+    }
+
     private void replaceInMap(final Map<String, String> targetMap, final Map<String, String> sourceMap) {
         if (targetMap == null) {
             return;

src/test/java/software/amazon/cloudformation/WrapperTest.java

@@ -160,7 +160,7 @@ public void invokeHandler_nullResponse_returnsFailure(final String requestDataPa
             }
 
             verify(providerEventsLogger).refreshClient();
-            verify(providerEventsLogger, times(2)).publishLogEvent(any());
+            verify(providerEventsLogger, times(3)).publishLogEvent(any());
             verifyNoMoreInteractions(providerEventsLogger);
 
             // verify output response
@@ -1029,4 +1029,14 @@ public void getStackId_setAndGetStackId() {
         assertThat(stackId).isNotNull();
         assertThat(stackId).isEqualTo("AWSStackId");
     }
+
+    @Test
+    public void getLogicalResourceId_setAndGetLogicalResourceId() {
+        final HandlerRequest<TestModel, TestContext> request = new HandlerRequest<>();
+        final RequestData<TestModel> requestData = new RequestData<>();
+        requestData.setLogicalResourceId("MyResource");
+        request.setRequestData(requestData);
+
+        assertThat(wrapper.getLogicalResourceId(request)).isEqualTo("MyResource");
+    }
 }