Merge pull request #425 from DataDog/tyler/httpurlconnection

Separate span for input and output streams.
This commit is contained in:
Tyler Benson 2018-08-07 12:33:26 +10:00 committed by GitHub
commit 9d8548406b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
7 changed files with 276 additions and 114 deletions

View File

@ -57,7 +57,12 @@ public class AgentInstaller {
.or(named("java.net.HttpURLConnection"))
.or(nameStartsWith("java.util.concurrent.")))))
.or(nameStartsWith("com.sun."))
.or(nameStartsWith("sun.").and(not(nameStartsWith("sun.net.www.protocol."))))
.or(
nameStartsWith("sun.")
.and(
not(
nameStartsWith("sun.net.www.protocol.")
.or(named("sun.net.www.http.HttpClient")))))
.or(nameStartsWith("jdk."))
.or(nameStartsWith("org.aspectj."))
.or(nameStartsWith("org.groovy."))

View File

@ -4,7 +4,6 @@ import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperT
import static io.opentracing.log.Fields.ERROR_OBJECT;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
import static net.bytebuddy.matcher.ElementMatchers.nameStartsWith;
import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.not;
@ -16,13 +15,11 @@ import datadog.trace.bootstrap.CallDepthThreadLocalMap;
import io.opentracing.Scope;
import io.opentracing.Span;
import io.opentracing.Tracer;
import io.opentracing.propagation.Format;
import io.opentracing.tag.Tags;
import io.opentracing.util.GlobalTracer;
import java.net.HttpURLConnection;
import java.net.URL;
import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import java.util.WeakHashMap;
import javax.net.ssl.HttpsURLConnection;
@ -50,26 +47,16 @@ public class HttpUrlConnectionInstrumentation extends Instrumenter.Default {
@Override
public String[] helperClassNames() {
return new String[] {
"datadog.trace.instrumentation.http_url_connection.MessageHeadersInjectAdapter",
HttpUrlConnectionInstrumentation.class.getName() + "$HttpURLState"
};
return new String[] {HttpUrlConnectionInstrumentation.class.getName() + "$HttpURLState"};
}
@Override
public Map<ElementMatcher, String> transformers() {
final Map<ElementMatcher, String> transformers = new HashMap<>();
transformers.put(
return Collections.<ElementMatcher, String>singletonMap(
isMethod()
.and(isPublic())
.and(
named("getResponseCode")
.or(named("connect"))
.or(named("getOutputStream"))
.or(named("getInputStream"))
.or(nameStartsWith("getHeaderField"))),
.and(named("connect").or(named("getOutputStream")).or(named("getInputStream"))),
HttpUrlConnectionAdvice.class.getName());
return transformers;
}
public static class HttpUrlConnectionAdvice {
@ -82,28 +69,42 @@ public class HttpUrlConnectionInstrumentation extends Instrumenter.Default {
final HttpURLState state = HttpURLState.get(thiz);
String operationName = "http.request";
if ("connect".equals(methodName)) {
if (connected) {
return null;
}
// We get here in cases where connect() is called first.
// We need to inject headers now because after connected=true no more headers can be added.
// In total there will be two spans:
// - one for the connect() which does propagation
// - one for the input or output stream (presumably called after connect())
operationName += ".connect";
} else {
if (state.hasDoneIO()) {
return null;
}
state.setHasDoneIO(true);
switch (methodName) {
case "connect":
if (connected) {
return null;
}
/*
* Ideally, we would like to only have a single span for each of the output and input streams,
* but since headers are also sent on connect(), there wouldn't be a span to mark as parent if
* we don't create a span here.
*/
operationName += ".connect";
break;
case "getOutputStream":
if (state.calledOutputStream) {
return null;
}
state.calledOutputStream = true;
operationName += ".output-stream";
break;
case "getInputStream":
if (state.calledInputStream) {
return null;
}
state.calledInputStream = true;
operationName += ".input-stream";
break;
}
// AgentWriter uses HttpURLConnection to report to the trace-agent. We don't want to trace
// those requests.
// Check after the connected test above because getRequestProperty will throw an exception if
// already connected.
/*
* AgentWriter uses HttpURLConnection to report to the trace-agent. We don't want to trace
* those requests. Check after the connected test above because getRequestProperty will
* throw an exception if already connected.
*/
final boolean isTraceRequest =
Thread.currentThread().getName().equals("dd-agent-writer")
|| (!connected && thiz.getRequestProperty("Datadog-Meta-Lang") != null);
@ -113,7 +114,7 @@ public class HttpUrlConnectionInstrumentation extends Instrumenter.Default {
final Tracer tracer = GlobalTracer.get();
if (tracer.activeSpan() == null) {
// httpurlconnection doesn't play nicely with top-level spans
// We don't want this as a top level span.
return null;
}
@ -143,8 +144,6 @@ public class HttpUrlConnectionInstrumentation extends Instrumenter.Default {
}
Tags.HTTP_METHOD.set(span, thiz.getRequestMethod());
tracer.inject(
span.context(), Format.Builtin.HTTP_HEADERS, new MessageHeadersInjectAdapter(thiz));
return scope;
}
@ -163,9 +162,11 @@ public class HttpUrlConnectionInstrumentation extends Instrumenter.Default {
Tags.ERROR.set(span, true);
span.log(Collections.singletonMap(ERROR_OBJECT, throwable));
} else if (responseCode > 0) {
// responseCode field cache is sometimes not populated.
// We can't call getResponseCode() due to some unwanted side-effects (e.g. breaks
// getOutputStream).
/*
* responseCode field cache is sometimes not populated.
* We can't call getResponseCode() due to some unwanted side-effects
* (e.g. breaks getOutputStream).
*/
Tags.HTTP_STATUS.set(span, responseCode);
}
scope.close();
@ -180,23 +181,21 @@ public class HttpUrlConnectionInstrumentation extends Instrumenter.Default {
public static HttpURLState get(final HttpURLConnection connection) {
HttpURLState state = STATE_MAP.get(connection);
if (state == null) {
// not thread-safe, but neither is HttpURLConnection
state = new HttpURLState();
STATE_MAP.put(connection, state);
synchronized (connection) {
// might not be a good idea to synchronize on a method parameter...
state = STATE_MAP.get(connection);
if (state == null) {
state = new HttpURLState();
STATE_MAP.put(connection, state);
}
}
}
return state;
}
public boolean hasDoneIO = false;
public boolean calledOutputStream = false;
public boolean calledInputStream = false;
private HttpURLState() {}
public boolean hasDoneIO() {
return hasDoneIO;
}
public void setHasDoneIO(final boolean value) {
hasDoneIO = value;
}
}
}

View File

@ -1,31 +0,0 @@
package datadog.trace.instrumentation.http_url_connection;
import io.opentracing.propagation.TextMap;
import java.net.HttpURLConnection;
import java.util.Iterator;
import java.util.Map;
public class MessageHeadersInjectAdapter implements TextMap {
private final HttpURLConnection connection;
public MessageHeadersInjectAdapter(final HttpURLConnection connection) {
this.connection = connection;
}
@Override
public void put(final String key, final String value) {
try {
if (connection.getRequestProperty(key) == null) {
connection.setRequestProperty(key, value);
}
} catch (final IllegalStateException e) {
// Connection is already established. Too late to set headers.
}
}
@Override
public Iterator<Map.Entry<String, String>> iterator() {
throw new UnsupportedOperationException("This class should be used only with tracer#inject()");
}
}

View File

@ -0,0 +1,94 @@
package datadog.trace.instrumentation.http_url_connection;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
import com.google.auto.service.AutoService;
import datadog.trace.agent.tooling.Instrumenter;
import io.opentracing.Span;
import io.opentracing.Tracer;
import io.opentracing.propagation.Format;
import io.opentracing.propagation.TextMap;
import io.opentracing.util.GlobalTracer;
import java.util.Collections;
import java.util.Iterator;
import java.util.Map;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.matcher.ElementMatcher;
import sun.net.www.MessageHeader;
import sun.net.www.http.HttpClient;
@AutoService(Instrumenter.class)
public class SunHttpClientInstrumentation extends Instrumenter.Default {
public SunHttpClientInstrumentation() {
super("httpurlconnection");
}
@Override
protected boolean defaultEnabled() {
return false;
}
@Override
public ElementMatcher typeMatcher() {
return named("sun.net.www.http.HttpClient");
}
@Override
public String[] helperClassNames() {
return new String[] {
SunHttpClientInstrumentation.class.getName() + "$MessageHeadersInjectAdapter"
};
}
@Override
public Map<ElementMatcher, String> transformers() {
return Collections.<ElementMatcher, String>singletonMap(
isMethod()
.and(isPublic())
.and(named("writeRequests"))
.and(takesArgument(0, named("sun.net.www.MessageHeader")))
// exclude the delegating method:
.and(takesArguments(1).or(takesArguments(2))),
InjectAdvice.class.getName());
}
public static class InjectAdvice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void inject(
@Advice.Argument(0) final MessageHeader header, @Advice.This final HttpClient client) {
final Tracer tracer = GlobalTracer.get();
final Span span = tracer.activeSpan();
if (span != null) {
tracer.inject(
span.context(), Format.Builtin.HTTP_HEADERS, new MessageHeadersInjectAdapter(header));
}
}
}
public static class MessageHeadersInjectAdapter implements TextMap {
private final MessageHeader header;
public MessageHeadersInjectAdapter(final MessageHeader header) {
this.header = header;
}
@Override
public void put(final String key, final String value) {
header.setIfNotSet(key, value);
}
@Override
public Iterator<Map.Entry<String, String>> iterator() {
throw new UnsupportedOperationException(
"This class should be used only with tracer#inject()");
}
}
}

View File

@ -29,14 +29,19 @@ class HttpUrlConnectionTest extends AgentTestRunner {
all {
RatpackUtils.handleDistributedRequest(context)
response.status(STATUS)
// Ratpack seems to be sending body with HEAD requests - RFC specifically forbids this.
// This becomes a major problem with keep-alived requests - client seems to fail to parse
// such response properly messing up following requests.
if (request.method.isHead()) {
response.send()
} else {
response.send(RESPONSE)
request.body.then {
if (it != null) {
println "RECEIVED: $it.text"
}
response.status(STATUS)
// Ratpack seems to be sending body with HEAD requests - RFC specifically forbids this.
// This becomes a major problem with keep-alived requests - client seems to fail to parse
// such response properly messing up following requests.
if (request.method.isHead()) {
response.send()
} else {
response.send(RESPONSE)
}
}
}
}
@ -46,6 +51,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
setup:
runUnderTrace("someTrace") {
HttpURLConnection connection = server.address.toURL().openConnection()
connection.useCaches = useCaches
assert GlobalTracer.get().scopeManager().active() != null
def stream = connection.inputStream
def lines = stream.readLines()
@ -55,9 +61,11 @@ class HttpUrlConnectionTest extends AgentTestRunner {
// call again to ensure the cycling is ok
connection = server.getAddress().toURL().openConnection()
connection.useCaches = useCaches
assert GlobalTracer.get().scopeManager().active() != null
assert connection.getResponseCode() == STATUS // call before input stream to test alternate behavior
stream = connection.inputStream
connection.inputStream
stream = connection.inputStream // one more to ensure state is working
lines = stream.readLines()
stream.close()
assert lines == [RESPONSE]
@ -95,7 +103,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(1) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
@ -111,7 +119,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(2) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
@ -128,15 +136,20 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
}
where:
useCaches << [false, true]
}
def "trace request without propagation"() {
setup:
runUnderTrace("someTrace") {
HttpURLConnection connection = server.address.toURL().openConnection()
connection.useCaches = useCaches
connection.addRequestProperty("is-dd-server", "false")
assert GlobalTracer.get().scopeManager().active() != null
def stream = connection.inputStream
connection.inputStream // one more to ensure state is working
def lines = stream.readLines()
stream.close()
assert connection.getResponseCode() == STATUS
@ -144,6 +157,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
// call again to ensure the cycling is ok
connection = server.getAddress().toURL().openConnection()
connection.useCaches = useCaches
connection.addRequestProperty("is-dd-server", "false")
assert GlobalTracer.get().scopeManager().active() != null
assert connection.getResponseCode() == STATUS // call before input stream to test alternate behavior
@ -165,7 +179,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(1) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
@ -181,7 +195,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(2) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
@ -198,6 +212,9 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
}
where:
useCaches << [false, true]
}
def "test response code"() {
@ -222,7 +239,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(1) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
@ -241,6 +258,54 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
def "test broken API usage"() {
setup:
HttpURLConnection conn = runUnderTrace("someTrace") {
HttpURLConnection connection = server.address.toURL().openConnection()
connection.setRequestProperty("Connection", "close")
connection.addRequestProperty("is-dd-server", "false")
assert GlobalTracer.get().scopeManager().active() != null
assert connection.getResponseCode() == STATUS
return connection
}
expect:
assertTraces(TEST_WRITER, 1) {
trace(0, 2) {
span(0) {
operationName "someTrace"
parent()
errored false
tags {
defaultTags()
}
}
span(1) {
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
"$Tags.COMPONENT.key" "HttpURLConnection"
"$Tags.SPAN_KIND.key" Tags.SPAN_KIND_CLIENT
"$DDTags.SPAN_TYPE" DDSpanTypes.HTTP_CLIENT
"$Tags.HTTP_URL.key" "$server.address"
"$Tags.HTTP_METHOD.key" "GET"
"$Tags.HTTP_STATUS.key" STATUS
"$Tags.PEER_HOSTNAME.key" "localhost"
"$Tags.PEER_PORT.key" server.address.port
defaultTags()
}
}
}
}
cleanup:
conn.disconnect()
where:
iteration << (1..10)
}
def "test post request"() {
setup:
runUnderTrace("someTrace") {
@ -276,7 +341,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
}
trace(1, 2) {
trace(1, 3) {
span(0) {
operationName "someTrace"
parent()
@ -286,7 +351,23 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(1) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
"$Tags.COMPONENT.key" "HttpURLConnection"
"$Tags.SPAN_KIND.key" Tags.SPAN_KIND_CLIENT
"$DDTags.SPAN_TYPE" DDSpanTypes.HTTP_CLIENT
"$Tags.HTTP_URL.key" "$server.address"
"$Tags.HTTP_METHOD.key" "POST"
"$Tags.HTTP_STATUS.key" STATUS
"$Tags.PEER_HOSTNAME.key" "localhost"
"$Tags.PEER_PORT.key" server.address.port
defaultTags()
}
}
span(2) {
operationName "http.request.output-stream"
childOf span(0)
errored false
tags {
@ -350,7 +431,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
setup:
runUnderTrace("someTrace") {
RestTemplate restTemplate = new RestTemplate()
String res = restTemplate.getForObject(server.address.toString(), String)
String res = restTemplate.postForObject(server.address.toString(), "Hello", String)
assert res == RESPONSE
}
@ -366,7 +447,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
}
trace(1, 3) {
trace(1, 4) {
span(0) {
operationName "someTrace"
parent()
@ -376,7 +457,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(1) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored false
tags {
@ -384,7 +465,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
"$Tags.SPAN_KIND.key" Tags.SPAN_KIND_CLIENT
"$DDTags.SPAN_TYPE" DDSpanTypes.HTTP_CLIENT
"$Tags.HTTP_URL.key" "$server.address"
"$Tags.HTTP_METHOD.key" "GET"
"$Tags.HTTP_METHOD.key" "POST"
"$Tags.HTTP_STATUS.key" STATUS
"$Tags.PEER_HOSTNAME.key" "localhost"
"$Tags.PEER_PORT.key" server.address.port
@ -392,6 +473,21 @@ class HttpUrlConnectionTest extends AgentTestRunner {
}
}
span(2) {
operationName "http.request.output-stream"
childOf span(0)
errored false
tags {
"$Tags.COMPONENT.key" "HttpURLConnection"
"$Tags.SPAN_KIND.key" Tags.SPAN_KIND_CLIENT
"$DDTags.SPAN_TYPE" DDSpanTypes.HTTP_CLIENT
"$Tags.HTTP_URL.key" "$server.address"
"$Tags.HTTP_METHOD.key" "POST"
"$Tags.PEER_HOSTNAME.key" "localhost"
"$Tags.PEER_PORT.key" server.address.port
defaultTags()
}
}
span(3) {
operationName "http.request.connect"
childOf span(0)
errored false
@ -400,7 +496,7 @@ class HttpUrlConnectionTest extends AgentTestRunner {
"$Tags.SPAN_KIND.key" Tags.SPAN_KIND_CLIENT
"$DDTags.SPAN_TYPE" DDSpanTypes.HTTP_CLIENT
"$Tags.HTTP_URL.key" "$server.address"
"$Tags.HTTP_METHOD.key" "GET"
"$Tags.HTTP_METHOD.key" "POST"
"$Tags.PEER_HOSTNAME.key" "localhost"
"$Tags.PEER_PORT.key" server.address.port
defaultTags()

View File

@ -41,7 +41,7 @@ class UrlConnectionTest extends AgentTestRunner {
}
}
span(1) {
operationName "http.request"
operationName "http.request.input-stream"
childOf span(0)
errored true
tags {

View File

@ -1,6 +1,5 @@
package datadog.trace.agent.test
import io.opentracing.Scope
import io.opentracing.SpanContext
import io.opentracing.propagation.Format
import io.opentracing.propagation.TextMap
@ -18,12 +17,12 @@ class RatpackUtils {
final SpanContext extractedContext =
GlobalTracer.get()
.extract(Format.Builtin.HTTP_HEADERS, new RatpackResponseAdapter(context))
Scope scope =
GlobalTracer.get()
.buildSpan("test-http-server")
.asChildOf(extractedContext)
.startActive(true)
scope.close()
def builder = GlobalTracer.get()
.buildSpan("test-http-server")
if (extractedContext != null) {
builder.asChildOf(extractedContext)
}
builder.start().finish()
}
}