Change names of servlet based server spans (#428)

* Add documentation describing non-obvious points of Servlet instrumentations

* Change names of servlet based server spans

instrumentation/jsp-2.3/src/test/groovy/JSPInstrumentationBasicTests.groovy

@@ -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'
   }
 }

instrumentation/jsp-2.3/src/test/groovy/JSPInstrumentationForwardTests.groovy

@@ -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'
   }
 }

instrumentation/servlet/README.md

@@ -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).

instrumentation/servlet/glassfish-testing/src/test/groovy/GlassFishServerTest.groovy

@@ -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'
+  }
 }
 

instrumentation/servlet/request-2.3/src/main/java/io/opentelemetry/auto/instrumentation/servlet/v2_3/Servlet2Advice.java

@@ -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)
@@ -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();
 
@@ -99,6 +102,7 @@ public static void stopSpan(
     if (spanWithScope == null) {
       return;
     }
+
     final Span span = spanWithScope.getSpan();
 
     if (response instanceof HttpServletResponse) {