Keep spans active during AsyncHandler methods in AsyncHttpClient#1172
Keep spans active during AsyncHandler methods in AsyncHttpClient#1172felixbarny merged 10 commits intoelastic:masterfrom
Conversation
| public static AsyncHandler<Response> customAsyncHandler = new AsyncCompletionHandler<Response>() { | ||
| @Override | ||
| public State onStatusReceived(HttpResponseStatus responseStatus) { | ||
| assert(tracer.currentTransaction() != null); |
There was a problem hiding this comment.
Not sure how to add a proper test making sure the context in the methods are active or not.
💚 Build Succeeded
Expand to view the summary
Build stats
Test stats 🧪
|
...c/main/java/co/elastic/apm/agent/asynchttpclient/AbstractAsyncHttpClientInstrumentation.java
Outdated
Show resolved
Hide resolved
| @@ -179,6 +179,14 @@ public AsyncHandlerOnCompletedInstrumentation() { | |||
|
|
|||
| @Advice.OnMethodEnter(suppress = Throwable.class) | |||
| private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler) { | |||
There was a problem hiding this comment.
Making sure that wrapped AsyncHandlers work as expected (activate and deactivate only in outer-most AsyncHandler
| private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler) { | |
| private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Local("span") Span span) { |
There was a problem hiding this comment.
Bit unsure on what you mean with activate and deactive in the outer-most AsyncHandler?
There was a problem hiding this comment.
Following the decorator pattern, calling AsyncHandler#onComplete may result in the handler calling another, wrapped/nested AsyncHandler#onComplete. We want to make sure that only the first AsyncHandler activates and deactivates the span.
In your first draft, the first AsyncHandler would activate the span but the last AsyncHandler in the chain would deactivate it. This would result in the span not being active in the first AsyncHandler after it called onComplete on its delegate handler.
private final AsyncHandler<Response> delegate;
@Override
public Response onCompleted(Response response) {
try {
return delegate.onCompleted(response);
} finally {
tracer.getActive() // returns null
}
}
By propagating the active span via a @Advice.Local, we have fixed that problem.
...c/main/java/co/elastic/apm/agent/asynchttpclient/AbstractAsyncHttpClientInstrumentation.java
Outdated
Show resolved
Hide resolved
...n/src/test/java/co/elastic/apm/agent/asynchttpclient/AsyncHttpClientInstrumentationTest.java
Outdated
Show resolved
Hide resolved
|
|
||
| @Override | ||
| public Response onCompleted(Response response) { | ||
| assertThat(tracer.currentTransaction()).isNotNull(); |
There was a problem hiding this comment.
To double-check, do the tests fail when doing isNull()?
There was a problem hiding this comment.
Ill double-check all PR requirements now and make sure the tests make sense :)
There was a problem hiding this comment.
Mmm, the changes make the existing tests fail (even when I remove the newly added customAsyncHandler.
testHttpCall[3] Time elapsed: 0.519 sec <<< ERROR!
org.awaitility.core.ConditionTimeoutException:
Assertion condition defined as a lambda expression in co.elastic.apm.agent.MockReporter
Expecting actual not to be empty within 500 milliseconds.
Seems to me that is a local problem linked to my laptop. Will try to figure out why it is doing that. Any chance you have a docker-image able to run the tests?
There was a problem hiding this comment.
The tests are failing on CI for the same reason. Not sure what causes that 🤔
There was a problem hiding this comment.
Oh wow, interesting. Very strange that the new instrumentations make the current tests time-out. Will have a look later today when I have a bit more time :)
There was a problem hiding this comment.
I tried to figure it out but tbh, I have no idea.
Only thing I could think of was that Im using a new AsyncCompletionHandler<Response> in the test and somehow the methods of this subclass don't get matched properly.
There was a problem hiding this comment.
@felixbarny I've played around with it a bit more:
@Advice.OnMethodEnter(suppress = Throwable.class)
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Local("span") Span span) {
span = handlerSpanMap.remove(asyncHandler);
if (span != null) {
span.activate();
System.out.println(tracer.currentTransaction());
System.out.println("=======================");
}
}
This prints out:
null
=======================
So it seems that activating the span does not mean I can do assertThat(tracer.currentTransaction()).isNotNull(); in the test.
There was a problem hiding this comment.
Yes, that's true. You should assert that tracer.getActive() is not null instead. I agree that if tracer.getActive() returns non-null, tracer.getTranaction() should do, too. I have an idea how to accomplish that. In the meantime, please assert on tracer.getActive().
There was a problem hiding this comment.
Cool, thanks :)
Ive applied the changes and the tests now pass correctly!
Codecov Report
@@ Coverage Diff @@
## master #1172 +/- ##
=========================================
Coverage 59.67% 59.67%
Complexity 83 83
=========================================
Files 328 328
Lines 15026 15026
Branches 2091 2091
=========================================
Hits 8967 8967
Misses 5448 5448
Partials 611 611 Continue to review full report at Codecov.
|
...c/main/java/co/elastic/apm/agent/asynchttpclient/AbstractAsyncHttpClientInstrumentation.java
Show resolved
Hide resolved
...c/main/java/co/elastic/apm/agent/asynchttpclient/AbstractAsyncHttpClientInstrumentation.java
Show resolved
Hide resolved
|
Great work, thanks! ❤️ |
3 participants
What does this PR do?
Currently, when using a custom
AsyncHandlerwith theAsyncHttpClient, there is no active span in the callback methods.This PR makes sure that span are activated when entering those methods making it possible for users to use tracing-context in those methods.
Checklist