From ef99ea6b4b4a5b62a31d0ad4b08233620df14a87 Mon Sep 17 00:00:00 2001 From: Ittay Stern Date: Tue, 7 Apr 2020 13:27:03 +0300 Subject: [PATCH] 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 --- .../src/main/java/org/onap/vid/utils/Logging.java | 25 +++++++++++++-- .../java/org/onap/vid/utils/LoggingUtilsTest.java | 37 +++++++++++++++++++++- 2 files changed, 59 insertions(+), 3 deletions(-) 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 f9894d1aa..ce811b41c 100644 --- 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 void logResponse(final EELFLogger logger, final HttpMethod method, final String url, final HttpResponse 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 c2a1f2877..8c3aa6471 100644 --- 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(); -- 2.16.6