Limit the length of logged responses in outgoingRequestLog

Currently truncated after 1 MB.

Issue-ID: VID-804

Change-Id: Ic99c33eede488db60c296d7272850cadee9f2925
Signed-off-by: Ittay Stern <ittay.stern@att.com>

diff --git a/vid-app-common/src/main/java/org/onap/vid/utils/Logging.java b/vid-app-common/src/main/java/org/onap/vid/utils/Logging.java
index f9894d1..ce811b4 100644 (file)
--- a/vid-app-common/src/main/java/org/onap/vid/utils/Logging.java
+++ b/vid-app-common/src/main/java/org/onap/vid/utils/Logging.java
@@ -35,6 +35,7 @@ import io.joshworks.restclient.http.HttpResponse;
 import java.nio.charset.StandardCharsets;
 import java.util.Arrays;
 import java.util.Map;
+import java.util.Objects;
 import java.util.Optional;
 import java.util.UUID;
 import java.util.concurrent.Callable;
@@ -122,7 +123,7 @@ public class Logging {
         }
         try {
             response.bufferEntity();
-            logger.debug("Received {} {} Status: {} . Body: {}", method.name(), url, response.getStatus(), response.readEntity(entityClass));
+            logger.debug("Received {} {} Status: {} . Body: {}", method.name(), url, response.getStatus(), new Substring(response.readEntity(entityClass)));
         }
         catch (Exception e) {
             logger.debug("Received {} {} Status: {} . Failed to read response as {}", method.name(), url, response.getStatus(), entityClass.getName());
@@ -132,7 +133,7 @@ public class Logging {
     public <T> void logResponse(final EELFLogger logger, final HttpMethod method, final String url, final HttpResponse<T> response) {
         try {
             logger.debug("Received {} {} Status: {} . Body: {}", method.name(),
-                url, response.getStatus(), IOUtils.toString(response.getRawBody(), StandardCharsets.UTF_8));
+                url, response.getStatus(), new Substring(IOUtils.toString(response.getRawBody(), StandardCharsets.UTF_8)));
             response.getRawBody().reset();
         }
         catch (Exception e) {
@@ -203,6 +204,26 @@ public class Logging {
         }
     }
 
+    /**
+     * This class defers the toString() and truncation to the point in time where logger needs it.
+     * This will save some bytes in memory if logger will decide to discard the logging (mostly because logging level
+     * is filtering the message out).
+     */
+    static class Substring {
+        private final Object obj;
+        private final int maxLen = 1_000_000;
+
+        public Substring(Object obj) {
+            this.obj = obj;
+        }
+
+        @Override
+        public String toString() {
+            // null safe truncation
+            return StringUtils.left(Objects.toString(obj), maxLen);
+        }
+    }
+
     /**
      * in order to be able to write the correct data while creating the node on a new thread save a copy of the current
      * thread's context map, with keys and values of type String.

diff --git a/vid-app-common/src/test/java/org/onap/vid/utils/LoggingUtilsTest.java b/vid-app-common/src/test/java/org/onap/vid/utils/LoggingUtilsTest.java
index c2a1f28..8c3aa64 100644 (file)
--- a/vid-app-common/src/test/java/org/onap/vid/utils/LoggingUtilsTest.java
+++ b/vid-app-common/src/test/java/org/onap/vid/utils/LoggingUtilsTest.java
@@ -21,15 +21,20 @@
 package org.onap.vid.utils;
 
 import static net.javacrumbs.jsonunit.JsonMatchers.jsonEquals;
+import static org.apache.commons.lang3.StringUtils.repeat;
 import static org.hamcrest.CoreMatchers.is;
 import static org.hamcrest.CoreMatchers.not;
 import static org.hamcrest.CoreMatchers.sameInstance;
 import static org.hamcrest.MatcherAssert.assertThat;
+import static org.hamcrest.Matchers.equalTo;
 import static org.hamcrest.Matchers.hasEntry;
+import static org.hamcrest.Matchers.hasToString;
 import static org.hamcrest.Matchers.matchesPattern;
+import static org.hamcrest.Matchers.samePropertyValuesAs;
 import static org.mockito.ArgumentMatchers.contains;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
 import static org.onap.vid.testUtils.RegExMatcher.matchesRegEx;
 import static org.testng.AssertJUnit.assertEquals;
 
@@ -53,6 +58,7 @@ import org.apache.commons.io.IOUtils;
 import org.mockito.ArgumentCaptor;
 import org.onap.vid.exceptions.GenericUncheckedException;
 import org.onap.vid.testUtils.TestUtils;
+import org.onap.vid.utils.Logging.Substring;
 import org.slf4j.MDC;
 import org.springframework.http.HttpMethod;
 import org.testng.annotations.BeforeMethod;
@@ -116,7 +122,7 @@ public class LoggingUtilsTest {
         assertEquals("POST", argumentCaptor.getAllValues().get(0));
         assertEquals(url, argumentCaptor.getAllValues().get(1));
         assertEquals(200, argumentCaptor.getAllValues().get(2));
-        assertEquals(TEST_OBJECT_JSON, argumentCaptor.getAllValues().get(3));
+        assertThat(argumentCaptor.getAllValues().get(3), samePropertyValuesAs(new Substring(TEST_OBJECT_JSON)));
     }
 
     @Test
@@ -204,6 +210,35 @@ public class LoggingUtilsTest {
         assertThat(Logging.exceptionToDescription(exceptionToDescribe), matchesRegEx(expectedButDotsEscaped));
     }
 
+    @Test
+    public void substringClass_givenNull_thenToStringIsNull() {
+        assertThat(new Substring(null), hasToString(equalTo("null")));
+    }
+
+    @Test
+    public void substringClass_givenAnObject_thenToStringIsEqualAndPassThrough() {
+        Object anyObject = mock(Object.class);
+        when(anyObject.toString()).thenReturn(TEST_OBJECT_JSON);
+
+        assertThat(new Substring(anyObject),
+            hasToString(sameInstance(TEST_OBJECT_JSON)));
+    }
+
+    @Test
+    public void substringClass_givenNotLongString_thenToStringIsNotTruncated() {
+        assertThat(new Substring(repeat(TEST_OBJECT_JSON, 100)),
+            hasToString(equalTo(repeat(TEST_OBJECT_JSON, 100))));
+    }
+
+    @Test
+    public void substringClass_givenLongString_thenToStringIsTruncatedToSize() {
+        int expectedLength = 1_000_000; // this is Substring's internal config
+        String headMarker = "head-";
+
+        assertThat(new Substring(headMarker + repeat("x", 2_000_000)),
+            hasToString(equalTo(headMarker + repeat("x", expectedLength - headMarker.length()))));
+    }
+
     @Test
     public void testWithMDCInternal_whenGivenProvider_functionShouldBeExtractedWithMdc() {
         Object myAnything = new Object();