From d78df8b7e7df3ecdf6c5c5052f594586080bce8a Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Wed, 27 Apr 2022 19:11:18 +0200 Subject: [PATCH 1/7] Dynatrace registry: Truncate log output --- .../dynatrace/v2/DynatraceExporterV2.java | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java index dadafc3f92..a401ede990 100644 --- a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java +++ b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java @@ -16,6 +16,8 @@ package io.micrometer.dynatrace.v2; import com.dynatrace.metric.util.*; + +import io.micrometer.common.util.StringUtils; import io.micrometer.core.instrument.*; import io.micrometer.core.instrument.distribution.HistogramSnapshot; import io.micrometer.core.instrument.distribution.ValueAtPercentile; @@ -55,6 +57,7 @@ public final class DynatraceExporterV2 extends AbstractDynatraceExporter { private static final Pattern EXTRACT_LINES_OK = Pattern.compile("\"linesOk\":\\s?(\\d+)"); private static final Pattern EXTRACT_LINES_INVALID = Pattern.compile("\"linesInvalid\":\\s?(\\d+)"); private static final Pattern IS_NULL_ERROR_RESPONSE = Pattern.compile("\"error\":\\s?null"); + private static final int LOG_RESPONSE_BODY_TRUNCATION_LIMIT = 1_000; private final InternalLogger logger = InternalLoggerFactory.getInstance(DynatraceExporterV2.class); private static final Map staticDimensions = Collections.singletonMap("dt.metrics.source", "micrometer"); @@ -310,7 +313,9 @@ private void send(List metricLines) { .withPlainText(body) .send() .onSuccess(response -> handleSuccess(metricLines.size(), response)) - .onError(response -> logger.error("Failed metric ingestion: Error Code={}, Response Body={}", response.code(), response.body())); + .onError(response -> logger.error("Failed metric ingestion: Error Code={}, Response Body={}", + response.code(), + StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT))); } catch (Throwable throwable) { logger.error("Failed metric ingestion: " + throwable.getMessage(), throwable); } @@ -325,16 +330,16 @@ private void handleSuccess(int totalSent, HttpSender.Response response) { logger.debug("Sent {} metric lines, linesOk: {}, linesInvalid: {}.", totalSent, linesOkMatchResult.group(1), linesInvalidMatchResult.group(1)); } else { - logger.warn("Unable to parse response: {}", response.body()); + logger.warn("Unable to parse response: {}", StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT)); } } else { - logger.warn("Unable to parse response: {}", response.body()); + logger.warn("Unable to parse response: {}", StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT)); } } else { // common pitfall if URI is supplied in V1 format (without endpoint path) logger.error("Expected status code 202, got {}.\nResponse Body={}\nDid you specify the ingest path (e.g.: /api/v2/metrics/ingest)?", response.code(), - response.body() + StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT) ); } } From 7acd632b9940f70bf5df76871885bf91f07ea98c Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Fri, 29 Apr 2022 13:13:51 +0200 Subject: [PATCH 2/7] Only log stack trace in debug --- .../java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java index a401ede990..467e393f43 100644 --- a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java +++ b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java @@ -317,7 +317,8 @@ private void send(List metricLines) { response.code(), StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT))); } catch (Throwable throwable) { - logger.error("Failed metric ingestion: " + throwable.getMessage(), throwable); + logger.error("Failed metric ingestion: " + throwable); + logger.debug(throwable); } } From 6c133bd1d661b099753562dec890a227d866f70d Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Mon, 2 May 2022 18:28:18 +0200 Subject: [PATCH 3/7] Add indicator for truncation with StringUtils --- .../core/instrument/util/StringUtils.java | 19 ++++++++++++++ .../core/instrument/util/StringUtilsTest.java | 26 +++++++++++++++++++ 2 files changed, 45 insertions(+) diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java index 2c9da6b6d9..09ebd50d8c 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java @@ -89,6 +89,25 @@ public static String truncate(String string, int maxLength) { return string; } + /** + * Truncate the String to the max length and append string to indicate if truncation was applied + * + * @param string String to truncate + * @param maxLength max length, which includes the length required for {@code truncationIndicator} + * @param truncationIndicator A string that is appended if {@code string} is truncated + * @return truncated String + */ + public static String truncate(String string, int maxLength, String truncationIndicator) { + if (truncationIndicator.length() >= maxLength) { + throw new IllegalArgumentException("maxLength must be greater than length of truncationIndicator"); + } + final int remainingLength = maxLength - truncationIndicator.length(); + if (string.length() > remainingLength) { + return string.substring(0, remainingLength) + truncationIndicator; + } + return string; + } + private StringUtils() { } diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java index 7310765a2c..a03add4561 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java @@ -18,6 +18,7 @@ import org.junit.jupiter.api.Test; import static org.assertj.core.api.Assertions.assertThat; +import static org.junit.jupiter.api.Assertions.assertThrows; /** * Tests for {@link StringUtils}. @@ -36,6 +37,31 @@ void truncateWhenLessThanMaxLengthShouldReturnItself() { assertThat(StringUtils.truncate("123", 5)).isEqualTo("123"); } + @Test + void truncateWithIndicatorWhenGreaterThanMaxLengthShouldTruncate() { + assertThat(StringUtils.truncate("1234567890", 7, "...")).isEqualTo("1234..."); + } + + @Test + void truncateWithEmptyIndicatorWhenGreaterThanMaxLengthShouldTruncate() { + assertThat(StringUtils.truncate("1234567890", 7, "")).isEqualTo("1234567"); + } + + @Test + void truncateWithIndicatorWhenLessThanMaxLengthShouldReturnItself() { + assertThat(StringUtils.truncate("123", 7, "...")).isEqualTo("123"); + } + + @Test + void truncateWithIndicatorThrowsOnInvalidLength1() { + assertThrows(IllegalArgumentException.class, () -> StringUtils.truncate("12345", 7, "[abbreviated]")); + } + + @Test + void truncateWithIndicatorThrowsOnInvalidLength2() { + assertThrows(IllegalArgumentException.class, () -> StringUtils.truncate("1234567890", 7, "[abbreviated]")); + } + @Test void isNotEmptyWhenNullShouldBeFalse() { assertThat(StringUtils.isNotEmpty(null)).isFalse(); From eeede6a281a9d155d3c03d9fa2fd600cf5f236f5 Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Mon, 2 May 2022 18:39:15 +0200 Subject: [PATCH 4/7] Use truncation with indicator --- .../dynatrace/v2/DynatraceExporterV2.java | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java index 467e393f43..62b037c515 100644 --- a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java +++ b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java @@ -17,11 +17,11 @@ import com.dynatrace.metric.util.*; -import io.micrometer.common.util.StringUtils; import io.micrometer.core.instrument.*; import io.micrometer.core.instrument.distribution.HistogramSnapshot; import io.micrometer.core.instrument.distribution.ValueAtPercentile; import io.micrometer.core.instrument.util.AbstractPartition; +import io.micrometer.core.instrument.util.StringUtils; import io.micrometer.core.ipc.http.HttpSender; import io.micrometer.core.util.internal.logging.InternalLogger; import io.micrometer.core.util.internal.logging.InternalLoggerFactory; @@ -58,6 +58,7 @@ public final class DynatraceExporterV2 extends AbstractDynatraceExporter { private static final Pattern EXTRACT_LINES_INVALID = Pattern.compile("\"linesInvalid\":\\s?(\\d+)"); private static final Pattern IS_NULL_ERROR_RESPONSE = Pattern.compile("\"error\":\\s?null"); private static final int LOG_RESPONSE_BODY_TRUNCATION_LIMIT = 1_000; + private static final String LOG_RESPONSE_BODY_TRUNCATION_INDICATOR = " (truncated)"; private final InternalLogger logger = InternalLoggerFactory.getInstance(DynatraceExporterV2.class); private static final Map staticDimensions = Collections.singletonMap("dt.metrics.source", "micrometer"); @@ -315,7 +316,7 @@ private void send(List metricLines) { .onSuccess(response -> handleSuccess(metricLines.size(), response)) .onError(response -> logger.error("Failed metric ingestion: Error Code={}, Response Body={}", response.code(), - StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT))); + StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT, LOG_RESPONSE_BODY_TRUNCATION_INDICATOR))); } catch (Throwable throwable) { logger.error("Failed metric ingestion: " + throwable); logger.debug(throwable); @@ -331,16 +332,18 @@ private void handleSuccess(int totalSent, HttpSender.Response response) { logger.debug("Sent {} metric lines, linesOk: {}, linesInvalid: {}.", totalSent, linesOkMatchResult.group(1), linesInvalidMatchResult.group(1)); } else { - logger.warn("Unable to parse response: {}", StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT)); + logger.warn("Unable to parse response: {}", + StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT, LOG_RESPONSE_BODY_TRUNCATION_INDICATOR)); } } else { - logger.warn("Unable to parse response: {}", StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT)); + logger.warn("Unable to parse response: {}", + StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT, LOG_RESPONSE_BODY_TRUNCATION_INDICATOR)); } } else { // common pitfall if URI is supplied in V1 format (without endpoint path) logger.error("Expected status code 202, got {}.\nResponse Body={}\nDid you specify the ingest path (e.g.: /api/v2/metrics/ingest)?", response.code(), - StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT) + StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT, LOG_RESPONSE_BODY_TRUNCATION_INDICATOR) ); } } From 05438b09a641f1323b3eecfa3d6c87322098a592 Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Mon, 2 May 2022 18:46:27 +0200 Subject: [PATCH 5/7] Use WarnThenDebugLogger --- .../java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java index 62b037c515..002a2cb5c8 100644 --- a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java +++ b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java @@ -25,6 +25,7 @@ import io.micrometer.core.ipc.http.HttpSender; import io.micrometer.core.util.internal.logging.InternalLogger; import io.micrometer.core.util.internal.logging.InternalLoggerFactory; +import io.micrometer.core.util.internal.logging.WarnThenDebugLogger; import io.micrometer.dynatrace.AbstractDynatraceExporter; import io.micrometer.dynatrace.DynatraceConfig; import io.micrometer.dynatrace.types.DynatraceSummarySnapshot; @@ -61,6 +62,7 @@ public final class DynatraceExporterV2 extends AbstractDynatraceExporter { private static final String LOG_RESPONSE_BODY_TRUNCATION_INDICATOR = " (truncated)"; private final InternalLogger logger = InternalLoggerFactory.getInstance(DynatraceExporterV2.class); + private static final WarnThenDebugLogger warnThenDebugLoggerSend = new WarnThenDebugLogger(DynatraceExporterV2.class); private static final Map staticDimensions = Collections.singletonMap("dt.metrics.source", "micrometer"); private final MetricBuilderFactory metricBuilderFactory; @@ -318,8 +320,7 @@ private void send(List metricLines) { response.code(), StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT, LOG_RESPONSE_BODY_TRUNCATION_INDICATOR))); } catch (Throwable throwable) { - logger.error("Failed metric ingestion: " + throwable); - logger.debug(throwable); + warnThenDebugLoggerSend.log("Failed metric ingestion", throwable); } } From 81912e5194064bf6dedf38203f527a2c5ef9ba27 Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Tue, 3 May 2022 18:14:05 +0200 Subject: [PATCH 6/7] Log 'send' exception message always and log once --- .../java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java index 002a2cb5c8..2ea4eddda7 100644 --- a/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java +++ b/implementations/micrometer-registry-dynatrace/src/main/java/io/micrometer/dynatrace/v2/DynatraceExporterV2.java @@ -62,7 +62,7 @@ public final class DynatraceExporterV2 extends AbstractDynatraceExporter { private static final String LOG_RESPONSE_BODY_TRUNCATION_INDICATOR = " (truncated)"; private final InternalLogger logger = InternalLoggerFactory.getInstance(DynatraceExporterV2.class); - private static final WarnThenDebugLogger warnThenDebugLoggerSend = new WarnThenDebugLogger(DynatraceExporterV2.class); + private static final WarnThenDebugLogger warnThenDebugLoggerSendStack = new WarnThenDebugLogger(DynatraceExporterV2.class); private static final Map staticDimensions = Collections.singletonMap("dt.metrics.source", "micrometer"); private final MetricBuilderFactory metricBuilderFactory; @@ -320,7 +320,8 @@ private void send(List metricLines) { response.code(), StringUtils.truncate(response.body(), LOG_RESPONSE_BODY_TRUNCATION_LIMIT, LOG_RESPONSE_BODY_TRUNCATION_INDICATOR))); } catch (Throwable throwable) { - warnThenDebugLoggerSend.log("Failed metric ingestion", throwable); + logger.warn("Failed metric ingestion: " + throwable); + warnThenDebugLoggerSendStack.log("Stack trace for previous 'Failed metric ingestion' warning log: ", throwable); } } From e455f190ef57a2913abf02eb403fbbafa13d139c Mon Sep 17 00:00:00 2001 From: Armin Ruech Date: Wed, 4 May 2022 09:35:17 +0200 Subject: [PATCH 7/7] Use entire length before abbreviating --- .../java/io/micrometer/core/instrument/util/StringUtils.java | 4 ++-- .../io/micrometer/core/instrument/util/StringUtilsTest.java | 5 +++++ 2 files changed, 7 insertions(+), 2 deletions(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java index 09ebd50d8c..58fc5b6d76 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/util/StringUtils.java @@ -101,8 +101,8 @@ public static String truncate(String string, int maxLength, String truncationInd if (truncationIndicator.length() >= maxLength) { throw new IllegalArgumentException("maxLength must be greater than length of truncationIndicator"); } - final int remainingLength = maxLength - truncationIndicator.length(); - if (string.length() > remainingLength) { + if (string.length() > maxLength) { + final int remainingLength = maxLength - truncationIndicator.length(); return string.substring(0, remainingLength) + truncationIndicator; } return string; diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java index a03add4561..693f2ae64d 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/util/StringUtilsTest.java @@ -47,6 +47,11 @@ void truncateWithEmptyIndicatorWhenGreaterThanMaxLengthShouldTruncate() { assertThat(StringUtils.truncate("1234567890", 7, "")).isEqualTo("1234567"); } + @Test + void truncateWithIndicatorWhenSameAsMaxLengthShouldReturnItself() { + assertThat(StringUtils.truncate("1234567", 7, "...")).isEqualTo("1234567"); + } + @Test void truncateWithIndicatorWhenLessThanMaxLengthShouldReturnItself() { assertThat(StringUtils.truncate("123", 7, "...")).isEqualTo("123");