[9.2] ILM Explain: valid JSON on truncated step info (#137638)

docs/changelog/137638.yaml

@@ -0,0 +1,6 @@
+pr: 137638
+summary: "ILM Explain: valid JSON on truncated step info"
+area: ILM+SLM
+type: bug
+issues:
+ - 135458

server/src/main/java/org/elasticsearch/cluster/metadata/LifecycleExecutionState.java

@@ -287,15 +287,31 @@ public Map<String, String> asMap() {
         return Collections.unmodifiableMap(result);
     }
 
-    public static String truncateWithExplanation(String input) {
-        if (input != null && input.length() > MAXIMUM_STEP_INFO_STRING_LENGTH) {
-            return Strings.cleanTruncate(input, MAXIMUM_STEP_INFO_STRING_LENGTH)
-                + "... ("
-                + (input.length() - MAXIMUM_STEP_INFO_STRING_LENGTH)
-                + " chars truncated)";
-        } else {
-            return input;
-        }
+    /**
+     * Truncates a potentially long JSON string to ensure it does not exceed {@link #MAXIMUM_STEP_INFO_STRING_LENGTH}. If truncation
+     * occurs, an explanation suffix is appended to the truncated string indicating <i>approximately</i> how many characters were removed.
+     * We return an approximation because we're valuing code simplicity over accuracy in this area.
+     *
+     * @param json the JSON string to potentially truncate
+     * @return the original JSON string if its length is within the limit, otherwise a truncated version with an explanation suffix - in
+     * correct JSON format
+     */
+    public static String potentiallyTruncateLongJsonWithExplanation(String json) {
+        if (json == null || json.length() <= MAXIMUM_STEP_INFO_STRING_LENGTH) {
+            return json;
+        }
+        // we'll now do our best to truncate the JSON and have the result be valid JSON.
+        // a long input JSON should generally only be possible with an exception turned into JSON that's well-formatted.
+        // if we fail to produce valid JSON, we might return invalid JSON in REST API in niche cases, so this isn't catastrophic.
+        assert json.startsWith("{\"") && json.endsWith("\"}") : "expected more specific JSON format, might produce invalid JSON";
+        final int roughNumberOfCharsTruncated = json.length() - MAXIMUM_STEP_INFO_STRING_LENGTH;
+        final String truncationExplanation = "... (~" + roughNumberOfCharsTruncated + " chars truncated)\"}";
+        // To ensure that the resulting string is always <= the max, we also need to remove the length of our suffix.
+        // This means that the actual number of characters removed is `truncationExplanation.length()` more than we say it is.
+        final String truncated = Strings.cleanTruncate(json, MAXIMUM_STEP_INFO_STRING_LENGTH - truncationExplanation.length())
+            + truncationExplanation;
+        assert truncated.length() <= MAXIMUM_STEP_INFO_STRING_LENGTH : "truncation didn't work";
+        return truncated;
     }
 
     public static class Builder {
@@ -340,7 +356,7 @@ public Builder setFailedStep(String failedStep) {
         }
 
         public Builder setStepInfo(String stepInfo) {
-            this.stepInfo = truncateWithExplanation(stepInfo);
+            this.stepInfo = potentiallyTruncateLongJsonWithExplanation(stepInfo);
             return this;
         }
 

x-pack/plugin/core/src/test/java/org/elasticsearch/xpack/core/ilm/LifecycleExecutionStateTests.java

@@ -8,13 +8,18 @@
 package org.elasticsearch.xpack.core.ilm;
 
 import org.elasticsearch.cluster.metadata.LifecycleExecutionState;
+import org.elasticsearch.common.Strings;
 import org.elasticsearch.test.ESTestCase;
 import org.elasticsearch.test.EqualsHashCodeTestUtils;
 
 import java.util.HashMap;
 import java.util.Map;
 
+import static org.hamcrest.Matchers.endsWith;
 import static org.hamcrest.Matchers.equalTo;
+import static org.hamcrest.Matchers.hasLength;
+import static org.hamcrest.Matchers.not;
+import static org.hamcrest.Matchers.sameInstance;
 
 public class LifecycleExecutionStateTests extends ESTestCase {
 
@@ -28,14 +33,12 @@ public void testTruncatingStepInfo() {
         Map<String, String> custom = createCustomMetadata();
         LifecycleExecutionState state = LifecycleExecutionState.fromCustomMetadata(custom);
         assertThat(custom.get("step_info"), equalTo(state.stepInfo()));
-        String longStepInfo = randomAlphanumericOfLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH + 100);
+        String longStepInfo = "{\"key\": \""
+            + randomAlphanumericOfLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH + 100)
+            + "\"}";
         LifecycleExecutionState newState = LifecycleExecutionState.builder(state).setStepInfo(longStepInfo).build();
-        // Length includes the post suffix
-        assertThat(newState.stepInfo().length(), equalTo(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH + 25));
-        assertThat(
-            newState.stepInfo().substring(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH, 1049),
-            equalTo("... (100 chars truncated)")
-        );
+        assertThat(newState.stepInfo(), hasLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH));
+        assertThat(newState.stepInfo(), endsWith("... (~111 chars truncated)\"}"));
     }
 
     public void testEmptyValuesAreNotSerialized() {
@@ -145,6 +148,59 @@ public void testGetCurrentStepKey() {
         assertNull(error6.getMessage());
     }
 
+    /** test that strings with length less than or equal to maximum string length are not truncated and returned as-is */
+    public void testPotentiallyTruncateLongJsonWithExplanationNoNeedToTruncate() {
+        final String input = randomAlphaOfLengthBetween(0, LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH);
+        assertSame(input, LifecycleExecutionState.potentiallyTruncateLongJsonWithExplanation(input));
+    }
+
+    /** test that string with length one character over the max limit has truncation applied to it and has correct explanation */
+    public void testPotentiallyTruncateLongJsonWithExplanationOneCharTruncated() {
+        final String jsonBaseFormat = "{\"key\": \"%s\"}";
+        final int baseLength = Strings.format(jsonBaseFormat, "").length();
+        final String value = randomAlphanumericOfLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH - baseLength + 1);
+        final String input = Strings.format(jsonBaseFormat, value);
+
+        final String expectedSuffix = "... (~1 chars truncated)";
+        final String expectedOutput = Strings.format(
+            jsonBaseFormat,
+            value.substring(0, value.length() - expectedSuffix.length() - 1) + expectedSuffix
+        );
+        final String actualOutput = LifecycleExecutionState.potentiallyTruncateLongJsonWithExplanation(input);
+        assertThat(actualOutput, hasLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH));
+        assertEquals(expectedOutput, actualOutput);
+    }
+
+    /** test that string with length two characters over the max limit has truncation applied to it and has correct explanation */
+    public void testPotentiallyTruncateLongJsonWithExplanationTwoCharsTruncated() {
+        final String jsonBaseFormat = "{\"key\": \"%s\"}";
+        final int baseLength = Strings.format(jsonBaseFormat, "").length();
+        final String value = randomAlphanumericOfLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH - baseLength + 2);
+        final String input = Strings.format(jsonBaseFormat, value);
+
+        final String expectedSuffix = "... (~2 chars truncated)";
+        final String expectedOutput = Strings.format(
+            jsonBaseFormat,
+            value.substring(0, value.length() - expectedSuffix.length() - 2) + expectedSuffix
+        );
+        final String actualOutput = LifecycleExecutionState.potentiallyTruncateLongJsonWithExplanation(input);
+        assertThat(actualOutput, hasLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH));
+        assertEquals(expectedOutput, actualOutput);
+    }
+
+    public void testPotentiallyTruncateLongJsonWithExplanationIsIdempotent() {
+        final String input = "{\"key\": \"" + randomAlphanumericOfLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH) + "\"}";
+
+        final String firstOutput = LifecycleExecutionState.potentiallyTruncateLongJsonWithExplanation(input);
+
+        assertThat(firstOutput, hasLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH));
+        assertThat(firstOutput, not(equalTo(input)));
+
+        final String secondOutput = LifecycleExecutionState.potentiallyTruncateLongJsonWithExplanation(firstOutput);
+
+        assertThat(secondOutput, sameInstance(firstOutput));
+    }
+
     private LifecycleExecutionState mutate(LifecycleExecutionState toMutate) {
         LifecycleExecutionState.Builder newState = LifecycleExecutionState.builder(toMutate);
         switch (randomIntBetween(0, 18)) {

x-pack/plugin/ilm/qa/multi-node/src/javaRestTest/java/org/elasticsearch/xpack/ilm/ExplainLifecycleIT.java

@@ -10,11 +10,10 @@
 import org.apache.http.entity.ContentType;
 import org.apache.http.entity.StringEntity;
 import org.apache.http.util.EntityUtils;
-import org.apache.logging.log4j.LogManager;
-import org.apache.logging.log4j.Logger;
 import org.elasticsearch.client.Request;
 import org.elasticsearch.client.Response;
 import org.elasticsearch.cluster.metadata.IndexMetadata;
+import org.elasticsearch.cluster.metadata.LifecycleExecutionState;
 import org.elasticsearch.common.Strings;
 import org.elasticsearch.common.settings.Settings;
 import org.elasticsearch.core.TimeValue;
@@ -44,6 +43,7 @@
 import static org.elasticsearch.xpack.TimeSeriesRestDriver.explainIndex;
 import static org.hamcrest.Matchers.allOf;
 import static org.hamcrest.Matchers.containsString;
+import static org.hamcrest.Matchers.equalTo;
 import static org.hamcrest.Matchers.greaterThan;
 import static org.hamcrest.Matchers.greaterThanOrEqualTo;
 import static org.hamcrest.Matchers.hasKey;
@@ -53,7 +53,6 @@
 import static org.hamcrest.Matchers.nullValue;
 
 public class ExplainLifecycleIT extends IlmESRestTestCase {
-    private static final Logger logger = LogManager.getLogger(ExplainLifecycleIT.class);
     private static final String FAILED_STEP_RETRY_COUNT_FIELD = "failed_step_retry_count";
     private static final String IS_AUTO_RETRYABLE_ERROR_FIELD = "is_auto_retryable_error";
 
@@ -321,6 +320,78 @@ public void testStepInfoPreservedOnAutoRetry() throws Exception {
         }, 30, TimeUnit.SECONDS);
     }
 
+    /**
+     * Test that, when there is an ILM <code>previous_step_info</code> that has had truncation applied to it (due to it being too long),
+     * the truncation:
+     * <ul>
+     * <li>doesn't break the JSON returned in <code>/{index}/_ilm/explain</code></li>
+     * <li>truncates as expected</li>
+     * </ul>
+     * We test this by creating an ILM policy that rolls-over at 1 document, and an index pattern that has a non-existing rollover alias
+     * that has a very long name (to trip the truncation due to the rollover alias name being in the <code>previous_step_info</code>).
+     * <p>
+     * We then index a document, wait for attempted rollover, and assert that we get valid JSON and expected truncated message
+     * in <code>/{index}/_ilm/explain</code>.
+     */
+    public void testTruncatedPreviousStepInfoDoesNotBreakExplainJson() throws Exception {
+        final String policyName = "policy-" + randomAlphaOfLength(5).toLowerCase(Locale.ROOT);
+
+        final Request createPolicy = new Request("PUT", "_ilm/policy/" + policyName);
+        createPolicy.setJsonEntity("""
+            {
+              "policy": {
+                "phases": {
+                  "hot": {
+                    "actions": {
+                      "rollover": {
+                        "max_docs": 1
+                      }
+                    }
+                  }
+                }
+              }
+            }
+            """);
+        assertOK(client().performRequest(createPolicy));
+
+        final String indexBase = "my-logs";
+        final String indexName = indexBase + "-" + randomAlphaOfLength(5).toLowerCase(Locale.ROOT);
+        final String longMissingAliasName = randomAlphanumericOfLength(LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH);
+
+        final Request templateRequest = new Request("PUT", "_index_template/template_" + policyName);
+        final String templateBody = Strings.format("""
+            {
+              "index_patterns": ["%s-*"],
+              "template": {
+                "settings": {
+                  "index.lifecycle.name": "%s",
+                  "index.lifecycle.rollover_alias": "%s"
+                }
+              }
+            }
+            """, indexBase, policyName, longMissingAliasName);
+        templateRequest.setJsonEntity(templateBody);
+
+        assertOK(client().performRequest(templateRequest));
+
+        final Request indexRequest = new Request("POST", "/" + indexName + "/_doc/1");
+        indexRequest.setJsonEntity("{\"test\":\"value\"}");
+        assertOK(client().performRequest(indexRequest));
+
+        final String expectedReason = Strings.format(
+            "index.lifecycle.rollover_alias [%s... (~122 chars truncated)",
+            longMissingAliasName.substring(0, longMissingAliasName.length() - 107)
+        );
+        final Map<String, Object> expectedStepInfo = Map.of("type", "illegal_argument_exception", "reason", expectedReason);
+        assertBusy(() -> {
+            final Map<String, Object> explainIndex = explainIndex(client(), indexName);
+
+            final String assertionMessage = "Assertion failed for the following response: " + explainIndex;
+            final Object previousStepInfo = explainIndex.get("previous_step_info");
+            assertThat(assertionMessage, previousStepInfo, equalTo(expectedStepInfo));
+        }, 30, TimeUnit.SECONDS);
+    }
+
     private void assertUnmanagedIndex(Map<String, Object> explainIndexMap) {
         assertThat(explainIndexMap.get("managed"), is(false));
         assertThat(explainIndexMap.get("time_since_index_creation"), is(nullValue()));

x-pack/plugin/ilm/src/main/java/org/elasticsearch/xpack/ilm/history/ILMHistoryItem.java

@@ -87,13 +87,7 @@ public static ILMHistoryItem failure(
     ) {
         Objects.requireNonNull(error, "ILM failures require an attached exception");
         String fullErrorString = exceptionToString(error);
-        String truncatedErrorString = LifecycleExecutionState.truncateWithExplanation(fullErrorString);
-        if (truncatedErrorString.equals(fullErrorString) == false) {
-            // Append a closing quote and closing brace to attempt to make it valid JSON.
-            // There is no requirement that it actually be valid JSON, so this is
-            // best-effort, but does not cause problems if it is still invalid.
-            truncatedErrorString += "\"}";
-        }
+        String truncatedErrorString = LifecycleExecutionState.potentiallyTruncateLongJsonWithExplanation(fullErrorString);
         return new ILMHistoryItem(index, policyId, timestamp, indexAge, false, executionState, truncatedErrorString);
     }
 

x-pack/plugin/ilm/src/test/java/org/elasticsearch/xpack/ilm/history/ILMHistoryItemTests.java

@@ -142,10 +142,10 @@ public void testTruncateLongError() throws IOException {
                         "{\"type\":\"illegal_argument_exception\",\"reason\":\""
                             // We subtract a number of characters here due to the truncation being based
                             // on the length of the whole string, not just the "reason" part.
-                            + longError.substring(0, LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH - 47)
+                            + longError.substring(0, LifecycleExecutionState.MAXIMUM_STEP_INFO_STRING_LENGTH - 76)
                     )
                 );
-                assertThat((String) item.get("error_details"), matchesPattern(".*\\.\\.\\. \\(\\d+ chars truncated\\).*"));
+                assertThat((String) item.get("error_details"), matchesPattern(".*\\.\\.\\. \\(~\\d+ chars truncated\\).*"));
             }
         }
     }