Closes #1049 - Edit the 'illegal tag value' error message to be print…

…ed more than once (#1064)
inspectIT · Jul 12, 2021 · b5690cd · b5690cd
1 parent 6e8176e
commit b5690cd
Show file tree

Hide file tree

Showing 4 changed files with 100 additions and 18 deletions.
diff --git a/...pectit-ocelot-eum-server/src/main/java/rocks/inspectit/oce/eum/server/utils/TagUtils.java b/...pectit-ocelot-eum-server/src/main/java/rocks/inspectit/oce/eum/server/utils/TagUtils.java
@@ -1,13 +1,29 @@
 package rocks.inspectit.oce.eum.server.utils;
 
+import com.google.common.annotations.VisibleForTesting;
 import io.opencensus.internal.StringUtils;
 import io.opencensus.tags.TagValue;
 import lombok.extern.slf4j.Slf4j;
 
 @Slf4j
 public final class TagUtils {
 
-    private static boolean isWarningPrinted = false;
+    //Counter for the number of warnings that have already been printed
+    @VisibleForTesting
+    static int printedWarningCounter = 0;
+
+    //The time in ms when the last warning was printed
+    @VisibleForTesting
+    static long lastWarningTime = 0;
+
+    //The number of maximum warnings that are to be printed
+    private final static int MAX_WARNING_PRINTS = 10;
+
+    //The duration in ms that needs to pass, if MAX_WARNING_PRINTS has been reached
+    private final static int WAITING_TIME_IN_MILLI_SECONDS = 600_000;
+
+    //Boolean that indicates whether the user gets a message that further logs are suppressed
+    private static boolean PRINT_FURTHER_MESSAGE = true;
 
     private TagUtils() {
         // empty private default constructor for util class
@@ -17,28 +33,35 @@ private TagUtils() {
      * Constructs a {@code io.opencensus.tags.TagValue} from the given string.
      * If String is not valid an <code>&lt;invalid&gt;</code> TagName is created.
      *
-     * @param tagKey the tag name
+     * @param tagKey the tag key
      * @param value  the tag value
      *
-     * @return the created TagValue with 'value' or '&lt;invalid&gt;'
+     * @return the created TagValue with 'v' or '&lt;invalid&gt;'
      */
     public static TagValue createTagValue(String tagKey, String value) {
         if (isTagValueValid(value)) {
             return TagValue.create(value);
         }
-        printWarningOnce(tagKey, value);
+        printWarning(tagKey, value);
         return TagValue.create("<invalid>");
     }
 
     private static boolean isTagValueValid(String value) {
         return value.length() <= TagValue.MAX_LENGTH && StringUtils.isPrintableString(value);
     }
 
-    private static void printWarningOnce(String tagKey, String value) {
-        if (!isWarningPrinted) {
+    private static void printWarning(String tagKey, String value) {
+        if ((System.currentTimeMillis() - lastWarningTime) > WAITING_TIME_IN_MILLI_SECONDS) {
+            printedWarningCounter = 0;
+            PRINT_FURTHER_MESSAGE = true;
+        }
+        if (printedWarningCounter < MAX_WARNING_PRINTS) {
             log.warn("Error creating value for tag <{}>: illegal tag value <{}> converted to <invalid>", tagKey, value);
-            isWarningPrinted = true;
+            printedWarningCounter++;
+            lastWarningTime = System.currentTimeMillis();
+        } else if (PRINT_FURTHER_MESSAGE) {
+            log.warn("Further log messages are suppressed");
+            PRINT_FURTHER_MESSAGE = false;
         }
     }
-
-}
+}
diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/tags/TagUtils.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/tags/TagUtils.java
@@ -1,13 +1,29 @@
 package rocks.inspectit.ocelot.core.tags;
 
+import com.google.common.annotations.VisibleForTesting;
 import io.opencensus.internal.StringUtils;
 import io.opencensus.tags.TagValue;
 import lombok.extern.slf4j.Slf4j;
 
 @Slf4j
 public final class TagUtils {
 
-    private static boolean isWarningPrinted = false;
+    //Counter for the number of warnings that have already been printed
+    @VisibleForTesting
+    static int printedWarningCounter = 0;
+
+    //The time in ms when the last warning was printed
+    @VisibleForTesting
+    static long lastWarningTime = 0;
+
+    //The number of maximum warnings that are to be printed
+    private final static int MAX_WARNING_PRINTS = 10;
+
+    //The duration in ms that needs to pass, if MAX_WARNING_PRINTS has been reached
+    private final static int WAITING_TIME_IN_MILLI_SECONDS = 600_000;
+
+    //Boolean that indicates whether the user gets a message that further logs are suppressed
+    private static boolean PRINT_FURTHER_MESSAGE = true;
 
     private TagUtils() {
         // empty private default constructor for util class
@@ -26,18 +42,26 @@ public static TagValue createTagValue(String tagKey, String value) {
         if (isTagValueValid(value)) {
             return TagValue.create(value);
         }
-        printWarningOnce(tagKey, value);
+        printWarning(tagKey, value);
         return TagValue.create("<invalid>");
     }
 
     private static boolean isTagValueValid(String value) {
         return value.length() <= TagValue.MAX_LENGTH && StringUtils.isPrintableString(value);
     }
 
-    private static void printWarningOnce(String tagKey, String value) {
-        if (!isWarningPrinted) {
+    private static void printWarning(String tagKey, String value) {
+        if ((System.currentTimeMillis() - lastWarningTime) > WAITING_TIME_IN_MILLI_SECONDS) {
+            printedWarningCounter = 0;
+            PRINT_FURTHER_MESSAGE = true;
+        }
+        if (printedWarningCounter < MAX_WARNING_PRINTS) {
             log.warn("Error creating value for tag <{}>: illegal tag value <{}> converted to <invalid>", tagKey, value);
-            isWarningPrinted = true;
+            printedWarningCounter++;
+            lastWarningTime = System.currentTimeMillis();
+        } else if (PRINT_FURTHER_MESSAGE) {
+            log.warn("Further log messages are suppressed");
+            PRINT_FURTHER_MESSAGE = false;
         }
     }
-}
+}
diff --git a/inspectit-ocelot-core/src/test/java/rocks/inspectit/ocelot/core/SpringTestBase.java b/inspectit-ocelot-core/src/test/java/rocks/inspectit/ocelot/core/SpringTestBase.java
@@ -29,8 +29,7 @@
 import java.util.stream.Collectors;
 
 import static org.assertj.core.api.Assertions.assertThat;
-
-import static org.mockito.Mockito.*;
+import static org.mockito.Mockito.when;
 
 /**
  * Base class for all tests.
@@ -143,4 +142,14 @@ public void assertLogsOfLevelOrGreater(Level level) {
                 .anyMatch(le -> le.isGreaterOrEqual(level));
     }
 
+    /**
+     * Asserts that count of specific log output is equal to the given integer
+     *
+     * @param count the number to compare against.
+     */
+    public void assertLogCount(String logMessage, int count) {
+        assertThat(StaticAppender.getEvents()).filteredOn(event -> event.getMessage().contains(logMessage))
+                .hasSize(count);
+    }
+
 }
diff --git a/inspectit-ocelot-core/src/test/java/rocks/inspectit/ocelot/core/tags/TagUtilsTest.java b/inspectit-ocelot-core/src/test/java/rocks/inspectit/ocelot/core/tags/TagUtilsTest.java
@@ -1,11 +1,13 @@
 package rocks.inspectit.ocelot.core.tags;
 
+import ch.qos.logback.classic.Level;
 import io.opencensus.tags.TagValue;
 import org.junit.jupiter.api.Test;
+import rocks.inspectit.ocelot.core.SpringTestBase;
 
 import static org.assertj.core.api.Assertions.assertThat;
 
-public class TagUtilsTest {
+public class TagUtilsTest extends SpringTestBase {
 
     @Test
     public void createTagValue() {
@@ -23,4 +25,28 @@ public void createTagValue_nonPrintableCharacter() {
         assertThat(TagUtils.createTagValue("my-tag-key", "non-printable-character-\u007f")).isEqualTo(TagValue.create("<invalid>"));
     }
 
+    @Test
+    public void multipleCreateTagValue_nonPrintableCharacter() {
+        TagUtils.printedWarningCounter = 0;
+
+        for (int i = 0; i < 11; i++) {
+            TagUtils.createTagValue("my-tag-key", "non-printable-character-\u007f");
+        }
+        assertLogsOfLevelOrGreater(Level.WARN);
+        assertLogCount("Error creating value for tag", 10);
+    }
+
+    @Test
+    public void multipleCreateTagValue_moreThan10Minutes() {
+        TagUtils.printedWarningCounter = 0;
+
+        for (int i = 0; i < 11; i++) {
+            TagUtils.createTagValue("my-tag-key", "non-printable-character-\u007f");
+        }
+
+        TagUtils.lastWarningTime = TagUtils.lastWarningTime - 610000;
+        TagUtils.createTagValue("my-tag-key", "non-printable-character-\u007f");
+
+        assertLogCount("Error creating value for tag", 11);
+    }
 }