Change names of servlet based server spans (#428)

* Add documentation describing non-obvious points of Servlet instrumentations

* Change names of servlet based server spans
This commit is contained in:
Nikita Salnikov-Tarnovski 2020-05-25 22:53:12 +03:00 committed by GitHub
parent 49a077065b
commit 6c8cd2e7f2
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
14 changed files with 180 additions and 99 deletions

View File

@ -14,7 +14,6 @@
* limitations under the License.
*/
import com.google.common.io.Files
import io.opentelemetry.auto.bootstrap.instrumentation.decorator.HttpServerDecorator
import io.opentelemetry.auto.instrumentation.api.MoreTags
import io.opentelemetry.auto.instrumentation.api.Tags
import io.opentelemetry.auto.test.AgentTestRunner
@ -34,6 +33,7 @@ import spock.lang.Unroll
import static io.opentelemetry.trace.Span.Kind.SERVER
//TODO should this be HttpServerTest?
class JSPInstrumentationBasicTests extends AgentTestRunner {
static {
@ -106,7 +106,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -168,7 +168,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -227,7 +227,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("POST")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -283,7 +283,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored true
tags {
@ -358,7 +358,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -413,7 +413,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 7) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -508,7 +508,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 2) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored true
tags {
@ -562,7 +562,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
span(0) {
parent()
// serviceName jspWebappContext
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
// FIXME: this is not a great span name for serving static content.
// spanName "GET /$jspWebappContext/$staticFile"
@ -588,7 +588,10 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
staticFile = "common/hello.html"
}
String expectedOperationName(String method) {
return method != null ? "HTTP $method" : HttpServerDecorator.DEFAULT_SPAN_NAME
//Simple class name plus method name of the entry point of the given servlet container.
//"Entry point" here means the first filter or servlet that accepts incoming requests.
//This will serve as a default name of the SERVER span created for this request.
protected String expectedOperationName() {
'ApplicationFilterChain.doFilter'
}
}

View File

@ -14,7 +14,6 @@
* limitations under the License.
*/
import com.google.common.io.Files
import io.opentelemetry.auto.bootstrap.instrumentation.decorator.HttpServerDecorator
import io.opentelemetry.auto.instrumentation.api.MoreTags
import io.opentelemetry.auto.instrumentation.api.Tags
import io.opentelemetry.auto.test.AgentTestRunner
@ -105,7 +104,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 5) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -186,7 +185,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -241,7 +240,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 9) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -359,7 +358,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 7) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -456,7 +455,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 4) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored true
tags {
@ -524,7 +523,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
@ -566,7 +565,10 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
res.close()
}
String expectedOperationName(String method) {
return method != null ? "HTTP $method" : HttpServerDecorator.DEFAULT_SPAN_NAME
//Simple class name plus method name of the entry point of the given servlet container.
//"Entry point" here means the first filter or servlet that accepts incoming requests.
//This will serve as a default name of the SERVER span created for this request.
protected String expectedOperationName() {
'ApplicationFilterChain.doFilter'
}
}

View File

@ -0,0 +1,74 @@
# Instrumentation for Java Servlets
In order to fully understand how java servlet instrumentation work,
let us first take a look at the following stacktrace from Spring PetClinic application.
Unimportant frames are redacted, points of interests are highlighted and discussed below.
<pre>
<b>at org.springframework.samples.petclinic.owner.OwnerController.initCreationForm(OwnerController.java:60)</b>
...
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
<b>at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)</b>
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
<b>at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)</b>
<b>at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)</b>
<b>at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)</b>
<b>at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)</b>
...
<b>at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)</b>
...
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:834)
</pre>
Everything starts when HTTP request processing reaches the first class from Servlet specification.
In the example above this is `ApplicationFilterChain.doFilter(ServletRequest, ServletResponse)` method.
Let us call this first servlet specific method an "entry point".
This is the main target for `Servlet3Instrumentation` and `Servlet2Instrumentation` instrumenters:
`public void javax.servlet.FilterChain#doFilter(ServletRequest, ServletResponse)`
`public void javax.servlet.http.HttpServlet#service(ServletRequest, ServletResponse)`.
For example, Jetty Servlet container does not have default filter chain and in many cases will have
the second method as instrumentation entry point.
These instrumentations are located in two separate submodules `request-3.0` and `request-2.3`, respectively,
because they and corresponding tests depend on different versions of servlet specification.
Next, request passes several other methods from Servlet specification, such as
`protected void javax.servlet.http.HttpServlet#service(HttpServletRequest, HttpServletResponse)` or
`protected void org.springframework.web.servlet.FrameworkServlet#doGet(HttpServletRequest, HttpServletResponse)`.
They are the targets for `HttpServletInstrumentation`.
From the observability point of view nothing of interest usually happens inside these methods.
Thus it usually does not make sense to create spans from them, as they would only add useless noise.
For this reason `HttpServletInstrumentation` is disabled by default.
In rare cases when you need it, you can enable it using configuration property `ota.integration.servlet-service.enabled`.
In exactly the same situation are all other Servlet filters beyond the initial entry point.
Usually unimportant, they may be sometimes of interest during troubleshooting.
They are instrumented by `FilterInstrumentation` which is too disabled by default.
You can enable it with the configuration property `ota.integration.servlet-filter.enabled`.
At last, request processing may reach the specific framework that you application uses.
In this case Spring MVC and `OwnerController.initCreationForm`.
If all instrumentations are enabled, then a new span will be created for every highlighted frame.
All spans from Servlet API will have `kind=SERVER` and name based on corresponding class ana method names,
such as `ApplicationFilterChain.doFilter` or `FrameworkServlet.doGet`.
Span created by Spring MVC instrumentation will have `kind=INTERNAL` and named `OwnerController.initCreationForm`.
The state described above has one significant problem.
Observability backends usually aggregate traces based on their root spans.
This means that ALL traces from any application deployed to Servlet container will be grouped together.
Becaue their root spans will all have the same named based on common entry point.
In order to alleviate this problem, instrumentations for specific frameworks, such as Spring MVC here,
_update_ name of the span corresponding to the entry point.
Each framework instrumentation can decide what is the best span name based on framework implementation details.
Of course, still adhering to OpenTelemetry
[semantic conventions](https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/semantic_conventions/http.md).

View File

@ -36,10 +36,6 @@ import static io.opentelemetry.trace.Span.Kind.SERVER
// TODO: Figure out a better way to test with OSGi included.
class GlassFishServerTest extends HttpServerTest<GlassFish> {
// static {
// System.setProperty("ota.integration.grizzly.enabled", "true")
// }
@Override
URI buildAddress() {
return new URI("http://localhost:$port/$context/")
@ -88,7 +84,7 @@ class GlassFishServerTest extends HttpServerTest<GlassFish> {
@Override
void serverSpan(TraceAssert trace, int index, String traceID = null, String parentID = null, String method = "GET", ServerEndpoint endpoint = SUCCESS) {
trace.span(index) {
operationName expectedOperationName(method)
operationName entryPointName()
spanKind SERVER
errored endpoint.errored
if (parentID != null) {
@ -117,5 +113,12 @@ class GlassFishServerTest extends HttpServerTest<GlassFish> {
}
}
}
//Simple class name plus method name of the entry point of the given servlet container.
//"Entry point" here means the first filter or servlet that accepts incoming requests.
//This will serve as a default name of the SERVER span created for this request.
protected String entryPointName() {
'HttpServlet.service'
}
}

View File

@ -29,31 +29,35 @@ import io.opentelemetry.auto.instrumentation.api.SpanWithScope;
import io.opentelemetry.auto.instrumentation.api.Tags;
import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Status;
import java.lang.reflect.Method;
import java.security.Principal;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.implementation.bytecode.assign.Assigner;
public class Servlet2Advice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static SpanWithScope onEnter(
@Advice.This final Object servlet,
@Advice.Origin final Method method,
@Advice.Argument(0) final ServletRequest request,
@Advice.Argument(value = 1, typing = Assigner.Typing.DYNAMIC)
final ServletResponse response) {
@Advice.Argument(1) final ServletResponse response) {
if (!(request instanceof HttpServletRequest)) {
return null;
}
final boolean hasServletTrace = request.getAttribute(SPAN_ATTRIBUTE) instanceof Span;
final boolean invalidRequest = !(request instanceof HttpServletRequest);
if (invalidRequest || hasServletTrace) {
if (hasServletTrace) {
// Tracing might already be applied by the FilterChain or a parent request (forward/include).
return null;
}
final HttpServletRequest httpServletRequest = (HttpServletRequest) request;
// TODO this logic should be moved to Servlet2 specific Decorator
if (response instanceof HttpServletResponse) {
// For use by HttpServletResponseInstrumentation:
InstrumentationContext.get(HttpServletResponse.class, HttpServletRequest.class)
@ -64,9 +68,8 @@ public class Servlet2Advice {
}
final Span.Builder builder =
TRACER.spanBuilder(DECORATE.spanNameForRequest(httpServletRequest)).setSpanKind(SERVER);
TRACER.spanBuilder(DECORATE.spanNameForMethod(method)).setSpanKind(SERVER);
builder.setParent(extract(httpServletRequest, GETTER));
final Span span =
builder.setAttribute("span.origin.type", servlet.getClass().getName()).startSpan();
@ -99,6 +102,7 @@ public class Servlet2Advice {
if (spanWithScope == null) {
return;
}
final Span span = spanWithScope.getSpan();
if (response instanceof HttpServletResponse) {

View File

@ -1,28 +0,0 @@
/*
* Copyright The OpenTelemetry Authors
*
* Licensed under 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 KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.servlet.v2_3;
import io.opentelemetry.auto.bootstrap.InstrumentationContext;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletResponse;
import net.bytebuddy.asm.Advice;
public class Servlet2ResponseRedirectAdvice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void onEnter(@Advice.This final HttpServletResponse response) {
InstrumentationContext.get(ServletResponse.class, Integer.class).put(response, 302);
}
}

View File

@ -1,29 +0,0 @@
/*
* Copyright The OpenTelemetry Authors
*
* Licensed under 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 KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.servlet.v2_3;
import io.opentelemetry.auto.bootstrap.InstrumentationContext;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletResponse;
import net.bytebuddy.asm.Advice;
public class Servlet2ResponseStatusAdvice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void onEnter(
@Advice.This final HttpServletResponse response, @Advice.Argument(0) final Integer status) {
InstrumentationContext.get(ServletResponse.class, Integer.class).put(response, status);
}
}

View File

@ -22,13 +22,30 @@ import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.not;
import com.google.auto.service.AutoService;
import io.opentelemetry.auto.bootstrap.InstrumentationContext;
import io.opentelemetry.auto.instrumentation.api.SpanWithScope;
import io.opentelemetry.auto.tooling.Instrumenter;
import java.util.HashMap;
import java.util.Map;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletResponse;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.description.method.MethodDescription;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
/**
* Class <code>javax.servlet.http.HttpServletResponse</code> got method <code>getStatus</code> only
* in Servlet specification version 3.0. This means that we cannot set {@link
* io.opentelemetry.auto.instrumentation.api.Tags#HTTP_STATUS} attribute on the created span using
* just response object.
*
* <p>This instrumentation intercepts status setting methods from Servlet 2.0 specification and
* stores that status into context store. Then {@link Servlet2Advice#stopSpan(ServletRequest,
* ServletResponse, SpanWithScope, Throwable)} can get it from context and set required span
* attribute.
*/
@AutoService(Instrumenter.class)
public final class Servlet2ResponseStatusInstrumentation extends Instrumenter.Default {
public Servlet2ResponseStatusInstrumentation() {
@ -51,16 +68,27 @@ public final class Servlet2ResponseStatusInstrumentation extends Instrumenter.De
return singletonMap("javax.servlet.ServletResponse", Integer.class.getName());
}
/**
* Unlike Servlet2Instrumentation it doesn't matter if the HttpServletResponseInstrumentation
* applies first
*/
@Override
public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
final Map<ElementMatcher<? super MethodDescription>, String> transformers = new HashMap<>();
transformers.put(
named("sendError").or(named("setStatus")), packageName + ".Servlet2ResponseStatusAdvice");
transformers.put(named("sendRedirect"), packageName + ".Servlet2ResponseRedirectAdvice");
named("sendError").or(named("setStatus")), Servlet2ResponseStatusAdvice.class.getName());
transformers.put(named("sendRedirect"), Servlet2ResponseRedirectAdvice.class.getName());
return transformers;
}
public static class Servlet2ResponseRedirectAdvice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void onEnter(@Advice.This final HttpServletResponse response) {
InstrumentationContext.get(ServletResponse.class, Integer.class).put(response, 302);
}
}
public static class Servlet2ResponseStatusAdvice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void onEnter(
@Advice.This final HttpServletResponse response, @Advice.Argument(0) final Integer status) {
InstrumentationContext.get(ServletResponse.class, Integer.class).put(response, status);
}
}
}

View File

@ -85,7 +85,7 @@ class JettyServlet2Test extends HttpServerTest<Server> {
// parent span must be cast otherwise it breaks debugging classloading (junit loads it early)
void serverSpan(TraceAssert trace, int index, String traceID = null, String parentID = null, String method = "GET", ServerEndpoint endpoint = SUCCESS) {
trace.span(index) {
operationName expectedOperationName(method)
operationName 'HttpServlet.service'
spanKind SERVER
errored endpoint.errored
if (parentID != null) {

View File

@ -29,6 +29,7 @@ import io.opentelemetry.auto.instrumentation.api.SpanWithScope;
import io.opentelemetry.auto.instrumentation.api.Tags;
import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Status;
import java.lang.reflect.Method;
import java.security.Principal;
import java.util.concurrent.atomic.AtomicBoolean;
import javax.servlet.ServletRequest;
@ -42,6 +43,7 @@ public class Servlet3Advice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static SpanWithScope onEnter(
@Advice.This final Object servlet,
@Advice.Origin final Method method,
@Advice.Argument(0) final ServletRequest request,
@Advice.Argument(1) final ServletResponse response) {
if (!(request instanceof HttpServletRequest)) {
@ -75,7 +77,7 @@ public class Servlet3Advice {
.put((HttpServletResponse) response, httpServletRequest);
final Span.Builder builder =
TRACER.spanBuilder(DECORATE.spanNameForRequest(httpServletRequest)).setSpanKind(SERVER);
TRACER.spanBuilder(DECORATE.spanNameForMethod(method)).setSpanKind(SERVER);
builder.setParent(extract(httpServletRequest, GETTER));
final Span span =
builder.setAttribute("span.origin.type", servlet.getClass().getName()).startSpan();

View File

@ -71,7 +71,7 @@ abstract class AbstractServlet3Test<SERVER, CONTEXT> extends HttpServerTest<SERV
@Override
void serverSpan(TraceAssert trace, int index, String traceID = null, String parentID = null, String method = "GET", ServerEndpoint endpoint = SUCCESS) {
trace.span(index) {
operationName expectedOperationName(method)
operationName entryPointName()
spanKind Span.Kind.SERVER // can't use static import because of SERVER type parameter
errored endpoint.errored
if (parentID != null) {
@ -102,4 +102,11 @@ abstract class AbstractServlet3Test<SERVER, CONTEXT> extends HttpServerTest<SERV
}
}
}
//Simple class name plus method name of the entry point of the given servlet container.
//"Entry point" here means the first filter or servlet that accepts incoming requests.
//This will serve as a default name of the SERVER span created for this request.
protected String entryPointName() {
'HttpServlet.service'
}
}

View File

@ -95,6 +95,11 @@ abstract class TomcatServlet3Test extends AbstractServlet3Test<Tomcat, Context>
return "tomcat-context"
}
@Override
protected String entryPointName() {
return 'ApplicationFilterChain.doFilter'
}
@Override
void addServlet(Context servletContext, String path, Class<Servlet> servlet) {
String name = UUID.randomUUID()

View File

@ -36,6 +36,11 @@ import net.bytebuddy.description.method.MethodDescription;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
/**
* Instruments all filter invocations in filter chain.
*
* <p>See README.md for more information about different servlet instrumentations.
*/
@AutoService(Instrumenter.class)
public final class FilterInstrumentation extends Instrumenter.Default {
public FilterInstrumentation() {

View File

@ -31,6 +31,7 @@ import com.google.auto.service.AutoService;
import io.opentelemetry.auto.instrumentation.api.SpanWithScope;
import io.opentelemetry.auto.tooling.Instrumenter;
import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Span.Kind;
import java.lang.reflect.Method;
import java.util.Map;
import net.bytebuddy.asm.Advice;
@ -38,6 +39,7 @@ import net.bytebuddy.description.method.MethodDescription;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
// Please read README.md of this subproject to understand what is this instrumentation.
@AutoService(Instrumenter.class)
public final class HttpServletInstrumentation extends Instrumenter.Default {
public HttpServletInstrumentation() {
@ -93,7 +95,10 @@ public final class HttpServletInstrumentation extends Instrumenter.Default {
}
// Here we use the Method instead of "this.class.name" to distinguish calls to "super".
final Span span = TRACER.spanBuilder(DECORATE.spanNameForMethod(method)).startSpan();
final Span span =
TRACER
.spanBuilder(DECORATE.spanNameForMethod(method))
.startSpan();
DECORATE.afterStart(span);
return new SpanWithScope(span, currentContextWith(span));