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

Fix tomcat async spans #4339

Merged
merged 6 commits into from
Oct 13, 2021
Merged

Fix tomcat async spans #4339

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
b63c50a
Add test
trask Oct 10, 2021
ea57d6b
Fix tomcat async spans
trask Oct 10, 2021
113342d
Merge remote-tracking branch 'upstream/main' into fix-tomcat-async-spans
trask Oct 11, 2021
5ee8e4b
Preserve existing test controller behavior
trask Oct 11, 2021
81cb6cf
Comments
trask Oct 11, 2021
aeb6f7e
Merge remote-tracking branch 'upstream/main' into fix-tomcat-async-spans
trask Oct 13, 2021
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
6 changes: 6 additions & 0 deletions instrumentation/dropwizard-testing/src/test/groovy/DropwizardAsyncTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,12 @@ class DropwizardAsyncTest extends DropwizardTest {
AsyncServiceResource
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the JAX-RS controller spans
return false
}

static class AsyncTestApp extends Application<Configuration> {
@Override
void initialize(Bootstrap<Configuration> bootstrap) {
Expand Down
6 changes: 6 additions & 0 deletions instrumentation/grizzly-2.0/javaagent/src/test/groovy/GrizzlyAsyncTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,12 @@ class GrizzlyAsyncTest extends GrizzlyTest {
false
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the JAX-RS controller spans
return false
}

@Path("/")
static class AsyncServiceResource {
private ExecutorService executor = Executors.newSingleThreadExecutor()
Expand Down
6 changes: 6 additions & 0 deletions instrumentation/grizzly-2.0/javaagent/src/test/groovy/GrizzlyFilterchainServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -70,6 +70,12 @@ class GrizzlyFilterchainServerTest extends HttpServerTest<HttpServer> implements
false
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the controller spans
return false
}

void setUpTransport(FilterChain filterChain) {
TCPNIOTransportBuilder transportBuilder = TCPNIOTransportBuilder.newInstance()
.setOptimizedForMultiplexing(true)
Expand Down
6 changes: 6 additions & 0 deletions instrumentation/play/play-2.4/javaagent/src/test/groovy/server/PlayServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -86,6 +86,12 @@ class PlayServerTest extends HttpServerTest<Server> implements AgentTestTrait {
return true
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the controller spans
return false
}

@Override
void handlerSpan(TraceAssert trace, int index, Object parent, String method = "GET", ServerEndpoint endpoint = SUCCESS) {
trace.span(index) {
Expand Down
6 changes: 6 additions & 0 deletions ...oovy/io/opentelemetry/instrumentation/ratpack/server/AbstractRatpackHttpServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,12 @@ abstract class AbstractRatpackHttpServerTest extends HttpServerTest<RatpackServe
true
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the controller spans
return false
}

@Override
void handlerSpan(TraceAssert trace, int index, Object parent, String method = "GET", ServerEndpoint endpoint = SUCCESS) {
trace.span(index) {
Expand Down
13 changes: 2 additions & 11 deletions ...rc/test/groovy/io/opentelemetry/javaagent/instrumentation/tomcat/v7_0/AsyncServlet.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,6 @@ import io.opentelemetry.instrumentation.test.base.HttpServerTest
import javax.servlet.annotation.WebServlet
import javax.servlet.http.HttpServletRequest
import javax.servlet.http.HttpServletResponse
import java.util.concurrent.CountDownLatch

import static io.opentelemetry.instrumentation.test.base.HttpServerTest.ServerEndpoint.CAPTURE_HEADERS
import static io.opentelemetry.instrumentation.test.base.HttpServerTest.ServerEndpoint.ERROR
Expand All @@ -26,7 +25,6 @@ class AsyncServlet extends AbstractHttpServlet {
@Override
protected void service(HttpServletRequest req, HttpServletResponse resp) {
HttpServerTest.ServerEndpoint endpoint = HttpServerTest.ServerEndpoint.forPath(req.servletPath)
def latch = new CountDownLatch(1)
def context = req.startAsync()
context.start {
try {
Expand All @@ -36,44 +34,37 @@ class AsyncServlet extends AbstractHttpServlet {
case SUCCESS:
resp.status = endpoint.status
resp.writer.print(endpoint.body)
context.complete()
break
case INDEXED_CHILD:
endpoint.collectSpanAttributes { req.getParameter(it) }
resp.status = endpoint.status
context.complete()
break
case QUERY_PARAM:
resp.status = endpoint.status
resp.writer.print(req.queryString)
context.complete()
break
case REDIRECT:
resp.sendRedirect(endpoint.body)
context.complete()
break
case CAPTURE_HEADERS:
resp.setHeader("X-Test-Response", req.getHeader("X-Test-Request"))
resp.status = endpoint.status
resp.writer.print(endpoint.body)
context.complete()
break
case ERROR:
resp.status = endpoint.status
resp.writer.print(endpoint.body)
context.complete()
break
case EXCEPTION:
resp.status = endpoint.status
resp.writer.print(endpoint.body)
context.complete()
throw new Exception(endpoint.body)
}
}
} finally {
latch.countDown()
// complete at the end so the server span will end after the controller span
context.complete()
}
}
latch.await()
}
}
5 changes: 4 additions & 1 deletion .../src/main/java/io/opentelemetry/javaagent/instrumentation/tomcat/common/TomcatHelper.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
import io.opentelemetry.context.Scope;
import io.opentelemetry.instrumentation.api.instrumenter.Instrumenter;
import io.opentelemetry.instrumentation.api.servlet.AppServerBridge;
import io.opentelemetry.instrumentation.api.tracer.HttpServerTracer;
import io.opentelemetry.javaagent.instrumentation.servlet.ServletHelper;
import org.apache.coyote.Request;
import org.apache.coyote.Response;
Expand All @@ -32,7 +33,9 @@ public boolean shouldStart(Context parentContext, Request request) {
}

public Context start(Context parentContext, Request request) {
return instrumenter.start(parentContext, request);
Context context = instrumenter.start(parentContext, request);
request.setAttribute(HttpServerTracer.CONTEXT_ATTRIBUTE, context);
Copy link
Member

Choose a reason for hiding this comment

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

Is this the actual fix?

Copy link
Contributor

Choose a reason for hiding this comment

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

It should be. The problem is in

opentelemetry-java-instrumentation/instrumentation/servlet/servlet-common/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/servlet/ServletHelper.java

Line 101 in 8066f27

Context context = getServerContext(request);
for async listeners we need to get the context for server span which servlet instrumentation stores in a request attribute. This works because HttpServletRequest implementation on tomcat stores attributes on the underlying coyote request. The only other server that does not use servlet api based instrumenter is undertow where request is always ended from a callback and presumably doesn't need special handling for async requests.
I guess alternatively we could add a field to AppServerBridge to carry context and in ServletHelper try both AppServerBridge and request attribute.

Copy link
Member Author

Choose a reason for hiding this comment

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

this would be nice if it leads to unifying app server behavior a bit, I created #4347 to revisit the idea

return context;
}

public void end(
Expand Down
6 changes: 6 additions & 0 deletions ...vertx-reactive-3.5/javaagent/src/latestDepTest/groovy/server/VertxRxHttpServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,12 @@ class VertxRxHttpServerTest extends HttpServerTest<Vertx> implements AgentTestTr
return true
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the controller spans
return false
}

protected Class<AbstractVerticle> verticle() {
return VertxReactiveWebServer
}
Expand Down
6 changes: 6 additions & 0 deletions ...vertx-reactive-3.5/javaagent/src/version35Test/groovy/server/VertxRxHttpServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,12 @@ class VertxRxHttpServerTest extends HttpServerTest<Vertx> implements AgentTestTr
return true
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the controller spans
return false
}

protected Class<AbstractVerticle> verticle() {
return VertxReactiveWebServer
}
Expand Down
6 changes: 6 additions & 0 deletions ...mentation/vertx-web-3.0/testing/src/main/groovy/server/AbstractVertxHttpServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,12 @@ abstract class AbstractVertxHttpServerTest extends HttpServerTest<Vertx> impleme
false
}

@Override
boolean verifyServerSpanEndTime() {
// server spans are ended inside of the controller spans
return false
}

@Override
String expectedServerSpanName(ServerEndpoint endpoint) {
switch (endpoint) {
Expand Down
9 changes: 9 additions & 0 deletions ...g-common/src/main/groovy/io/opentelemetry/instrumentation/test/base/HttpServerTest.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -135,6 +135,10 @@ abstract class HttpServerTest<SERVER> extends InstrumentationSpecification imple
false
}

boolean verifyServerSpanEndTime() {
return true
}

List<AttributeKey<?>> extraAttributes() {
[]
}
Expand Down Expand Up @@ -506,6 +510,11 @@ abstract class HttpServerTest<SERVER> extends InstrumentationSpecification imple
(0..size - 1).each {
trace(it, spanCount) {
def spanIndex = 0
if (verifyServerSpanEndTime() && spanCount > 1) {
(1..spanCount - 1).each { index ->
assert it.span(0).endEpochNanos - it.span(index).endEpochNanos >= 0
}
}
serverSpan(it, spanIndex++, traceID, parentID, method, response?.content()?.length(), endpoint)
if (hasHandlerSpan(endpoint)) {
handlerSpan(it, spanIndex++, span(0), method, endpoint)
Expand Down