diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java b/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java index 502a28a263..1380b2753c 100644 --- a/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java +++ b/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java @@ -1,8 +1,5 @@ package datadog.opentracing; -import static io.opentracing.log.Fields.ERROR_OBJECT; -import static io.opentracing.log.Fields.MESSAGE; - import datadog.trace.api.DDTags; import datadog.trace.api.interceptor.MutableSpan; import datadog.trace.api.sampling.PrioritySampling; @@ -50,6 +47,9 @@ public class DDSpan implements Span, MutableSpan { */ private final AtomicLong durationNano = new AtomicLong(); + /** Delegates to for handling the logs if present. */ + private final LogHandler logHandler; + /** Implementation detail. Stores the weak reference to this span. Used by TraceCollection. */ volatile WeakReference ref; @@ -60,7 +60,19 @@ public class DDSpan implements Span, MutableSpan { * @param context the context used for the span */ DDSpan(final long timestampMicro, final DDSpanContext context) { + this(timestampMicro, context, new DefaultLogHandler()); + } + + /** + * Spans should be constructed using the builder, not by calling the constructor directly. + * + * @param timestampMicro if greater than zero, use this time instead of the current time + * @param context the context used for the span + * @param logHandler as the handler where to delegate the log actions + */ + DDSpan(final long timestampMicro, final DDSpanContext context, final LogHandler logHandler) { this.context = context; + this.logHandler = logHandler; if (timestampMicro <= 0L) { // record the start time @@ -143,18 +155,6 @@ public class DDSpan implements Span, MutableSpan { setTag(DDTags.ERROR_STACK, errorString.toString()); } - private boolean extractError(final Map map) { - if (map.get(ERROR_OBJECT) instanceof Throwable) { - final Throwable error = (Throwable) map.get(ERROR_OBJECT); - setErrorMeta(error); - return true; - } else if (map.get(MESSAGE) instanceof String) { - setTag(DDTags.ERROR_MSG, (String) map.get(MESSAGE)); - return true; - } - return false; - } - /* (non-Javadoc) * @see io.opentracing.BaseSpan#setTag(java.lang.String, java.lang.String) */ @@ -227,9 +227,7 @@ public class DDSpan implements Span, MutableSpan { */ @Override public final DDSpan log(final Map map) { - if (!extractError(map)) { - log.debug("`log` method is not implemented. Doing nothing"); - } + logHandler.log(map, this); return this; } @@ -238,9 +236,7 @@ public class DDSpan implements Span, MutableSpan { */ @Override public final DDSpan log(final long l, final Map map) { - if (!extractError(map)) { - log.debug("`log` method is not implemented. Doing nothing"); - } + logHandler.log(l, map, this); return this; } @@ -249,7 +245,7 @@ public class DDSpan implements Span, MutableSpan { */ @Override public final DDSpan log(final String s) { - log.debug("`log` method is not implemented. Provided log: {}", s); + logHandler.log(s, this); return this; } @@ -258,7 +254,7 @@ public class DDSpan implements Span, MutableSpan { */ @Override public final DDSpan log(final long l, final String s) { - log.debug("`log` method is not implemented. Provided log: {}", s); + logHandler.log(l, s, this); return this; } diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java b/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java index 0c2782a1db..76ccb4b32f 100644 --- a/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java +++ b/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java @@ -580,6 +580,7 @@ public class DDTracer implements io.opentracing.Tracer, Closeable, datadog.trace private boolean errorFlag; private String spanType; private boolean ignoreScope = false; + private LogHandler logHandler = new DefaultLogHandler(); public DDSpanBuilder(final String operationName, final ScopeManager scopeManager) { this.operationName = operationName; @@ -593,7 +594,7 @@ public class DDTracer implements io.opentracing.Tracer, Closeable, datadog.trace } private Span startSpan() { - return new DDSpan(timestampMicro, buildSpanContext()); + return new DDSpan(timestampMicro, buildSpanContext(), logHandler); } @Override @@ -670,6 +671,13 @@ public class DDTracer implements io.opentracing.Tracer, Closeable, datadog.trace return parent.baggageItems(); } + public DDSpanBuilder withLogHandler(final LogHandler logHandler) { + if (logHandler != null) { + this.logHandler = logHandler; + } + return this; + } + @Override public DDSpanBuilder asChildOf(final Span span) { return asChildOf(span == null ? null : span.context()); diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/DefaultLogHandler.java b/dd-trace-ot/src/main/java/datadog/opentracing/DefaultLogHandler.java new file mode 100644 index 0000000000..0f7cf2ba63 --- /dev/null +++ b/dd-trace-ot/src/main/java/datadog/opentracing/DefaultLogHandler.java @@ -0,0 +1,43 @@ +package datadog.opentracing; + +import static io.opentracing.log.Fields.ERROR_OBJECT; +import static io.opentracing.log.Fields.MESSAGE; + +import datadog.trace.api.DDTags; +import java.util.Map; +import lombok.extern.slf4j.Slf4j; + +/** The default implementation of the LogHandler. */ +@Slf4j +public class DefaultLogHandler implements LogHandler { + @Override + public void log(Map fields, DDSpan span) { + extractError(fields, span); + log.debug("`log` method is not implemented. Doing nothing"); + } + + @Override + public void log(long timestampMicroseconds, Map fields, DDSpan span) { + extractError(fields, span); + log.debug("`log` method is not implemented. Doing nothing"); + } + + @Override + public void log(String event, DDSpan span) { + log.debug("`log` method is not implemented. Provided log: {}", event); + } + + @Override + public void log(long timestampMicroseconds, String event, DDSpan span) { + log.debug("`log` method is not implemented. Provided log: {}", event); + } + + private void extractError(final Map map, DDSpan span) { + if (map.get(ERROR_OBJECT) instanceof Throwable) { + final Throwable error = (Throwable) map.get(ERROR_OBJECT); + span.setErrorMeta(error); + } else if (map.get(MESSAGE) instanceof String) { + span.setTag(DDTags.ERROR_MSG, (String) map.get(MESSAGE)); + } + } +} diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/LogHandler.java b/dd-trace-ot/src/main/java/datadog/opentracing/LogHandler.java new file mode 100644 index 0000000000..03bc25029e --- /dev/null +++ b/dd-trace-ot/src/main/java/datadog/opentracing/LogHandler.java @@ -0,0 +1,43 @@ +package datadog.opentracing; + +import java.util.Map; + +public interface LogHandler { + + /** + * Handles the log implementation in the Span. + * + * @param fields key:value log fields. Tracer implementations should support String, numeric, and + * boolean values; some may also support arbitrary Objects. + * @param span from which the call was made + */ + void log(Map fields, DDSpan span); + + /** + * Handles the log implementation in the Span. + * + * @param timestampMicroseconds The explicit timestamp for the log record. Must be greater than or + * equal to the Span's start timestamp. + * @param fields key:value log fields. Tracer implementations should support String, numeric, and + * @param span from which the call was made + */ + void log(long timestampMicroseconds, Map fields, DDSpan span); + + /** + * Handles the log implementation in the Span.. + * + * @param event the event value; often a stable identifier for a moment in the Span lifecycle + * @param span from which the call was made + */ + void log(String event, DDSpan span); + + /** + * Handles the log implementation in the Span. + * + * @param timestampMicroseconds The explicit timestamp for the log record. Must be greater than or + * equal to the Span's start timestamp. + * @param event the event value; often a stable identifier for a moment in the Span lifecycle + * @param span from which the call was made + */ + void log(long timestampMicroseconds, String event, DDSpan span); +} diff --git a/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanBuilderTest.groovy b/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanBuilderTest.groovy index 8c753ce8f1..ad1ce537ad 100644 --- a/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanBuilderTest.groovy +++ b/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanBuilderTest.groovy @@ -8,7 +8,6 @@ import datadog.trace.common.writer.ListWriter import datadog.trace.util.test.DDSpecification import io.opentracing.Scope import io.opentracing.noop.NoopSpan - import static datadog.opentracing.DDSpanContext.ORIGIN_KEY import static java.util.concurrent.TimeUnit.MILLISECONDS @@ -480,4 +479,164 @@ class DDSpanBuilderTest extends DDSpecification { "a:a,a:b,a:c" | [a: "c"] "a:1,b-c:d" | [a: "1", "b-c": "d"] } + + def "sanity test for logs if logHandler is null"() { + setup: + final String expectedName = "fakeName" + + final DDSpan span = + tracer + .buildSpan(expectedName) + .withServiceName("foo") + .start() + final String expectedLogEvent = "fakeEvent" + final timeStamp = System.currentTimeMillis() + final Map fieldsMap = new HashMap<>() + + span.log(expectedLogEvent) + span.log(timeStamp, expectedLogEvent) + span.log(fieldsMap) + span.log(timeStamp, fieldsMap) + } + + def "sanity test when passed log handler is null"() { + setup: + final String expectedName = "fakeName" + final DDSpan span = tracer + .buildSpan(expectedName) + .withLogHandler(null) + .start() + final String expectedLogEvent = "fakeEvent" + final timeStamp = System.currentTimeMillis() + final Map fieldsMap = new HashMap<>() + + span.log(expectedLogEvent) + span.log(timeStamp, expectedLogEvent) + span.log(fieldsMap) + span.log(timeStamp, fieldsMap) + } + + + def "should delegate simple logs to logHandler"() { + setup: + final LogHandler logHandler = new TestLogHandler() + final String expectedName = "fakeName" + + final DDSpan span = + tracer + .buildSpan(expectedName) + .withLogHandler(logHandler) + .withServiceName("foo") + .start() + final String expectedLogEvent = "fakeEvent" + final timeStamp = System.currentTimeMillis() + span.log(timeStamp, expectedLogEvent) + + expect: + logHandler.assertLogCalledWithArgs(timeStamp, expectedLogEvent, span) + } + + def "should delegate simple logs with timestamp to logHandler"() { + setup: + final LogHandler logHandler = new TestLogHandler() + final String expectedName = "fakeName" + + final DDSpan span = + tracer + .buildSpan(expectedName) + .withLogHandler(logHandler) + .withServiceName("foo") + .start() + final String expectedLogEvent = "fakeEvent" + span.log(expectedLogEvent) + + expect: + logHandler.assertLogCalledWithArgs(expectedLogEvent, span) + + } + + def "should delegate logs with fields to logHandler"() { + setup: + final LogHandler logHandler = new TestLogHandler() + final String expectedName = "fakeName" + + final DDSpan span = + tracer + .buildSpan(expectedName) + .withLogHandler(logHandler) + .withServiceName("foo") + .start() + final Map fieldsMap = new HashMap<>() + span.log(fieldsMap) + + expect: + logHandler.assertLogCalledWithArgs(fieldsMap, span) + + } + + def "should delegate logs with fields and timestamp to logHandler"() { + setup: + final LogHandler logHandler = new TestLogHandler() + final String expectedName = "fakeName" + + final DDSpan span = + tracer + .buildSpan(expectedName) + .withLogHandler(logHandler) + .withServiceName("foo") + .start() + final Map fieldsMap = new HashMap<>() + final timeStamp = System.currentTimeMillis() + span.log(timeStamp, fieldsMap) + + expect: + logHandler.assertLogCalledWithArgs(timeStamp, fieldsMap, span) + + } + + private static class TestLogHandler implements LogHandler { + Object[] arguments = null + + @Override + void log(Map fields, DDSpan span) { + arguments = new Object[2] + arguments[0] = fields + arguments[1] = span + } + + @Override + void log(long timestampMicroseconds, Map fields, DDSpan span) { + arguments = new Object[3] + arguments[0] = timestampMicroseconds + arguments[1] = fields + arguments[2] = span + } + + @Override + void log(String event, DDSpan span) { + arguments = new Object[2] + arguments[0] = event + arguments[1] = span + } + + @Override + void log(long timestampMicroseconds, String event, DDSpan span) { + arguments = new Object[3] + arguments[0] = timestampMicroseconds + arguments[1] = event + arguments[2] = span + } + + boolean assertLogCalledWithArgs(Object... args) { + if (arguments.size() != args.size()) { + return false + } + for (int i = 0; i < args.size(); i++) { + if (arguments[i] != args[i]) { + return false + } + } + return true + } + } } diff --git a/dd-trace-ot/src/test/groovy/datadog/opentracing/DefaultLogHandlerTest.groovy b/dd-trace-ot/src/test/groovy/datadog/opentracing/DefaultLogHandlerTest.groovy new file mode 100644 index 0000000000..4241ffd645 --- /dev/null +++ b/dd-trace-ot/src/test/groovy/datadog/opentracing/DefaultLogHandlerTest.groovy @@ -0,0 +1,80 @@ +package datadog.opentracing + +import datadog.trace.api.DDTags +import datadog.trace.common.writer.ListWriter +import io.opentracing.log.Fields +import datadog.trace.util.test.DDSpecification + + +class DefaultLogHandlerTest extends DDSpecification { + def writer = new ListWriter() + def tracer = DDTracer.builder().writer(writer).build() + + def "handles correctly the error passed in the fields"() { + setup: + final LogHandler underTest = new DefaultLogHandler() + final DDSpan span = tracer.buildSpan("op name").withServiceName("foo").start() + final String errorMessage = "errorMessage" + final String differentMessage = "differentMessage" + final Throwable throwable = new Throwable(errorMessage) + final Map fields = new HashMap<>() + fields.put(Fields.ERROR_OBJECT, throwable) + fields.put(Fields.MESSAGE, differentMessage) + + when: + underTest.log(fields, span) + + then: + span.getTags().get(DDTags.ERROR_MSG) == throwable.getMessage() + span.getTags().get(DDTags.ERROR_TYPE) == throwable.getClass().getName() + } + + def "handles correctly the error passed in the fields when called with timestamp"() { + setup: + final LogHandler underTest = new DefaultLogHandler() + final DDSpan span = tracer.buildSpan("op name").withServiceName("foo").start() + final String errorMessage = "errorMessage" + final String differentMessage = "differentMessage" + final Throwable throwable = new Throwable(errorMessage) + final Map fields = new HashMap<>() + fields.put(Fields.ERROR_OBJECT, throwable) + fields.put(Fields.MESSAGE, differentMessage) + + when: + underTest.log(System.currentTimeMillis(), fields, span) + + then: + span.getTags().get(DDTags.ERROR_MSG) == throwable.getMessage() + span.getTags().get(DDTags.ERROR_TYPE) == throwable.getClass().getName() + } + + def "handles correctly the message passed in the fields"() { + setup: + final LogHandler underTest = new DefaultLogHandler() + final DDSpan span = tracer.buildSpan("op name").withServiceName("foo").start() + final String errorMessage = "errorMessage" + final Map fields = new HashMap<>() + fields.put(Fields.MESSAGE, errorMessage) + + when: + underTest.log(fields, span) + + then: + span.getTags().get(DDTags.ERROR_MSG) == errorMessage + } + + def "handles correctly the message passed in the fields when called with timestamp"() { + setup: + final LogHandler underTest = new DefaultLogHandler() + final DDSpan span = tracer.buildSpan("op name").withServiceName("foo").start() + final String errorMessage = "errorMessage" + final Map fields = new HashMap<>() + fields.put(Fields.MESSAGE, errorMessage) + + when: + underTest.log(System.currentTimeMillis(), fields, span) + + then: + span.getTags().get(DDTags.ERROR_MSG) == errorMessage + } +}