Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Broadened catch clause when extracting es query body #2993

Merged
merged 7 commits into from
Feb 6, 2023
Merged

Broadened catch clause when extracting es query body #2993

Show file tree
Hide file tree
Changes from 5 commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
6c0c9f5
Broadened catch clause when extracting es query body
JonasKunz Jan 30, 2023
6a821e3
Merge remote-tracking branch 'elastic/main' into es-querybody-error
JonasKunz Feb 1, 2023
326db67
Review fixed, ensured uncaught advice exceptions are printed to agent…
JonasKunz Feb 1, 2023
0dc2468
Altered log message
JonasKunz Feb 1, 2023
3d61f9d
Ensured that actually only suppressed exceptions are suppressed, swit…
JonasKunz Feb 1, 2023
8a25a12
Review fixes
JonasKunz Feb 6, 2023
23c02c4
Removed anonymous class from IndyBootStrapDispatcher for simplicity
JonasKunz Feb 6, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 13 additions & 0 deletions apm-agent-bootstrap/src/main/java/bootstrap/dispatcher/IndyBootstrapDispatcher.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@
public class IndyBootstrapDispatcher {

public static Method bootstrap;
public static Method logAdviceException;

private static final MethodHandle VOID_NOOP;

Expand Down Expand Up @@ -82,6 +83,18 @@ public static CallSite bootstrap(MethodHandles.Lookup lookup,
return callSite;
}

public static void logAdviceException(Throwable exception) {
try {
if (logAdviceException != null) {
logAdviceException.invoke(null, exception);
} else {
exception.printStackTrace();
}
} catch (Throwable t) {
t.printStackTrace();
JonasKunz marked this conversation as resolved.
Show resolved Hide resolved
}
}

public static void voidNoop() {
}
}
Binary file modified apm-agent-bootstrap/src/main/resources/bootstrap/java/lang/IndyBootstrapDispatcher.esclazz
View file
Open in desktop
Binary file not shown.
8 changes: 5 additions & 3 deletions apm-agent-core/src/main/java/co/elastic/apm/agent/bci/ElasticApmAgent.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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");
Expand Down Expand Up @@ -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));
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[For Reviewer]
I noticed that when an exception is thrown by an advice and suppressed by bytebuddy, it is only printed to stdout and not to the agent logs. I don't know if this already bit us in the past but I think it might in the future: If an advice throws an exception and we only have the agentlogs without the application stdout, we might not see the actual root cause: E.g. we might see messages due to orphaned spans without the actual exception causing this.

I fixed this in this PR by adjusting how exceptions suppressed by bytebuddy are logged. Feel free to object if you don't like it, I have no problem with removing it from this PR.

You can verify the behaviour via the existing InstrumentationTest.testSuppressException test.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Awesome! We were scratching our heads how to get advice exceptions into the agent logs without manually writing byte code for the stack manipulation. 👏

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah that's nice to hear! I initially tried a different approach (wrapping the MethodHandles, see 326db67#diff-2ec63f545539ff7d65f52ef01087a18c7cdd9eb7130de156fb412ae6fe9e580eR465), but then noticed that some Advices might intentionally throw exceptions, at least according to the tests.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice!! 👏

}

/**
Expand Down
23 changes: 23 additions & 0 deletions apm-agent-core/src/main/java/co/elastic/apm/agent/bci/IndyBootstrap.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -210,6 +210,9 @@ public class IndyBootstrap {
@Nullable
static Method indyBootstrapMethod;

@Nullable
static Method bootstrapLoggingMethod;

private static final CallDepth callDepth = CallDepth.get(IndyBootstrap.class);

public static Method getIndyBootstrapMethod(final Logger logger) {
Expand All @@ -227,6 +230,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.
*/
Expand Down Expand Up @@ -296,6 +315,10 @@ static void setJavaBaseModule(Class<?> targetClass) throws Throwable {
.invoke(targetClass);
}

public static void logExceptionThrownByAdvice(Throwable exception) {
LoggerFactory.getLogger(IndyBootstrap.class).error("Advice threw an exception, this should never happen!", exception);
JonasKunz marked this conversation as resolved.
Show resolved Hide resolved
}

/**
* Is called by {@code java.lang.IndyBootstrapDispatcher#bootstrap} via reflection.
* <p>
Expand Down
13 changes: 10 additions & 3 deletions .../java/co/elastic/apm/agent/esrestclient/ElasticsearchRestClientInstrumentationHelper.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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(
Expand Down Expand Up @@ -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);
}
}
Expand Down