Merge pull request #179 from DataDog/tyler/filter-errors

Change point where servlet instrumentation is applied
This commit is contained in:
Andrew Kent 2017-12-28 09:45:32 -08:00 committed by GitHub
commit f546dd4188
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 301 additions and 2 deletions

View File

@ -12,6 +12,7 @@ import spock.lang.Unroll
import javax.jms.Connection
import javax.jms.Session
import javax.jms.TextMessage
import java.util.concurrent.CountDownLatch
import java.util.concurrent.atomic.AtomicReference
class JMS1Test extends Specification {
@ -162,16 +163,18 @@ class JMS1Test extends Specification {
@Unroll
def "sending to a MessageListener on #resourceName generates a span"() {
setup:
def lock = new CountDownLatch(1)
def messageRef = new AtomicReference<TextMessage>()
def producer = session.createProducer(destination)
def consumer = session.createConsumer(destination)
consumer.setMessageListener { message ->
Thread.sleep(5) // Slow things down a bit.
lock.await() // ensure the producer trace is reported first.
messageRef.set(message)
}
def message = session.createTextMessage("a message")
producer.send(message)
lock.countDown()
writer.waitForTraces(2)
expect:

View File

@ -21,6 +21,7 @@ import spock.lang.Unroll
import javax.jms.Session
import javax.jms.TextMessage
import java.util.concurrent.CountDownLatch
import java.util.concurrent.atomic.AtomicReference
class JMS2Test extends Specification {
@ -152,16 +153,18 @@ class JMS2Test extends Specification {
@Unroll
def "sending to a MessageListener on #resourceName generates a span"() {
setup:
def lock = new CountDownLatch(1)
def messageRef = new AtomicReference<TextMessage>()
def producer = session.createProducer(destination)
def consumer = session.createConsumer(destination)
consumer.setMessageListener { message ->
Thread.sleep(10) // Slow things down a bit.
lock.await() // ensure the producer trace is reported first.
messageRef.set(message)
}
def message = session.createTextMessage("a message")
producer.send(message)
lock.countDown()
writer.waitForTraces(2)
expect:

View File

@ -0,0 +1,111 @@
package dd.inst.servlet2;
import static dd.trace.ClassLoaderMatcher.classLoaderHasClasses;
import static net.bytebuddy.matcher.ElementMatchers.hasSuperType;
import static net.bytebuddy.matcher.ElementMatchers.isInterface;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.not;
import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
import com.google.auto.service.AutoService;
import dd.trace.DDAdvice;
import dd.trace.HelperInjector;
import dd.trace.Instrumenter;
import io.opentracing.ActiveSpan;
import io.opentracing.SpanContext;
import io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter;
import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;
import io.opentracing.propagation.Format;
import io.opentracing.tag.Tags;
import io.opentracing.util.GlobalTracer;
import java.util.Collections;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.asm.Advice;
@AutoService(Instrumenter.class)
public final class FilterChain2Instrumentation implements Instrumenter {
public static final String FILTER_CHAIN_OPERATION_NAME = "servlet.request";
@Override
public AgentBuilder instrument(final AgentBuilder agentBuilder) {
return agentBuilder
.type(
not(isInterface()).and(hasSuperType(named("javax.servlet.FilterChain"))),
not(classLoaderHasClasses("javax.servlet.AsyncEvent", "javax.servlet.AsyncListener"))
.and(
classLoaderHasClasses(
"javax.servlet.ServletContextEvent", "javax.servlet.ServletRequest")))
.transform(
new HelperInjector(
"io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter",
"io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter$MultivaluedMapFlatIterator",
"io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator",
"io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator$1",
"io.opentracing.contrib.web.servlet.filter.TracingFilter",
"io.opentracing.contrib.web.servlet.filter.TracingFilter$1"))
.transform(
DDAdvice.create()
.advice(
named("doFilter")
.and(takesArgument(0, named("javax.servlet.ServletRequest")))
.and(takesArgument(1, named("javax.servlet.ServletResponse")))
.and(isPublic()),
FilterChain2Advice.class.getName()))
.asDecorator();
}
public static class FilterChain2Advice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static ActiveSpan startSpan(@Advice.Argument(0) final ServletRequest req) {
if (GlobalTracer.get().activeSpan() != null || !(req instanceof HttpServletRequest)) {
// doFilter is called by each filter. We only want to time outer-most.
return null;
}
final SpanContext extractedContext =
GlobalTracer.get()
.extract(
Format.Builtin.HTTP_HEADERS,
new HttpServletRequestExtractAdapter((HttpServletRequest) req));
final ActiveSpan span =
GlobalTracer.get()
.buildSpan(FILTER_CHAIN_OPERATION_NAME)
.asChildOf(extractedContext)
.withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER)
.startActive();
ServletFilterSpanDecorator.STANDARD_TAGS.onRequest((HttpServletRequest) req, span);
return span;
}
@Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
public static void stopSpan(
@Advice.Argument(0) final ServletRequest request,
@Advice.Argument(1) final ServletResponse response,
@Advice.Enter final ActiveSpan span,
@Advice.Thrown final Throwable throwable) {
if (span != null) {
if (request instanceof HttpServletRequest && response instanceof HttpServletResponse) {
final HttpServletRequest req = (HttpServletRequest) request;
final HttpServletResponse resp = (HttpServletResponse) response;
if (throwable != null) {
ServletFilterSpanDecorator.STANDARD_TAGS.onError(req, resp, throwable, span);
span.log(Collections.singletonMap("error.object", throwable));
} else {
ServletFilterSpanDecorator.STANDARD_TAGS.onResponse(req, resp, span);
}
}
span.deactivate();
}
}
}
}

View File

@ -61,6 +61,10 @@ public final class HttpServlet2Instrumentation implements Instrumenter {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static ActiveSpan startSpan(@Advice.Argument(0) final HttpServletRequest req) {
if (GlobalTracer.get().activeSpan() != null) {
// Tracing might already be applied by the FilterChain. If so ignore this.
return null;
}
final SpanContext extractedContext =
GlobalTracer.get()

View File

@ -0,0 +1,174 @@
package dd.inst.servlet3;
import static dd.trace.ClassLoaderMatcher.classLoaderHasClasses;
import static net.bytebuddy.matcher.ElementMatchers.hasSuperType;
import static net.bytebuddy.matcher.ElementMatchers.isInterface;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.not;
import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
import com.google.auto.service.AutoService;
import dd.trace.DDAdvice;
import dd.trace.HelperInjector;
import dd.trace.Instrumenter;
import io.opentracing.ActiveSpan;
import io.opentracing.SpanContext;
import io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter;
import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;
import io.opentracing.propagation.Format;
import io.opentracing.tag.Tags;
import io.opentracing.util.GlobalTracer;
import java.io.IOException;
import java.util.Collections;
import java.util.concurrent.atomic.AtomicBoolean;
import javax.servlet.AsyncEvent;
import javax.servlet.AsyncListener;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.asm.Advice;
@AutoService(Instrumenter.class)
public final class FilterChain3Instrumentation implements Instrumenter {
public static final String SERVLET_OPERATION_NAME = "servlet.request";
@Override
public AgentBuilder instrument(final AgentBuilder agentBuilder) {
return agentBuilder
.type(
not(isInterface()).and(hasSuperType(named("javax.servlet.FilterChain"))),
classLoaderHasClasses("javax.servlet.AsyncEvent", "javax.servlet.AsyncListener"))
.transform(
new HelperInjector(
"io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter",
"io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter$MultivaluedMapFlatIterator",
"io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator",
"io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator$1",
"io.opentracing.contrib.web.servlet.filter.TracingFilter",
"io.opentracing.contrib.web.servlet.filter.TracingFilter$1"))
.transform(
DDAdvice.create()
.advice(
named("doFilter")
.and(takesArgument(0, named("javax.servlet.ServletRequest")))
.and(takesArgument(1, named("javax.servlet.ServletResponse")))
.and(isPublic()),
HttpServlet3Advice.class.getName()))
.asDecorator();
}
public static class HttpServlet3Advice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static ActiveSpan startSpan(@Advice.Argument(0) final ServletRequest req) {
if (GlobalTracer.get().activeSpan() != null || !(req instanceof HttpServletRequest)) {
// doFilter is called by each filter. We only want to time outer-most.
return null;
}
final SpanContext extractedContext =
GlobalTracer.get()
.extract(
Format.Builtin.HTTP_HEADERS,
new HttpServletRequestExtractAdapter((HttpServletRequest) req));
final ActiveSpan span =
GlobalTracer.get()
.buildSpan(SERVLET_OPERATION_NAME)
.asChildOf(extractedContext)
.withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER)
.startActive();
ServletFilterSpanDecorator.STANDARD_TAGS.onRequest((HttpServletRequest) req, span);
return span;
}
@Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
public static void stopSpan(
@Advice.Argument(0) final ServletRequest request,
@Advice.Argument(1) final ServletResponse response,
@Advice.Enter final ActiveSpan span,
@Advice.Thrown final Throwable throwable) {
if (span != null) {
if (request instanceof HttpServletRequest && response instanceof HttpServletResponse) {
final HttpServletRequest req = (HttpServletRequest) request;
final HttpServletResponse resp = (HttpServletResponse) response;
if (throwable != null) {
ServletFilterSpanDecorator.STANDARD_TAGS.onError(req, resp, throwable, span);
span.log(Collections.singletonMap("error.object", throwable));
} else if (req.isAsyncStarted()) {
final ActiveSpan.Continuation cont = span.capture();
final AtomicBoolean activated = new AtomicBoolean(false);
// what if async is already finished? This would not be called
req.getAsyncContext().addListener(new TagSettingAsyncListener(activated, cont, span));
} else {
ServletFilterSpanDecorator.STANDARD_TAGS.onResponse(req, resp, span);
}
}
span.deactivate();
}
}
public static class TagSettingAsyncListener implements AsyncListener {
private final AtomicBoolean activated;
private final ActiveSpan.Continuation cont;
private final ActiveSpan span;
public TagSettingAsyncListener(
final AtomicBoolean activated,
final ActiveSpan.Continuation cont,
final ActiveSpan span) {
this.activated = activated;
this.cont = cont;
this.span = span;
}
@Override
public void onComplete(final AsyncEvent event) throws IOException {
if (activated.compareAndSet(false, true)) {
try (ActiveSpan activeSpan = cont.activate()) {
ServletFilterSpanDecorator.STANDARD_TAGS.onResponse(
(HttpServletRequest) event.getSuppliedRequest(),
(HttpServletResponse) event.getSuppliedResponse(),
span);
}
}
}
@Override
public void onTimeout(final AsyncEvent event) throws IOException {
if (activated.compareAndSet(false, true)) {
try (ActiveSpan activeSpan = cont.activate()) {
ServletFilterSpanDecorator.STANDARD_TAGS.onTimeout(
(HttpServletRequest) event.getSuppliedRequest(),
(HttpServletResponse) event.getSuppliedResponse(),
event.getAsyncContext().getTimeout(),
span);
}
}
}
@Override
public void onError(final AsyncEvent event) throws IOException {
if (event.getThrowable() != null && activated.compareAndSet(false, true)) {
try (ActiveSpan activeSpan = cont.activate()) {
ServletFilterSpanDecorator.STANDARD_TAGS.onError(
(HttpServletRequest) event.getSuppliedRequest(),
(HttpServletResponse) event.getSuppliedResponse(),
event.getThrowable(),
span);
span.log(Collections.singletonMap("error.object", event.getThrowable()));
}
}
}
@Override
public void onStartAsync(final AsyncEvent event) throws IOException {}
}
}
}

View File

@ -62,6 +62,10 @@ public final class HttpServlet3Instrumentation implements Instrumenter {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static ActiveSpan startSpan(@Advice.Argument(0) final HttpServletRequest req) {
if (GlobalTracer.get().activeSpan() != null) {
// Tracing might already be applied by the FilterChain. If so ignore this.
return null;
}
final SpanContext extractedContext =
GlobalTracer.get()