Merge pull request #927 from commercetools/logger-fix

Fix Logger with unwrapped CompletionExceptions

Author: kodiakhq[bot]

rmf/rmf-java-base/src/main/java/io/vrap/rmf/base/client/http/InternalLoggerMiddlewareImpl.java

@@ -109,12 +109,10 @@ public CompletableFuture<ApiHttpResponse<byte[]>> invoke(final ApiHttpRequest re
                 requestContext.ifPresent(c -> MDC.setContextMap(c.getValue()));
                 Throwable cause = throwable instanceof CompletionException ? throwable.getCause() : throwable;
                 if (cause instanceof ApiHttpException) {
-                    final ApiHttpResponse<byte[]> errorResponse = ((ApiHttpException) throwable.getCause())
-                            .getResponse();
+                    final ApiHttpResponse<byte[]> errorResponse = ((ApiHttpException) cause).getResponse();
                     final Level level = exceptionLogEvents.entrySet()
                             .stream()
-                            .filter(classLevelEntry -> classLevelEntry.getKey()
-                                    .isAssignableFrom(throwable.getCause().getClass()))
+                            .filter(classLevelEntry -> classLevelEntry.getKey().isAssignableFrom(cause.getClass()))
                             .findFirst()
                             .map(Map.Entry::getValue)
                             .orElse(defaultExceptionLogEvent);

rmf/rmf-java-base/src/test/java/io/vrap/rmf/base/client/http/InternalLoggerMiddlewareTest.java

@@ -184,6 +184,35 @@ public void testLoggerException() {
         testLogAppender.stop();
     }
 
+    @Test
+    public void testLoggerUnwrappedException() {
+
+        TestLogAppender testLogAppender = new TestLogAppender();
+        ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger) LoggerFactory
+                .getLogger(Logger.ROOT_LOGGER_NAME);
+        logger.addAppender(testLogAppender);
+        testLogAppender.start();
+
+        final InternalLoggerMiddleware loggerMiddleware = InternalLoggerMiddleware
+                .of((request, topic) -> new TestLogger(logger));
+
+        ApiHttpRequest request = new ApiHttpRequest(ApiHttpMethod.GET, URI.create("https://api.commercetools.com/"),
+            new ApiHttpHeaders(), null);
+        CompletableFuture<ApiHttpResponse<byte[]>> f = new CompletableFuture<>();
+        ApiHttpResponse<byte[]> response = new ApiHttpResponse<>(400, new ApiHttpHeaders(),
+            "".getBytes(StandardCharsets.UTF_8));
+        f.completeExceptionally(new ApiHttpException(response.getStatusCode(), response.getBodyAsString().orElse(""),
+            response.getHeaders(), response));
+        loggerMiddleware.invoke(request, apiHttpRequest -> f);
+
+        Assertions.assertThat(testLogAppender.loggingEvents).hasSize(1);
+        Assertions.assertThat(testLogAppender.loggingEvents.get(0).getLevel()).isEqualTo(Level.ERROR);
+        Assertions.assertThat(testLogAppender.loggingEvents.get(0).getFormattedMessage())
+                .matches("GET https://api.commercetools.com/ 400 \\d+ - -");
+
+        testLogAppender.stop();
+    }
+
     static class TestLogAppender extends AppenderBase<ILoggingEvent> {
         ArrayList<ILoggingEvent> loggingEvents = new ArrayList<>();
 

rmf/rmf-java-base/src/test/resources/logback-test.xml

@@ -10,6 +10,7 @@
     </appender>
 
     <logger name="commercetools" level="INFO"/>
+    <logger name="org.reflections.Reflections" level="WARN" />
 
     <root level="INFO">
         <appender-ref ref="STDOUT" />