Broadened catch clause when extracting es query body, fixed advice ex…

…ception printing (#2993)

apm-agent-bootstrap/src/main/java/bootstrap/dispatcher/IndyBootstrapDispatcher.java

@@ -39,6 +39,7 @@
 public class IndyBootstrapDispatcher {
 
     public static Method bootstrap;
+    public static Method logAdviceException;
 
     private static final MethodHandle VOID_NOOP;
 
@@ -63,7 +64,7 @@ public static CallSite bootstrap(MethodHandles.Lookup lookup,
                     adviceMethodType,
                     args);
             } catch (Exception e) {
-                e.printStackTrace();
+                printStackTrace(e);
             }
         }
         if (callSite == null) {
@@ -82,6 +83,34 @@ public static CallSite bootstrap(MethodHandles.Lookup lookup,
         return callSite;
     }
 
+    public static void logAdviceException(Throwable exception) {
+        try {
+            if (logAdviceException != null) {
+                logAdviceException.invoke(null, exception);
+            } else {
+                printStackTrace(exception);
+            }
+        } catch (Throwable t) {
+            printStackTrace(t);
+        }
+    }
+
+    /**
+     * Replicates the logic from SystemStandardOutputLogger, as it cannot be directly accessed here.
+     * Note that we don't log anything if the security manager is enabled, as we don't want to deal
+     * with doPrivileged() here.
+     *
+     * @param t the throwable to print
+     */
+    private static void printStackTrace(Throwable t) {
+        if (System.getSecurityManager() == null) {
+            boolean loggingDisabled = System.getProperty("elastic.apm.system_output_disabled") != null || System.getenv("ELASTIC_APM_SYSTEM_OUTPUT_DISABLED") != null;
+            if (!loggingDisabled) {
+                t.printStackTrace();
+            }
+        }
+    }
+
     public static void voidNoop() {
     }
 }

apm-agent-common/src/main/java/co/elastic/apm/agent/common/util/SystemStandardOutputLogger.java

@@ -25,6 +25,8 @@
  * A utility for writing to System standard output and standard error output streams.
  * Prints can be disabled through the {@code elastic.apm.system_output_disabled} system property or the corresponding
  * {@code ELASTIC_APM_SYSTEM_OUTPUT_DISABLED} environment variable.
+ * <p>
+ * Important: The logic here is replicated in IndyBootstrapDispatcher, as it cannot access this class directly.
  */
 public class SystemStandardOutputLogger {
     private static final String DISABLED_SYSTEM_PROPERTY = "elastic.apm.system_output_disabled";

apm-agent-core/src/main/java/co/elastic/apm/agent/bci/ElasticApmAgent.java

@@ -62,6 +62,8 @@
 import net.bytebuddy.dynamic.ClassFileLocator;
 import net.bytebuddy.dynamic.DynamicType;
 import net.bytebuddy.dynamic.scaffold.TypeValidation;
+import net.bytebuddy.implementation.bytecode.StackManipulation;
+import net.bytebuddy.implementation.bytecode.member.MethodInvocation;
 import net.bytebuddy.matcher.ElementMatcher;
 import net.bytebuddy.matcher.ElementMatchers;
 import net.bytebuddy.pool.TypePool;
@@ -99,7 +101,6 @@
 import static co.elastic.apm.agent.bci.bytebuddy.ClassLoaderNameMatcher.classLoaderWithNamePrefix;
 import static co.elastic.apm.agent.bci.bytebuddy.ClassLoaderNameMatcher.isReflectionClassLoader;
 import static co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.anyMatch;
-import static net.bytebuddy.asm.Advice.ExceptionHandler.Default.PRINTING;
 import static net.bytebuddy.matcher.ElementMatchers.any;
 import static net.bytebuddy.matcher.ElementMatchers.is;
 import static net.bytebuddy.matcher.ElementMatchers.isAbstract;
@@ -327,7 +328,7 @@ public void run() {
     public static boolean areModulesSupported() {
         return ModuleOpener.areModulesSupported();
     }
-    
+
     public static boolean openModule(Class<?> classFromTargetModule, ClassLoader openTo, Collection<String> packagesToOpen) {
         if (instrumentation == null) {
             throw new IllegalStateException("Can't open modules before the agent has been initialized");
@@ -511,10 +512,11 @@ public boolean matches(MethodDescription target) {
                 }
             }
         };
+        StackManipulation exceptionHandler = MethodInvocation.invoke(new MethodDescription.ForLoadedMethod(IndyBootstrap.getExceptionHandlerMethod(logger)));
         return new AgentBuilder.Transformer.ForAdvice(withCustomMapping)
             .advice(instrumentationStats.shouldMeasureMatching() ? statsCollectingMatcher : matcher, instrumentation.getAdviceClassName())
             .include(ClassLoader.getSystemClassLoader(), PrivilegedActionUtils.getClassLoader(instrumentation.getClass()))
-            .withExceptionHandler(PRINTING);
+            .withExceptionHandler(new Advice.ExceptionHandler.Simple(exceptionHandler));
     }
 
     /**

apm-agent-core/src/main/java/co/elastic/apm/agent/bci/IndyBootstrap.java

@@ -210,8 +210,16 @@ public class IndyBootstrap {
     @Nullable
     static Method indyBootstrapMethod;
 
+    @Nullable
+    static Method bootstrapLoggingMethod;
+
     private static final CallDepth callDepth = CallDepth.get(IndyBootstrap.class);
 
+    private static Logger logger() {
+        // must not be a static field as it would initialize logging before it's ready
+        return LoggerFactory.getLogger(IndyBootstrap.class);
+    }
+
     public static Method getIndyBootstrapMethod(final Logger logger) {
         if (indyBootstrapMethod != null) {
             return indyBootstrapMethod;
@@ -227,6 +235,22 @@ public static Method getIndyBootstrapMethod(final Logger logger) {
         }
     }
 
+
+    public static Method getExceptionHandlerMethod(final Logger logger) {
+        if (bootstrapLoggingMethod != null) {
+            return bootstrapLoggingMethod;
+        }
+        try {
+            Class<?> indyBootstrapClass = initIndyBootstrap(logger);
+            indyBootstrapClass
+                .getField("logAdviceException")
+                .set(null, IndyBootstrap.class.getMethod("logExceptionThrownByAdvice", Throwable.class));
+            return bootstrapLoggingMethod = indyBootstrapClass.getMethod("logAdviceException", Throwable.class);
+        } catch (Exception e) {
+            throw new RuntimeException(e);
+        }
+    }
+
     /**
      * Injects the {@code java.lang.IndyBootstrapDispatcher} class into the bootstrap class loader if it wasn't already.
      */
@@ -296,6 +320,10 @@ static void setJavaBaseModule(Class<?> targetClass) throws Throwable {
             .invoke(targetClass);
     }
 
+    public static void logExceptionThrownByAdvice(Throwable exception) {
+        logger().error("Advice threw an exception, this should never happen!", exception);
+    }
+
     /**
      * Is called by {@code java.lang.IndyBootstrapDispatcher#bootstrap} via reflection.
      * <p>
@@ -376,8 +404,7 @@ private static ConstantCallSite internalBootstrap(MethodHandles.Lookup lookup, S
                 // avoid re-entrancy and stack overflow errors
                 // may happen when bootstrapping an instrumentation that also gets triggered during the bootstrap
                 // for example, adding correlation ids to the thread context when executing logger.debug.
-                // We cannot use a static logger field as it would initialize logging before it's ready
-                LoggerFactory.getLogger(IndyBootstrap.class).warn("Nested instrumented invokedynamic instruction linkage detected", new Throwable());
+                logger().warn("Nested instrumented invokedynamic instruction linkage detected", new Throwable());
                 return null;
             }
             String adviceClassName = (String) args[0];
@@ -430,8 +457,7 @@ private static ConstantCallSite internalBootstrap(MethodHandles.Lookup lookup, S
             if (ElasticApmAgent.areModulesSupported() && !requiredModuleOpens.isEmpty()) {
                 boolean success = addRequiredModuleOpens(requiredModuleOpens, targetClassLoader, pluginClassLoader);
                 if (!success) {
-                    // must not be a static field as it would initialize logging before it's ready
-                    LoggerFactory.getLogger(IndyBootstrap.class).error("Cannot bootstrap advice because required modules could not be opened!");
+                    logger().error("Cannot bootstrap advice because required modules could not be opened!");
                     return null;
                 }
             }
@@ -443,8 +469,7 @@ private static ConstantCallSite internalBootstrap(MethodHandles.Lookup lookup, S
             MethodHandle methodHandle = indyLookup.findStatic(adviceInPluginCL, adviceMethodName, adviceMethodType);
             return new ConstantCallSite(methodHandle);
         } catch (Exception e) {
-            // must not be a static field as it would initialize logging before it's ready
-            LoggerFactory.getLogger(IndyBootstrap.class).error(e.getMessage(), e);
+            logger().error(e.getMessage(), e);
             return null;
         } finally {
             callDepth.decrement();
@@ -473,8 +498,7 @@ private static boolean addRequiredModuleOpens(Map<String, List<String>> required
                 }
             }
         } catch (ClassNotFoundException e) {
-            // must not be a static field as it would initialize logging before it's ready
-            LoggerFactory.getLogger(IndyBootstrap.class).error("Cannot open module because witness class is not found", e);
+            logger().error("Cannot open module because witness class is not found", e);
             return false;
         }
         return true;

apm-agent-plugins/apm-es-restclient-plugin/apm-es-restclient-plugin-common/src/main/java/co/elastic/apm/agent/esrestclient/ElasticsearchRestClientInstrumentationHelper.java

@@ -18,32 +18,34 @@
  */
 package co.elastic.apm.agent.esrestclient;
 
+import co.elastic.apm.agent.common.util.WildcardMatcher;
 import co.elastic.apm.agent.impl.ElasticApmTracer;
 import co.elastic.apm.agent.impl.GlobalTracer;
 import co.elastic.apm.agent.impl.transaction.AbstractSpan;
 import co.elastic.apm.agent.impl.transaction.Outcome;
 import co.elastic.apm.agent.impl.transaction.Span;
-import co.elastic.apm.agent.common.util.WildcardMatcher;
 import co.elastic.apm.agent.objectpool.Allocator;
 import co.elastic.apm.agent.objectpool.ObjectPool;
 import co.elastic.apm.agent.sdk.logging.Logger;
 import co.elastic.apm.agent.sdk.logging.LoggerFactory;
 import co.elastic.apm.agent.util.IOUtils;
+import co.elastic.apm.agent.util.LoggerUtils;
 import org.apache.http.HttpEntity;
 import org.apache.http.HttpHost;
 import org.elasticsearch.client.Response;
 import org.elasticsearch.client.ResponseException;
 import org.elasticsearch.client.ResponseListener;
 
 import javax.annotation.Nullable;
-import java.io.IOException;
 import java.util.Arrays;
 import java.util.List;
 import java.util.concurrent.CancellationException;
 
 public class ElasticsearchRestClientInstrumentationHelper {
 
     private static final Logger logger = LoggerFactory.getLogger(ElasticsearchRestClientInstrumentationHelper.class);
+
+    private static final Logger unsupportedOperationOnceLogger = LoggerUtils.logOnce(logger);
     private static final ElasticsearchRestClientInstrumentationHelper INSTANCE = new ElasticsearchRestClientInstrumentationHelper(GlobalTracer.requireTracerImpl());
 
     public static final List<WildcardMatcher> QUERY_WILDCARD_MATCHERS = Arrays.asList(
@@ -104,7 +106,12 @@ public Span createClientSpan(String method, String endpoint, @Nullable HttpEntit
                 if (httpEntity != null && httpEntity.isRepeatable()) {
                     try {
                         IOUtils.readUtf8Stream(httpEntity.getContent(), span.getContext().getDb().withStatementBuffer());
-                    } catch (IOException e) {
+                    } catch (UnsupportedOperationException e) {
+                        // special case for hibernatesearch versions pre 6.0:
+                        // those don't support httpEntity.getContent() and throw an UnsupportedException when called.
+                        unsupportedOperationOnceLogger.error(
+                            "Failed to read Elasticsearch client query from request body, most likely because you are using hibernatesearch pre 6.0", e);
+                    } catch (Exception e) {
                         logger.error("Failed to read Elasticsearch client query from request body", e);
                     }
                 }