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

Record exception for async servlet invocations #4677

Merged
merged 3 commits into from
Nov 22, 2021
Merged

Record exception for async servlet invocations #4677

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
8644b4e
Record exception for asyn servlet invocations
laurit Nov 19, 2021
4da3587
add back accidentally commented out line
laurit Nov 19, 2021
f7d0b65
rearrange test so that it passes on both jetty and tomcat
laurit Nov 22, 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
27 changes: 27 additions & 0 deletions ...opentelemetry/javaagent/instrumentation/servlet/v3_0/Servlet3AsyncContextStartAdvice.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.servlet.v3_0;

import static io.opentelemetry.javaagent.instrumentation.servlet.v3_0.Servlet3Singletons.helper;

import javax.servlet.AsyncContext;
import javax.servlet.ServletRequest;
import javax.servlet.http.HttpServletRequest;
import net.bytebuddy.asm.Advice;

@SuppressWarnings("unused")
public class Servlet3AsyncContextStartAdvice {

@Advice.OnMethodEnter(suppress = Throwable.class)
public static void start(
@Advice.This AsyncContext asyncContext,
@Advice.Argument(value = 0, readOnly = false) Runnable runnable) {
ServletRequest request = asyncContext.getRequest();
if (request instanceof HttpServletRequest) {
runnable = helper().wrapAsyncRunnable((HttpServletRequest) request, runnable);
}
}
}
7 changes: 5 additions & 2 deletions ...o/opentelemetry/javaagent/instrumentation/servlet/v3_0/Servlet3InstrumentationModule.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
import io.opentelemetry.javaagent.extension.instrumentation.InstrumentationModule;
import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.async.AsyncContextInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.async.AsyncContextStartInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.async.AsyncStartInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.service.ServletAndFilterInstrumentation;
import java.util.List;
Expand All @@ -34,12 +35,14 @@ public ElementMatcher.Junction<ClassLoader> classLoaderMatcher() {
public List<TypeInstrumentation> typeInstrumentations() {
return asList(
new AsyncContextInstrumentation(BASE_PACKAGE, adviceClassName(".AsyncDispatchAdvice")),
new AsyncContextStartInstrumentation(
BASE_PACKAGE, adviceClassName(".Servlet3AsyncContextStartAdvice")),
new AsyncStartInstrumentation(BASE_PACKAGE, adviceClassName(".Servlet3AsyncStartAdvice")),
new ServletAndFilterInstrumentation(
BASE_PACKAGE,
adviceClassName(".Servlet3Advice"),
adviceClassName(".Servlet3InitAdvice"),
adviceClassName(".Servlet3FilterInitAdvice")),
new AsyncStartInstrumentation(BASE_PACKAGE, adviceClassName(".Servlet3AsyncStartAdvice")));
adviceClassName(".Servlet3FilterInitAdvice")));
}

private static String adviceClassName(String suffix) {
Expand Down
38 changes: 20 additions & 18 deletions instrumentation/servlet/servlet-3.0/javaagent/src/test/groovy/JettyServlet3Test.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,9 +42,13 @@ abstract class JettyServlet3Test extends AbstractServlet3Test<Server, ServletCon
ServletException
}

boolean isAsyncTest() {
false
}

@Override
boolean hasResponseSpan(ServerEndpoint endpoint) {
return (IS_BEFORE_94 && endpoint == EXCEPTION) || super.hasResponseSpan(endpoint)
return (IS_BEFORE_94 && endpoint == EXCEPTION && !isAsyncTest()) || super.hasResponseSpan(endpoint)
}

@Override
Expand Down Expand Up @@ -140,9 +144,8 @@ class JettyServlet3TestAsync extends JettyServlet3Test {
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
boolean isAsyncTest() {
true
}
}

Expand All @@ -155,8 +158,9 @@ class JettyServlet3TestFakeAsync extends JettyServlet3Test {

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
// we expect this request to fail with http 500 but is succeeds with http 200
// when using -PtestLatestDeps=true
Copy link
Member

Choose a reason for hiding this comment

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

do u know if this is a limitation of jetty, our instrumentation, or our tests?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It is hard to say. My guess is that our test is weird and could very well depend on unspecified behaviour. Test first completes an AsyncContext and then lets exception propagate out of servlet. It might be better to not complete AsyncContext and rely on timeout (if AsyncContext isn't completed container will close it with timeout). In that case the behaviour should be better defined, but timeout has its own issues. There is always the problem that we'd need to make the timeout as short as possible to not waste time but still have it long enough so that test doesn't timeout before the exception is thrown even when running under load.
The tests that are currently failing also exhibit weirdness, apparently on tomcat10 exception test can break the subsequent test.

false
}
}

Expand Down Expand Up @@ -223,6 +227,11 @@ class JettyServlet3TestDispatchImmediate extends JettyDispatchTest {
TestServlet3.Sync
}

@Override
boolean isAsyncTest() {
true
}

@Override
protected void setupServlets(ServletContextHandler context) {
super.setupServlets(context)
Expand All @@ -237,12 +246,6 @@ class JettyServlet3TestDispatchImmediate extends JettyDispatchTest {
addServlet(context, "/dispatch" + INDEXED_CHILD.path, TestServlet3.DispatchImmediate)
addServlet(context, "/dispatch/recursive", TestServlet3.DispatchRecursive)
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

class JettyServlet3TestDispatchAsync extends JettyDispatchTest {
Expand All @@ -251,6 +254,11 @@ class JettyServlet3TestDispatchAsync extends JettyDispatchTest {
TestServlet3.Async
}

@Override
boolean isAsyncTest() {
true
}

@Override
protected void setupServlets(ServletContextHandler context) {
super.setupServlets(context)
Expand All @@ -270,12 +278,6 @@ class JettyServlet3TestDispatchAsync extends JettyDispatchTest {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

abstract class JettyDispatchTest extends JettyServlet3Test {
Expand Down
4 changes: 2 additions & 2 deletions instrumentation/servlet/servlet-3.0/javaagent/src/test/groovy/TestServlet3.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ class TestServlet3 {
resp.status = endpoint.status
resp.writer.print(endpoint.body)
context.complete()
throw new Exception(endpoint.body)
throw new ServletException(endpoint.body)
}
}
} finally {
Expand Down Expand Up @@ -157,7 +157,7 @@ class TestServlet3 {
resp.sendError(endpoint.status, endpoint.body)
break
case EXCEPTION:
throw new Exception(endpoint.body)
throw new ServletException(endpoint.body)
}
}
} finally {
Expand Down
18 changes: 0 additions & 18 deletions instrumentation/servlet/servlet-3.0/javaagent/src/test/groovy/TomcatServlet3Test.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -319,12 +319,6 @@ class TomcatServlet3TestAsync extends TomcatServlet3Test {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

class TomcatServlet3TestFakeAsync extends TomcatServlet3Test {
Expand All @@ -333,12 +327,6 @@ class TomcatServlet3TestFakeAsync extends TomcatServlet3Test {
Class<Servlet> servlet() {
TestServlet3.FakeAsync
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

class TomcatServlet3TestForward extends TomcatDispatchTest {
Expand Down Expand Up @@ -459,12 +447,6 @@ class TomcatServlet3TestDispatchAsync extends TomcatDispatchTest {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

abstract class TomcatDispatchTest extends TomcatServlet3Test {
Expand Down
3 changes: 3 additions & 0 deletions ...telemetry/javaagent/instrumentation/servlet/v5_0/JakartaServletInstrumentationModule.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.javaagent.extension.instrumentation.InstrumentationModule;
import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.async.AsyncContextInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.async.AsyncContextStartInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.async.AsyncStartInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.response.HttpServletResponseInstrumentation;
import io.opentelemetry.javaagent.instrumentation.servlet.common.service.ServletAndFilterInstrumentation;
Expand All @@ -28,6 +29,8 @@ public List<TypeInstrumentation> typeInstrumentations() {
return Arrays.asList(
new AsyncContextInstrumentation(
BASE_PACKAGE, adviceClassName(".async.AsyncDispatchAdvice")),
new AsyncContextStartInstrumentation(
BASE_PACKAGE, adviceClassName(".async.AsyncContextStartAdvice")),
new AsyncStartInstrumentation(BASE_PACKAGE, adviceClassName(".async.AsyncStartAdvice")),
new ServletAndFilterInstrumentation(
BASE_PACKAGE,
Expand Down
27 changes: 27 additions & 0 deletions ...o/opentelemetry/javaagent/instrumentation/servlet/v5_0/async/AsyncContextStartAdvice.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.servlet.v5_0.async;

import static io.opentelemetry.javaagent.instrumentation.servlet.v5_0.Servlet5Singletons.helper;

import jakarta.servlet.AsyncContext;
import jakarta.servlet.ServletRequest;
import jakarta.servlet.http.HttpServletRequest;
import net.bytebuddy.asm.Advice;

@SuppressWarnings("unused")
public class AsyncContextStartAdvice {

@Advice.OnMethodEnter(suppress = Throwable.class)
public static void start(
@Advice.This AsyncContext asyncContext,
@Advice.Argument(value = 0, readOnly = false) Runnable runnable) {
ServletRequest request = asyncContext.getRequest();
if (request instanceof HttpServletRequest) {
runnable = helper().wrapAsyncRunnable((HttpServletRequest) request, runnable);
}
}
}
22 changes: 2 additions & 20 deletions instrumentation/servlet/servlet-5.0/javaagent/src/test/groovy/JettyServlet5Test.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -119,12 +119,6 @@ class JettyServlet5TestAsync extends JettyServlet5Test {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

@IgnoreIf({ !jvm.java11Compatible })
Expand All @@ -137,8 +131,8 @@ class JettyServlet5TestFakeAsync extends JettyServlet5Test {

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
// we expect this request to fail with http 500 but is succeeds with http 200
false
}
}

Expand Down Expand Up @@ -222,12 +216,6 @@ class JettyServlet5TestDispatchImmediate extends JettyDispatchTest {
addServlet(context, "/dispatch" + INDEXED_CHILD.path, TestServlet5.DispatchImmediate)
addServlet(context, "/dispatch/recursive", TestServlet5.DispatchRecursive)
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

@IgnoreIf({ !jvm.java11Compatible })
Expand Down Expand Up @@ -256,12 +244,6 @@ class JettyServlet5TestDispatchAsync extends JettyDispatchTest {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

abstract class JettyDispatchTest extends JettyServlet5Test {
Expand Down
4 changes: 2 additions & 2 deletions instrumentation/servlet/servlet-5.0/javaagent/src/test/groovy/TestServlet5.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ class TestServlet5 {
resp.status = endpoint.status
resp.writer.print(endpoint.body)
context.complete()
throw new Exception(endpoint.body)
throw new ServletException(endpoint.body)
}
}
} finally {
Expand Down Expand Up @@ -157,7 +157,7 @@ class TestServlet5 {
resp.sendError(endpoint.status, endpoint.body)
break
case EXCEPTION:
throw new Exception(endpoint.body)
throw new ServletException(endpoint.body)
}
}
} finally {
Expand Down
18 changes: 0 additions & 18 deletions instrumentation/servlet/servlet-5.0/javaagent/src/test/groovy/TomcatServlet5Test.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -318,12 +318,6 @@ class TomcatServlet5TestAsync extends TomcatServlet5Test {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

class TomcatServlet5TestFakeAsync extends TomcatServlet5Test {
Expand All @@ -332,12 +326,6 @@ class TomcatServlet5TestFakeAsync extends TomcatServlet5Test {
Class<Servlet> servlet() {
TestServlet5.FakeAsync
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

class TomcatServlet5TestForward extends TomcatDispatchTest {
Expand Down Expand Up @@ -458,12 +446,6 @@ class TomcatServlet5TestDispatchAsync extends TomcatDispatchTest {
boolean errorEndpointUsesSendError() {
false
}

@Override
boolean testException() {
// https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/807
return false
}
}

abstract class TomcatDispatchTest extends TomcatServlet5Test {
Expand Down
6 changes: 4 additions & 2 deletions ...va/io/opentelemetry/javaagent/instrumentation/servlet/AsyncRequestCompletionListener.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,8 @@ public void onComplete(RESPONSE response) {
if (responseHandled.compareAndSet(false, true)) {
ServletResponseContext<RESPONSE> responseContext =
new ServletResponseContext<>(response, null);
instrumenter.end(context, requestContext, responseContext, null);
Throwable throwable = servletHelper.getAsyncException(requestContext.request());
instrumenter.end(context, requestContext, responseContext, throwable);
Comment on lines +38 to +39
Copy link
Member

Choose a reason for hiding this comment

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

does an exception thrown from a Runnable executed under AsyncContext.start(Runnable) always lead to servlet failure?

Copy link
Contributor Author

@laurit laurit Nov 20, 2021 •
edited
Loading

Choose a reason for hiding this comment

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

This is a good question. If the response has already been sent then exception can not turn it back. This behaviour is the same for regular servlets. So it is possible to have requests that were ok from http client's perspective, but failed (got an exception) from server's perspective.

Copy link
Member

Choose a reason for hiding this comment

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

good point 👍

}
}

Expand All @@ -46,7 +47,8 @@ public void onTimeout(long timeout) {
ServletResponseContext<RESPONSE> responseContext =
new ServletResponseContext<>(response, null);
responseContext.setTimeout(timeout);
instrumenter.end(context, requestContext, responseContext, null);
Throwable throwable = servletHelper.getAsyncException(requestContext.request());
instrumenter.end(context, requestContext, responseContext, throwable);
}
}

Expand Down
Loading