Http spans #466

iNikem · 2020-06-01T13:05:51Z

This draft/POC PR try to solve too many concerns at once but here it is...

First, it solves #423 by extracting all common functionality of servlet instrumentation into one common place. So far Servlet 2, Servlet 3 and Grizzly were de-duplicated.

Second, that common place mention above is io.opentelemetry.auto.typed.server.http.HttpServerTracer. It together with more specific subclasses aims to provide a single place where all http server instrumentations can use common functionality. It does more than current HttpServerDecorator and exposes smaller API.

Third, it demonstrates rudimental HttpServerSpan. This is an example of semantic span that was a focus of #195, #229 and open-telemetry/opentelemetry-java#964

I tried to follow these guidelines:

Semantic span exposes more specialised API comparing to generic Span, following semantic convention from Otel specification. At the same time, spans still know nothing about the source of the attribute values. E.g. span should know nothing about HttpRequest or URLConnection
Semantic tracer, such as HttpServerTracer knows the "shape" of a specific semantic span, fixed values of some attributes (e.g. SpanKind) and how and from where to extract other values. E.g. server traces know about incoming http requests and responses but delegate to subclasses to deal with specific libraries, such as Servlet or Project Reactor.
Instrumentation (or Advice) know only where to inject calls to the corresponding methods of semantic tracers. They should not know anything about how to compose a span or what rules govern their attributes.

trask

Thanks for tackling this!

I think I'd keep scope a separate (optional) concept to this new API, and have HttpServerTracer return and work directly on HttpServerSpan, and remove HttpServerSpanWithScope.

SpanWithScope is primarily an auto-instrumentation detail to make it easier to pass them both between @OnMethodEnter and @OnMethodExit (in the future we could potentially get rid of it altogether using an extra @Local bytebuddy parameter, reducing memory allocations).

For now, we could add a generic version of SpanWithScope, so we can use e.g. SpanWithScope<HttpServerSpan>, or we could start adding the extra @Local now, migrating away from SpanWithScope altogether.

trask · 2020-06-02T01:58:23Z

agent-tooling/src/main/java/io/opentelemetry/auto/typed/server/http/HttpServerTracer.java

+    return new HttpServerSpanWithScope(span, currentContextWith(span));
+  }
+
+  protected HttpServerSpan findExistingSpan(REQUEST request) {


would be nice for the names of these two methods to reflect that they are opposites, e.g. something like

findExistingSpan --> getSpan(REQUEST)
persistSpanToRequest --> setSpan(REQUEST, HttpServerSpan)

probably even attach/detach. And #465 will change that anyway.

trask · 2020-06-02T02:07:38Z

agent-tooling/src/main/java/io/opentelemetry/auto/typed/server/http/HttpServerTracer.java

+    return throwable instanceof ExecutionException ? throwable.getCause() : throwable;
+  }
+
+  public static <C> SpanContext extract(final C carrier, final HttpTextFormat.Getter<C> getter) {


Suggested change

public static <C> SpanContext extract(final C carrier, final HttpTextFormat.Getter<C> getter) {

private static <C> SpanContext extract(final C carrier, final HttpTextFormat.Getter<C> getter) {

trask · 2020-06-02T02:11:58Z

gradle/instrumentation.gradle

+//tasks.withType(Test) {
+//  forkEvery = 1
+//}


was this just for local testing? i'm not opposed to trying this again, but let's do it in a separate PR

Yes, that is purely for local testing. I decided to post this draft PR as it is for faster feedback instead of taking 2 more days for polishing it

trask · 2020-06-02T02:15:54Z

...in/java/io/opentelemetry/auto/instrumentation/grizzly/GrizzlyHttpHandlerInstrumentation.java


 @AutoService(Instrumenter.class)
 public class GrizzlyHttpHandlerInstrumentation extends Instrumenter.Default {

+  public static final GrizzlyHttpServerTracer TRACER = new GrizzlyHttpServerTracer();


I think putting this here is going to give you muzzle problems, because it will cause GrizzlyHttpHandlerInstrumentation and all of its dependencies (e.g. bytebuddy) to be pulled into the transitive closure of what's needed to run the advice

trask · 2020-06-02T02:29:49Z

agent-tooling/src/main/java/io/opentelemetry/auto/typed/server/http/HttpServerTracer.java

+    spanWithScope.closeScope();
+  }
+
+  public void end(HttpServerSpan span, RESPONSE response) {


We may end up wanting something more general, but for now we are only capturing statusCode, so I think this would simplify things (e.g. removes need ResponseWithStatus)

Suggested change

public void end(HttpServerSpan span, RESPONSE response) {

public void end(HttpServerSpan span, int statusCode) {

trask · 2020-06-02T02:31:50Z

agent-tooling/src/main/java/io/opentelemetry/auto/typed/server/http/HttpServerTracer.java

+      //TODO I think this is wrong.
+      //We must report that response status that was actually sent to end user
+      //We may change span status, but not http_status attribute


I believe the problem here is that if a servlet throws an exception, the servlet container will then set response status to 500, so 500 really is the status code that the user receives.

trask · 2020-06-02T02:35:26Z

agent-tooling/src/main/java/io/opentelemetry/auto/typed/server/http/HttpServerSpan.java

+  //TODO Specification does not recommend using this attribute
+  //See https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/semantic_conventions/http.md#http-server-semantic-conventions


trask · 2020-06-02T02:47:35Z

...mon/src/main/java/io/opentelemetry/auto/instrumentation/servlet/ServletHttpServerTracer.java

+    //TODO why?
+    request.setAttribute("traceId", span.getTraceId().toLowerBase16());
+    request.setAttribute("spanId", span.getSpanId().toLowerBase16());


This is for adding traceId and spanId to access logs, so you can correlate access logs with traces (e.g. https://tomcat.apache.org/tomcat-8.0-doc/config/valve.html#Access_Log_Valve/Attributes).

trask · 2020-06-02T02:53:17Z

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

-        span.setAttribute(Tags.HTTP_STATUS, 500);
-        span.setStatus(Status.UNKNOWN);
+    if (request instanceof HttpServletRequest && response instanceof HttpServletResponse) {
+      TRACER.setPrincipal((HttpServletRequest) request);


You have faithfully translated the existing logic, but I think the existing logic is incorrect here, wdyt?

Suggested change

TRACER.setPrincipal((HttpServletRequest) request);

if (spanWithScope != null) {

TRACER.setPrincipal(spanWithScope.getSpan());

}

Existing logic has a comment "set principal no matter who created the span". If that was the goal, then existing code is correct. But I don't know yet, if the goal was correct.

Yeah, I'm confused by that comment as well, but I don't think that comment is related to that particular logic of not looking at the current span. If you look back in the history:

https://github.com/DataDog/dd-trace-java/blob/00fe40f1fba5c0df65a8af80430feb2a3cba6eea/dd-java-agent/instrumentation/servlet-2/src/main/java/datadog/trace/instrumentation/servlet2/Servlet2Advice.java#L66-L67

that comment existed when it used to apply to the current span at one time.

But then it still should be not spanWithScope but Tracer.getCurrentSpan()

They are the same in this case (the span was just put into scope above, so will be the same span returned by getCurrentSpan)

trask · 2020-06-02T02:55:12Z

...est-3.0/src/main/java/io/opentelemetry/auto/instrumentation/servlet/v3_0/Servlet3Advice.java

    if (request instanceof HttpServletRequest && response instanceof HttpServletResponse) {
-      final HttpServletRequest req = (HttpServletRequest) request;
-      final HttpServletResponse resp = (HttpServletResponse) response;
+      TRACER.setPrincipal((HttpServletRequest) request);


similar to above, wdyt?

Suggested change

TRACER.setPrincipal((HttpServletRequest) request);

TRACER.setPrincipal(spanWithScope.getSpan());

thisthat · 2020-06-02T11:02:40Z

I don't know the requirements for the instrumentation project, but I find strange that no attribute is set before the Span starts. This way, Samplers that want to take a decision on specific attributes (e.g. to only trace a business-critical path) will not work!

iNikem · 2020-06-02T11:05:50Z

You are absolutely correct on this. There is even #388 for that.

iNikem · 2020-06-02T14:28:21Z

instrumentation/servlet/request-2.3/request-2.3.gradle

@@ -24,6 +24,7 @@ testSets {

 dependencies {
  compileOnly group: 'javax.servlet', name: 'servlet-api', version: '2.2'
+  compile(project(':instrumentation:servlet:servlet-common'))


@trask can you advice me? I currently get java.lang.ClassNotFoundException: io.opentelemetry.auto.instrumentation.servlet.ServletHttpServerTracer during smoke tests. How instrumentations can share classes in general? If they can...

I got it :)

trask · 2020-06-15T17:35:45Z

@iNikem can we close this?

iNikem added 5 commits May 26, 2020 12:31

Servlet instrumentations unified

8fef624

Grizzly migrated

6f0c6e7

Merge remote-tracking branch 'upstream/master' into http-spans

5e02f97

Fix tests after merge

83624f9

.

e413de3

iNikem requested review from trask and tylerbenson and removed request for trask June 1, 2020 19:36

trask reviewed Jun 2, 2020

View reviewed changes

iNikem commented Jun 2, 2020

View reviewed changes

iNikem mentioned this pull request Jun 2, 2020

Deduplicate servlets #469

Merged

trask mentioned this pull request Jun 2, 2020

"user.principal" is set on the wrong span #470

Closed

iNikem mentioned this pull request Jun 6, 2020

Migrate grpc instrumentation to InstrumentationTracer/Span #477

Closed

iNikem closed this Jun 15, 2020

iNikem deleted the http-spans branch July 15, 2020 10:44

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Http spans #466

Http spans #466

iNikem commented Jun 1, 2020

trask left a comment

trask Jun 2, 2020

iNikem Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

iNikem Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

iNikem Jun 2, 2020

trask Jun 2, 2020

iNikem Jun 2, 2020

trask Jun 2, 2020

trask Jun 2, 2020

thisthat commented Jun 2, 2020

iNikem commented Jun 2, 2020

iNikem Jun 2, 2020

iNikem Jun 2, 2020

trask commented Jun 15, 2020

	public static <C> SpanContext extract(final C carrier, final HttpTextFormat.Getter<C> getter) {
	private static <C> SpanContext extract(final C carrier, final HttpTextFormat.Getter<C> getter) {

	public void end(HttpServerSpan span, RESPONSE response) {
	public void end(HttpServerSpan span, int statusCode) {

		//TODO Specification does not recommend using this attribute
		//See https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/semantic_conventions/http.md#http-server-semantic-conventions

-      TRACER.setPrincipal((HttpServletRequest) request);
+      if (spanWithScope != null) {
+        TRACER.setPrincipal(spanWithScope.getSpan());
+      }

	TRACER.setPrincipal((HttpServletRequest) request);
	TRACER.setPrincipal(spanWithScope.getSpan());

Http spans #466

Http spans #466

Conversation

iNikem commented Jun 1, 2020

trask left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

thisthat commented Jun 2, 2020

iNikem commented Jun 2, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

trask commented Jun 15, 2020