info level log for pipeline abort (#6459)

* info level log for pipeline abort
* add depth protection

Signed-off-by: garyschulte <garyschulte@gmail.com>

ethereum/core/src/main/java/org/hyperledger/besu/ethereum/util/LogUtil.java

@@ -1,39 +0,0 @@
-/*
- * Copyright Hyperledger Besu Contributors.
- *
- * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with
- * the License. You may obtain a copy of the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on
- * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the
- * specific language governing permissions and limitations under the License.
- *
- * SPDX-License-Identifier: Apache-2.0
- */
-package org.hyperledger.besu.ethereum.util;
-
-import java.util.concurrent.Executors;
-import java.util.concurrent.ScheduledExecutorService;
-import java.util.concurrent.TimeUnit;
-import java.util.concurrent.atomic.AtomicBoolean;
-import java.util.function.Consumer;
-
-public class LogUtil {
-  static ScheduledExecutorService executor = Executors.newSingleThreadScheduledExecutor();
-
-  public static void throttledLog(
-      final Consumer<String> logger,
-      final String logMessage,
-      final AtomicBoolean shouldLog,
-      final int logRepeatDelay) {
-
-    if (shouldLog.compareAndSet(true, false)) {
-      logger.accept(logMessage);
-
-      final Runnable runnable = () -> shouldLog.set(true);
-      executor.schedule(runnable, logRepeatDelay, TimeUnit.SECONDS);
-    }
-  }
-}

ethereum/eth/src/main/java/org/hyperledger/besu/ethereum/eth/sync/fastsync/SyncTargetManager.java

@@ -16,7 +16,7 @@ package org.hyperledger.besu.ethereum.eth.sync.fastsync;
 
 import static java.util.concurrent.CompletableFuture.completedFuture;
 import static org.hyperledger.besu.ethereum.eth.sync.fastsync.PivotBlockRetriever.MAX_QUERY_RETRIES_PER_PEER;
-import static org.hyperledger.besu.ethereum.util.LogUtil.throttledLog;
+import static org.hyperledger.besu.util.log.LogUtil.throttledLog;
 
 import org.hyperledger.besu.ethereum.ProtocolContext;
 import org.hyperledger.besu.ethereum.core.BlockHeader;

services/pipeline/src/main/java/org/hyperledger/besu/services/pipeline/Pipeline.java

@@ -18,6 +18,7 @@ import static java.util.stream.Collectors.toList;
 
 import org.hyperledger.besu.services.pipeline.exception.AsyncOperationException;
 import org.hyperledger.besu.util.ExceptionUtils;
+import org.hyperledger.besu.util.log.LogUtil;
 
 import java.util.Collection;
 import java.util.List;
@@ -176,7 +177,9 @@ public class Pipeline<I> {
                 || t instanceof AsyncOperationException) {
               LOG.trace("Unhandled exception in pipeline. Aborting.", t);
             } else {
-              LOG.info("Unexpected exception in pipeline. Aborting.");
+              LOG.info(
+                  LogUtil.summarizeBesuStackTrace(
+                      "Unexpected exception in pipeline. Aborting.", t));
               LOG.debug("Unexpected exception in pipeline. Aborting.", t);
             }
             try {

util/src/main/java/org/hyperledger/besu/util/log/LogUtil.java

@@ -0,0 +1,92 @@
+/*
+ * Copyright Hyperledger Besu Contributors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on
+ * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations under the License.
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+package org.hyperledger.besu.util.log;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.Executors;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.function.Consumer;
+
+/** Utility class for logging. */
+public class LogUtil {
+  static ScheduledExecutorService executor = Executors.newSingleThreadScheduledExecutor();
+  static final String BESU_NAMESPACE = "org.hyperledger.besu";
+  static final int MAX_SUMMARY_DEPTH = 20;
+
+  /**
+   * Throttles logging to a given logger.
+   *
+   * @param logger logger as a String consumer
+   * @param logMessage message to log
+   * @param shouldLog AtomicBoolean to track whether the message should be logged
+   * @param logRepeatDelay delay in seconds between repeated logs
+   */
+  public static void throttledLog(
+      final Consumer<String> logger,
+      final String logMessage,
+      final AtomicBoolean shouldLog,
+      final int logRepeatDelay) {
+
+    if (shouldLog.compareAndSet(true, false)) {
+      logger.accept(logMessage);
+
+      final Runnable runnable = () -> shouldLog.set(true);
+      executor.schedule(runnable, logRepeatDelay, TimeUnit.SECONDS);
+    }
+  }
+
+  /**
+   * Summarizes the stack trace of a throwable to the first class in the namespace. Useful for
+   * limiting exceptionally deep stack traces to the last relevant point in besu code.
+   *
+   * @param contextMessage message to prepend to the summary
+   * @param throwable exception to summarize
+   * @param namespace namespace to summarize to
+   * @return summary of the StackTrace
+   */
+  public static String summarizeStackTrace(
+      final String contextMessage, final Throwable throwable, final String namespace) {
+    StackTraceElement[] stackTraceElements = throwable.getStackTrace();
+
+    List<String> stackTraceSummary = new ArrayList<>();
+    int depth = 0;
+    for (StackTraceElement element : stackTraceElements) {
+      stackTraceSummary.add(String.format("\tat: %s", element));
+      if (element.getClassName().startsWith(namespace) || ++depth >= MAX_SUMMARY_DEPTH) {
+        break;
+      }
+    }
+
+    return String.format(
+        "%s\nThrowable summary: %s\n%s",
+        contextMessage, throwable, String.join("\n", stackTraceSummary));
+  }
+
+  /**
+   * Summarizes the stack trace of a throwable to the first besu class in the namespace. Useful for
+   * limiting exceptionally deep stack traces to the last relevant point in besu code.
+   *
+   * @param contextMessage message to prepend to the summary
+   * @param throwable exception to summarize
+   * @return summary of the StackTrace
+   */
+  public static String summarizeBesuStackTrace(
+      final String contextMessage, final Throwable throwable) {
+    return summarizeStackTrace(contextMessage, throwable, BESU_NAMESPACE);
+  }
+}

util/src/test/java/org/hyperledger/besu/util/log/LogUtilTest.java

@@ -0,0 +1,127 @@
+/*
+ * Copyright Hyperledger Besu Contributors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on
+ * an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations under the License.
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+package org.hyperledger.besu.util.log;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+import java.util.Arrays;
+import java.util.List;
+import java.util.Optional;
+import java.util.function.Supplier;
+
+import org.junit.jupiter.api.Test;
+
+public class LogUtilTest {
+
+  static final String exceptionMessage = "test message";
+  static final String contextMessage = "context message";
+
+  @Test
+  public void testMessageSummarizeStackTrace() {
+    Throwable throwable = new Throwable(exceptionMessage);
+    String namespace = "org.hyperledger.besu";
+    String result = LogUtil.summarizeStackTrace(contextMessage, throwable, namespace);
+    var lines =
+        assertFoundInTrace(result, LogUtil.BESU_NAMESPACE, contextMessage, exceptionMessage, 1);
+    assertThat(lines.size()).isEqualTo(3);
+  }
+
+  @Test
+  public void testSummarizeStackTraceToArbitrary() {
+    Throwable throwable = new Throwable("test message");
+    String namespace = "java.lang";
+    String result = LogUtil.summarizeStackTrace(contextMessage, throwable, namespace);
+    var lines = assertFoundInTrace(result, namespace, contextMessage, exceptionMessage, 1);
+    assertThat(lines.size()).isGreaterThan(3);
+  }
+
+  @Test
+  public void testSummarizeLambdaStackTrace() {
+    String result = "";
+    try {
+      Supplier<Object> lambda = () -> besuStackHelper(null);
+      assertThat(lambda.get()).isNotNull();
+    } catch (Exception e) {
+      String namespace = "org.hyperledger.besu";
+      result = LogUtil.summarizeStackTrace(contextMessage, e, namespace);
+    }
+    var lines =
+        assertFoundInTrace(
+            result, LogUtil.BESU_NAMESPACE, contextMessage, "NullPointerException", 1);
+    assertThat(lines).hasSize(5);
+  }
+
+  @Test
+  public void assertSummarizeStopsAtFirstBesu() {
+    String result = "";
+    try {
+      Supplier<Object> lambda = () -> besuStackHelper((null));
+      Supplier<Object> lambda2 = lambda::get;
+      assertThat(lambda2.get()).isNotNull();
+    } catch (Exception e) {
+      result = LogUtil.summarizeBesuStackTrace("besuSummary", e);
+    }
+    var lines =
+        assertFoundInTrace(
+            result, LogUtil.BESU_NAMESPACE, "besuSummary", "NullPointerException", 1);
+    assertThat(lines).hasSize(5);
+    assertThat(lines.get(0)).contains("besuSummary");
+  }
+
+  @Test
+  public void assertMaxDepth() {
+    String result = "";
+    try {
+      recurseTimesAndThrow(30);
+    } catch (Exception ex) {
+      result = LogUtil.summarizeStackTrace("besuSummary", ex, "java.lang");
+    }
+    System.out.println(result);
+    List<String> lines = Arrays.asList(result.split("\n"));
+    assertThat(lines).hasSize(22);
+    assertThat(lines.get(0)).contains("besuSummary");
+  }
+
+  private List<String> assertFoundInTrace(
+      final String result,
+      final String namespace,
+      final String ctxMessage,
+      final String excMessage,
+      final int times) {
+    System.out.println(result);
+    assertThat(result).containsOnlyOnce(ctxMessage);
+    assertThat(result).containsOnlyOnce(excMessage);
+
+    List<String> lines = Arrays.asList(result.split("\n"));
+    assertThat(
+            lines.stream()
+                .filter(s -> s.contains("at: "))
+                .filter(s -> s.contains(namespace))
+                .count())
+        .isEqualTo(times);
+    return lines;
+  }
+
+  private void recurseTimesAndThrow(final int times) {
+    if (times < 1) {
+      throw new RuntimeException("FakeStackOverflowError");
+    }
+    recurseTimesAndThrow(times - 1);
+  }
+
+  private Optional<Object> besuStackHelper(final Object o) {
+    return Optional.of(o);
+  }
+}