Skip to content

Keep spans active during AsyncHandler methods in AsyncHttpClient #1172

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

Merged
felixbarny merged 10 commits into from
May 8, 2020
Merged

Keep spans active during AsyncHandler methods in AsyncHttpClient #1172

Show file tree
Hide file tree
Changes from 5 commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
c2cd89e
Keep span active in AsyncHandler methods
milanvdm May 4, 2020
355f20c
Add initial attempt for testing custom AsyncHandler
milanvdm May 4, 2020
8463d41
Optimize passing span values
milanvdm May 5, 2020
b2eb4e5
Use assertj
milanvdm May 5, 2020
09b0479
Add extra assertion
milanvdm May 5, 2020
2e577d0
Update changelog
milanvdm May 5, 2020
3d08881
Fix failing tests
milanvdm May 5, 2020
766688b
Deactivate spans on exit
milanvdm May 5, 2020
a8fa295
Use getActive instead of currentTransaction
milanvdm May 7, 2020
4cf8353
Merge remote-tracking branch 'upstream/master' into instrument-on-com…
milanvdm May 7, 2020
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
33 changes: 27 additions & 6 deletions ...ain/java/co/elastic/apm/agent/asynchttpclient/AbstractAsyncHttpClientInstrumentation.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -178,8 +178,15 @@ public AsyncHandlerOnCompletedInstrumentation() {
}

@Advice.OnMethodEnter(suppress = Throwable.class)
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler) {
final Span span = handlerSpanMap.remove(asyncHandler);
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Local("span") Span span) {
span = handlerSpanMap.remove(asyncHandler);
if (span != null) {
span.activate();
}
}

@Advice.OnMethodExit(suppress = Throwable.class)
private static void onMethodExit(@Advice.This AsyncHandler<?> asyncHandler, @Nullable @Advice.Local("span") Span span) {
if (span != null) {
Comment thread
felixbarny marked this conversation as resolved.
span.end();
}
Expand All @@ -193,8 +200,15 @@ public AsyncHandlerOnThrowableInstrumentation() {
}

@Advice.OnMethodEnter(suppress = Throwable.class)
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Argument(0) Throwable t) {
final Span span = handlerSpanMap.remove(asyncHandler);
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Local("span") Span span) {
span = handlerSpanMap.remove(asyncHandler);
if (span != null) {
span.activate();
}
}

@Advice.OnMethodExit(suppress = Throwable.class)
private static void onMethodExit(@Advice.This AsyncHandler<?> asyncHandler, @Nullable @Advice.Local("span") Span span, @Advice.Argument(0) Throwable t) {
if (span != null) {
span.captureException(t).end();
}
Expand All @@ -208,8 +222,15 @@ public AsyncHandlerOnStatusReceivedInstrumentation() {
}

@Advice.OnMethodEnter(suppress = Throwable.class)
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Argument(0) HttpResponseStatus status) {
final Span span = handlerSpanMap.get(asyncHandler);
private static void onMethodEnter(@Advice.This AsyncHandler<?> asyncHandler, @Advice.Local("span") Span span, @Advice.Argument(0) HttpResponseStatus status) {
span = handlerSpanMap.remove(asyncHandler);
if (span != null) {
span.activate();
}
}

@Advice.OnMethodExit(suppress = Throwable.class)
private static void onMethodExit(@Advice.This AsyncHandler<?> asyncHandler, @Nullable @Advice.Local("span") Span span, @Advice.Argument(0) HttpResponseStatus status) {
if (span != null) {
span.getContext().getHttp().withStatusCode(status.getStatusCode());
}
Expand Down
34 changes: 28 additions & 6 deletions ...rc/test/java/co/elastic/apm/agent/asynchttpclient/AsyncHttpClientInstrumentationTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,9 +11,9 @@
* 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
Expand All @@ -25,10 +25,7 @@
package co.elastic.apm.agent.asynchttpclient;

import co.elastic.apm.agent.httpclient.AbstractHttpClientInstrumentationTest;
import org.asynchttpclient.AsyncCompletionHandlerBase;
import org.asynchttpclient.AsyncHttpClient;
import org.asynchttpclient.Dsl;
import org.asynchttpclient.RequestBuilder;
import org.asynchttpclient.*;
import org.junit.After;
import org.junit.Before;
import org.junit.runner.RunWith;
Expand All @@ -38,6 +35,7 @@
import java.util.Arrays;

import static org.asynchttpclient.Dsl.asyncHttpClient;
import static org.assertj.core.api.Assertions.assertThat;

@RunWith(Parameterized.class)
public class AsyncHttpClientInstrumentationTest extends AbstractHttpClientInstrumentationTest {
Expand All @@ -49,11 +47,35 @@ public AsyncHttpClientInstrumentationTest(RequestExecutor requestExecutor) {
this.requestExecutor = requestExecutor;
}

public static AsyncHandler<Response> customAsyncHandler = new AsyncCompletionHandler<Response>() {
@Override
public State onStatusReceived(HttpResponseStatus responseStatus) {
assertThat(tracer.currentTransaction()).isNotNull();
assertThat(tracer.currentTransaction().isExit()).isTrue();
return State.CONTINUE;
}

@Override
public void onThrowable(Throwable t) {
assertThat(tracer.currentTransaction()).isNotNull();
assertThat(tracer.currentTransaction().isExit()).isTrue();
}

@Override
public Response onCompleted(Response response) {
assertThat(tracer.currentTransaction()).isNotNull();

@felixbarny felixbarny May 5, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

To double-check, do the tests fail when doing isNull()?

@milanvdm milanvdm May 5, 2020

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Ill double-check all PR requirements now and make sure the tests make sense :)

@milanvdm milanvdm May 5, 2020

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

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?

@felixbarny felixbarny May 5, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

The tests are failing on CI for the same reason. Not sure what causes that 🤔

@milanvdm milanvdm May 5, 2020

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

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 :)

@milanvdm milanvdm May 5, 2020

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

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.

@milanvdm milanvdm May 7, 2020 •
edited
Loading

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

@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.

@felixbarny felixbarny May 7, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

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().

@felixbarny felixbarny May 7, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

See also #1174

@milanvdm milanvdm May 7, 2020

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Cool, thanks :)
Ive applied the changes and the tests now pass correctly!

assertThat(tracer.currentTransaction().isExit()).isTrue();
return response;
}

};

@Parameterized.Parameters()
public static Iterable<RequestExecutor> data() {
return Arrays.asList(
(client, path) -> client.executeRequest(new RequestBuilder().setUrl(path).build()).get(),
(client, path) -> client.executeRequest(new RequestBuilder().setUrl(path).build(), new AsyncCompletionHandlerBase()).get(),
(client, path) -> client.executeRequest(new RequestBuilder().setUrl(path).build(), customAsyncHandler).get(),
(client, path) -> client.prepareGet(path).execute(new AsyncCompletionHandlerBase()).get(),
(client, path) -> client.prepareGet(path).execute().get()
);
Expand Down