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.

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

Change names of servlet based server spans #428

Merged
merged 5 commits into from
May 25, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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 {
Expand Down Expand Up @@ -106,7 +106,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -168,7 +168,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -227,7 +227,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("POST")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -283,7 +283,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored true
tags {
Expand Down Expand Up @@ -358,7 +358,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -413,7 +413,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 7) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -508,7 +508,7 @@ class JSPInstrumentationBasicTests extends AgentTestRunner {
trace(0, 2) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored true
tags {
Expand Down Expand Up @@ -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"
Expand All @@ -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'
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -105,7 +104,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 5) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -186,7 +185,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -241,7 +240,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 9) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -359,7 +358,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 7) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -456,7 +455,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 4) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored true
tags {
Expand Down Expand Up @@ -524,7 +523,7 @@ class JSPInstrumentationForwardTests extends AgentTestRunner {
trace(0, 3) {
span(0) {
parent()
operationName expectedOperationName("GET")
operationName expectedOperationName()
spanKind SERVER
errored false
tags {
Expand Down Expand Up @@ -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'
}
}
74 changes: 74 additions & 0 deletions instrumentation/servlet/README.md
Original file line number Diff line number Diff line change
@@ -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).
Original file line number Diff line number Diff line change
Expand Up @@ -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/")
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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'
}
}

Original file line number Diff line number Diff line change
Expand Up @@ -29,31 +29,35 @@
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)
Expand All @@ -64,9 +68,8 @@ public static SpanWithScope onEnter(
}

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

Expand Down Expand Up @@ -99,6 +102,7 @@ public static void stopSpan(
if (spanWithScope == null) {
return;
}

final Span span = spanWithScope.getSpan();

if (response instanceof HttpServletResponse) {
Expand Down

This file was deleted.

Loading