Start implementation of the new tracer API

This mainly implements Span, Trace and Continuation logic.
This commit is contained in:
Nikolay Martynov 2018-12-12 16:42:17 -05:00
parent f6818fae84
commit 9674e9f61a
31 changed files with 2477 additions and 298 deletions

View File

@ -1,7 +1,7 @@
package datadog.trace.tracer.ext;
import datadog.trace.tracer.Continuation;
import datadog.trace.tracer.Span;
import datadog.trace.tracer.Trace;
import datadog.trace.tracer.Tracer;
// Keeping in PR for potential discussions. Will eventually remove.
@ -18,9 +18,8 @@ class Examples {
final TracerContext ctx = TracerContext.getGlobalContext();
// without try-with-resources
{
Span rootSpan = ctx.getTracer().buildTrace(null);
final Span rootSpan = ctx.getTracer().buildTrace(null);
final Scope scope = ctx.pushScope(rootSpan);
rootSpan.setError(true);
rootSpan.attachThrowable(someThrowable);
scope.close();
rootSpan.finish();
@ -44,11 +43,10 @@ class Examples {
// with try-with-resources finishOnClose=false
{
Span rootSpan = ctx.getTracer().buildTrace(null);
try (Scope scope = ctx.pushScope(rootSpan)) {
final Span rootSpan = ctx.getTracer().buildTrace(null);
try (final Scope scope = ctx.pushScope(rootSpan)) {
// the body
} catch (Throwable t) {
rootSpan.setError(true);
} catch (final Throwable t) {
rootSpan.attachThrowable(t);
throw t;
} finally {
@ -58,10 +56,10 @@ class Examples {
// continuations
{
Span rootSpan = ctx.getTracer().buildTrace(null);
final Trace.Continuation cont = rootSpan.getTrace().createContinuation(rootSpan);
final Span rootSpan = ctx.getTracer().buildTrace(null);
final Continuation cont = rootSpan.getTrace().createContinuation(rootSpan);
{ // on another thread
final Span parent = cont.span();
final Span parent = cont.getSpan();
try {
// body
} finally {
@ -71,6 +69,7 @@ class Examples {
}
// create a span as a child of the currently active span
Span childSpan = ctx.peekScope().span().getTrace().createSpan(ctx.peekScope().span());
final Span childSpan =
ctx.peekScope().span().getTrace().createSpan(ctx.peekScope().span().getContext());
}
}

View File

@ -1,14 +1,14 @@
package datadog.trace.tracer.ext;
import datadog.trace.tracer.Continuation;
import datadog.trace.tracer.Span;
import datadog.trace.tracer.Trace;
/**
* A scope holds a single span or trace continuation and may optionally finish its span or
* continuation.
*
* <p>To create a scope, see {@link TracerContext#pushScope(Span)} and {@link
* TracerContext#pushScope(Trace.Continuation)}.
* TracerContext#pushScope(Continuation)}.
*
* <p>All created scopes must be closed with {@link Scope#close()}
*/
@ -22,5 +22,6 @@ public interface Scope extends AutoCloseable {
* <p>Attempting to close a scope which is not on the top of its TracerContext's scope-stack is an
* error. See {@link TracerContext#peekScope()}.
*/
@Override
void close();
}

View File

@ -1,7 +1,7 @@
package datadog.trace.tracer.ext;
import datadog.trace.tracer.Continuation;
import datadog.trace.tracer.Span;
import datadog.trace.tracer.Trace;
import datadog.trace.tracer.Tracer;
/**
@ -27,7 +27,7 @@ public final class TracerContext {
* @return The old global TracerContext, or null if no previous context ws registered
*/
public static TracerContext registerGlobalContext(
TracerContext context, boolean replaceExisting) {
final TracerContext context, final boolean replaceExisting) {
return null;
}
@ -38,7 +38,7 @@ public final class TracerContext {
private final Tracer tracer;
public TracerContext(Tracer tracer) {
public TracerContext(final Tracer tracer) {
this.tracer = tracer;
}
@ -55,7 +55,7 @@ public final class TracerContext {
* @param span
* @return
*/
public Scope pushScope(Span span) {
public Scope pushScope(final Span span) {
return null;
}
@ -66,7 +66,7 @@ public final class TracerContext {
* @param continuation
* @return
*/
public Scope pushScope(Trace.Continuation continuation) {
public Scope pushScope(final Continuation continuation) {
return null;
}
@ -77,7 +77,7 @@ public final class TracerContext {
*
* @param scope the topmost scope in the scope stack.
*/
public void popScope(Scope scope) {}
public void popScope(final Scope scope) {}
/** @return The scope on the top of this scope-stack or null if there is no active scope. */
public Scope peekScope() {

View File

@ -5,6 +5,7 @@ dependencies {
annotationProcessor deps.autoservice
implementation deps.autoservice
compile project(':dd-java-agent:agent-bootstrap')
compile project(':dd-trace-api')
compile deps.jackson
@ -12,4 +13,9 @@ dependencies {
// any higher versions seems to break ES tests with this exception:
// java.lang.NoSuchMethodError: com.fasterxml.jackson.dataformat.smile.SmileGenerator.getOutputContext()
compile group: 'org.msgpack', name: 'jackson-dataformat-msgpack', version: '0.8.14'
// Spock uses that for mocking
testCompile deps.bytebuddy
testCompile group: 'org.objenesis', name: 'objenesis', version: '2.6' // Last version to support Java7
testCompile group: 'nl.jqno.equalsverifier', name: 'equalsverifier', version: '2.5.2' // Last version to support Java7
}

View File

@ -1,34 +1,59 @@
package datadog.trace.tracer;
import java.util.concurrent.TimeUnit;
import lombok.EqualsAndHashCode;
/**
* A simple wrapper for system clock that aims to provide the current time
*
* <p>
*
* <p>
*
* <p>
* This is a wrapper to System clock that provides an easier way to get nanosecond precision.
*
* <p>The JDK provides two clocks:
* <li>one in nanoseconds, for precision, but it can only use to measure durations
* <li>one in milliseconds, for accuracy, useful to provide epoch time
*
* <p>
* <p>Once created this class captures current time with millisecond presition and current
* nanosecond counter.
*
* <p>At this time, we are using a millis precision (converted to micros) in order to guarantee
* consistency between the span start times and the durations
* <p>It provides an API to create {@link Timestamp} that can be used to measure durations with
* nanosecond precision.
*/
@EqualsAndHashCode
public class Clock {
/** Tracer that created this clock */
private final Tracer tracer;
/** Trace start time in nano seconds measured up to a millisecond accuracy */
private final long startTimeNano;
/** Nano ticks counter when clock is created */
private final long startNanoTicks;
public Clock(final Tracer tracer) {
this.tracer = tracer;
startTimeNano = epochTimeNano();
startNanoTicks = nanoTicks();
}
/** @return {@link Tracer} that created this clock. */
public Tracer getTracer() {
return tracer;
}
/**
* Get the current nanos ticks (i.e. System.nanonTime()), this method can't be use for date
* accuracy (only duration calculations)
* Create new timestamp instance for current time.
*
* @return The current nanos ticks
* @return new timestamp capturing current time.
*/
public static long nanoTime() {
public Timestamp createCurrentTimestamp() {
return new Timestamp(this);
}
/**
* Get the current nanos ticks (i.e. System.nanoTime()), this method can't be use for date
* accuracy (only duration calculations).
*
* @return The current nanos ticks.
*/
long nanoTicks() {
return System.nanoTime();
}
@ -37,20 +62,38 @@ public class Clock {
*
* <p>Note: The actual precision is the millis.
*
* @return the current epoch time in micros
* @return the current epoch time in micros.
*/
public static long epochTimeMicro() {
long epochTimeMicro() {
return TimeUnit.MILLISECONDS.toMicros(System.currentTimeMillis());
}
/**
* Get the current epoch time in nanos.
*
* <p>Note: The actual precision is the millis. This will overflow ~290 years after epoch
* <p>Note: The actual precision is the millis. This will overflow ~290 years after epoch.
*
* @return the current epoch time in nanos
* @return the current epoch time in nanos.
*/
public static long epochTimeNano() {
long epochTimeNano() {
return TimeUnit.MILLISECONDS.toNanos(System.currentTimeMillis());
}
/**
* Get time this clock instance was created in nanos.
*
* @return the time this clock instance was created in nanos.
*/
long getStartTimeNano() {
return startTimeNano;
}
/**
* Get nano ticks counter value when this clock instance was created.
*
* @return nano ticks counter value when this clock instance was created.
*/
long getStartNanoTicks() {
return startNanoTicks;
}
}

View File

@ -0,0 +1,26 @@
package datadog.trace.tracer;
/**
* Continuations are used to prevent a trace from reporting without creating a span.
*
* <p>All spans are thread safe.
*
* <p>To create a Span, see {@link Trace#createContinuation(Span parentSpan)}
*/
public interface Continuation {
/** @return parent span used to create this continuation. */
Span getSpan();
/** @return trace used to create this continuation. */
Trace getTrace();
/** @return true iff continuation has been closed. */
boolean isClosed();
/**
* Close the continuation. Continuation's trace will not block reporting on account of this
* continuation.
*/
void close();
}

View File

@ -0,0 +1,69 @@
package datadog.trace.tracer;
/** Concrete implementation of a continuation */
class ContinuationImpl implements Continuation {
private final TraceInternal trace;
private final Span span;
private volatile boolean closed = false;
ContinuationImpl(final TraceInternal trace, final Span span) {
this.trace = trace;
this.span = span;
}
@Override
public Trace getTrace() {
return trace;
}
@Override
public Span getSpan() {
return span;
}
@Override
public boolean isClosed() {
return closed;
}
@Override
public synchronized void close() {
if (closed) {
reportUsageError("Attempted to close continuation that is already closed: %s", this);
} else {
closeContinuation(false);
}
}
// TODO: we may want to reconsider usage of 'finalize'. One of the problems seems to be that
// exceptions thrown in finalizer are eaten up and ignored, and may not even be logged by default.
// This may lead to fun debugging sessions.
@Override
protected synchronized void finalize() {
if (!closed) {
trace
.getTracer()
.reportWarning(
"Closing continuation due to GC, this will prevent trace from being reported: %s",
this);
closeContinuation(true);
}
}
/**
* Helper method to perform operations needed to close the continuation.
*
* <p>Note: This has to be called under object lock.
*
* @param invalid true iff continuation is being closed due to GC, this will make trace invalid.
*/
private void closeContinuation(final boolean invalid) {
closed = true;
trace.closeContinuation(this, invalid);
}
private void reportUsageError(final String message, final Object... args) {
trace.getTracer().reportError(message, args);
}
}

View File

@ -0,0 +1,29 @@
package datadog.trace.tracer;
/**
* An Interceptor allows adding hooks to particular events of a span starting and finishing and also
* trace being written to backend.
*/
public interface Interceptor {
/**
* Called after a span is started.
*
* @param span the started span.
*/
void afterSpanStarted(Span span);
/**
* Called before a span is finished.
*
* @param span the span to be finished.
*/
void beforeSpanFinished(Span span);
/**
* Invoked when a trace is eligible for writing but hasn't been handed off to its writer yet.
*
* @param trace The intercepted trace.
* @return modified trace. Null if trace is to be dropped.
*/
Trace beforeTraceWritten(Trace trace);
}

View File

@ -5,13 +5,118 @@ package datadog.trace.tracer;
*
* <p>All spans are thread safe.
*
* <p>To create a Span, see {@link Tracer#buildTrace()}
* <p>To create a Span, see {@link Trace#createSpan(SpanContext parentContext, Timestamp
* startTimestamp)}
*/
public interface Span {
/** @return The trace this span is associated with. */
Trace getTrace();
/** @return start timestamp of this span */
public Timestamp getStartTimestamp();
/** @return duration of this span in nanoseconds or null if span is not finished */
public Long getDuration();
/** @return true if a finish method has been invoked on this span. */
boolean isFinished();
/**
* Get the span context for this span - required attributes to report to datadog.
*
* <p>See https://docs.datadoghq.com/api/?lang=python#tracing
*
* @return the span context.
*/
SpanContext getContext();
/** @return the span's service. */
String getService();
/**
* Set the span's service.
*
* <p>May not exceed 100 characters.
*
* @param service the new service for the span.
*/
void setService(String service);
/** @return the span's resource. */
String getResource();
/**
* Span the span's resource (e.g. http endpoint).
*
* <p>May not exceed 5000 characters.
*
* @param resource the new resource for the span.
*/
void setResource(String resource);
/** @return the span's type. */
String getType();
/**
* Set the span's type (web, db, etc). {@see DDSpanTypes}.
*
* @param type the new type of the span.
*/
void setType(String type);
/** @return the span's name. */
String getName();
/**
* Set the span's name.
*
* <p>May not exceed 100 characters.
*
* @param name the new name for the span.
*/
void setName(String name);
/** @return true iff span was marked as error span. */
boolean isErrored();
/**
* Mark the span as having an error.
*
* @param errored true if the span has an error.
*/
void setErrored(boolean errored);
/** */
/**
* Attach a throwable to this span.
*
* @param throwable throwable to attach
*/
void attachThrowable(Throwable throwable);
/**
* Get a meta value on a span.
*
* @param key The meta key
* @return The value currently associated with the given key. Null if no associated.
*/
Object getMeta(String key);
/**
* Set key-value metadata on the span.
*
* @param key to set
* @param value to set
*/
void setMeta(String key, String value);
/** {@link Span#setMeta(String, String)} for boolean values */
void setMeta(String key, Boolean value);
/** {@link Span#setMeta(String, String)} for number values */
void setMeta(String key, Number value);
/** Stop the span's timer. Has no effect if the span is already finished. */
void finish();
@ -25,93 +130,6 @@ public interface Span {
*/
void finish(long finishTimestampNanoseconds);
/** Returns true if a finish method has been invoked on this span. */
boolean isFinished();
/**
* Get the span context for this span.
*
* @return the span context.
*/
SpanContext getContext();
/**
* Get a meta value on a span.
*
* @param key The meta key
* @return The value currently associated with the given key. Null if no associated. TODO: can
* return null
*/
Object getMeta(String key);
/**
* Set key-value metadata on the span.
*
* <p>TODO: Forbid setting null?
*/
void setMeta(String key, String value);
/** {@link Span#setMeta(String, String)} for boolean values */
void setMeta(String key, boolean value);
/** {@link Span#setMeta(String, String)} for number values */
void setMeta(String key, Number value);
/** Get the span's name */
String getName();
/**
* Set the span's name.
*
* @param newName the new name for the span.
*/
void setName(String newName);
String getResource();
void setResource(String newResource);
String getService();
void setService(String newService);
String getType();
void setType(String newType);
boolean isErrored();
/** Attach a throwable to this span. */
void attachThrowable(Throwable t);
/**
* Mark the span as having an error.
*
* @param isErrored true if the span has an error.
*/
void setError(boolean isErrored);
// TODO: OpenTracing Span#log methods. Do we need something here to support them? Current DDSpan
// does not implement.
/**
* A Interceptor allows adding hooks to particular events between a span starting and finishing.
*/
interface Interceptor {
/**
* Called after a span is started.
*
* @param span the started span
*/
void spanStarted(Span span);
/** Called after a span's metadata is updated. */
void afterMetadataSet(Span span, Object key, Object value);
/**
* Called after a span is finished.
*
* @param span the started span
*/
void spanFinished(Span span);
}
}

View File

@ -8,19 +8,6 @@ package datadog.trace.tracer;
* <p>All SpanContexts are thread safe.
*/
public interface SpanContext {
/**
* Get this context's span id.
*
* @return 64 bit unsigned integer in String format.
*/
String getSpanId();
/**
* Get this context's parent span id.
*
* @return 64 bit unsigned integer in String format.
*/
String getParentId();
/**
* Get this context's trace id.
@ -29,6 +16,20 @@ public interface SpanContext {
*/
String getTraceId();
/**
* Get this context's parent span id.
*
* @return 64 bit unsigned integer in String format.
*/
String getParentId();
/**
* Get this context's span id.
*
* @return 64 bit unsigned integer in String format.
*/
String getSpanId();
/**
* Get the sampling flag for this context.
*

View File

@ -0,0 +1,61 @@
package datadog.trace.tracer;
import datadog.trace.api.sampling.PrioritySampling;
import java.util.concurrent.ThreadLocalRandom;
import lombok.EqualsAndHashCode;
@EqualsAndHashCode
class SpanContextImpl implements SpanContext {
public static final String ZERO = "0";
private final String traceId;
private final String parentId;
private final String spanId;
SpanContextImpl(final String traceId, final String parentId, final String spanId) {
this.traceId = traceId;
this.parentId = parentId;
this.spanId = spanId;
}
@Override
public String getTraceId() {
return traceId;
}
@Override
public String getParentId() {
return parentId;
}
@Override
public String getSpanId() {
return spanId;
}
// TODO: Implement proper priority handling methods
@Override
public Integer getSamplingFlags() {
return PrioritySampling.SAMPLER_KEEP;
}
static SpanContext fromParent(final SpanContext parent) {
final String traceId;
final String parentId;
if (parent == null) {
traceId = generateNewId();
parentId = ZERO;
} else {
traceId = parent.getTraceId();
parentId = parent.getSpanId();
}
return new SpanContextImpl(traceId, parentId, generateNewId());
}
static String generateNewId() {
// TODO: expand the range of numbers generated to be from 1 to uint 64 MAX
// Ensure the generated ID is in a valid range:
return String.valueOf(ThreadLocalRandom.current().nextLong(1, Long.MAX_VALUE));
}
}

View File

@ -1,138 +1,261 @@
package datadog.trace.tracer;
import datadog.trace.api.DDTags;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.concurrent.atomic.AtomicLong;
public class SpanImpl implements Span {
private final Clock clock = null;
private final Trace trace = null;
// See See https://docs.datadoghq.com/api/?lang=python#tracing
// Required attributes to report to datadog.
private final SpanContext context = null;
/* Span name. May not exceed 100 characters. */
private final String name = "";
/* Span resource (e.g. http endpoint). May not exceed 5000 characters. */
private final String resource = "";
/* Span service. May not exceed 100 characters. */
private final String service = "";
/* The start time of the request in nanoseconds from the unix epoch. */
private final long startEpochNano = -1;
/* Duration of the span in nanoseconds */
private final AtomicLong durationNano = new AtomicLong(-1);
// optional attributes to report to datadog
/* The type of the span (web, db, etc). See DDSpanTypes. */
private final String type = null;
/* Marks the span as having an error. */
private final boolean isErrored = false;
/* Additional key-value pairs for a span. */
private final Map<String, Object> meta = null;
/** Concrete implementation of a span */
class SpanImpl implements Span {
private final TraceInternal trace;
private final SpanContext context;
private final Timestamp startTimestamp;
/* Note: some fields are volatile so we could make getters non synchronized.
Alternatively we could make getters synchronized, but this may create more contention.
*/
private volatile Long duration = null;
private volatile String service;
private volatile String resource;
private volatile String type;
private volatile String name;
private volatile boolean errored = false;
private final Map<String, Object> meta = new HashMap<>();
private final List<Interceptor> interceptors;
/**
* Create a span with a start time of the current timestamp.
* Create a span with the a specific startTimestamp timestamp.
*
* @param trace The trace to associate this span with
* @param trace The trace to associate this span with.
* @param parentContext identifies the parent of this span. May be null.
* @param clock The clock to use to measure the span's duration.
* @param interceptors interceptors to run on the span
* @param startTimestamp timestamp when this span was started.
*/
SpanImpl(
final TraceImpl trace,
final SpanContext parentContext,
final Clock clock,
List<Interceptor> interceptors) {}
final TraceInternal trace, final SpanContext parentContext, final Timestamp startTimestamp) {
this.trace = trace;
/**
* Create a span with the a specific start timestamp.
*
* @param trace The trace to associate this span with
* @param parentContext identifies the parent of this span. May be null.
* @param clock The clock to use to measure the span's duration.
* @param interceptors interceptors to run on the span
* @param startTimestampNanoseconds Epoch time in nanoseconds when this span started.
*/
SpanImpl(
final TraceImpl trace,
final SpanContext parentContext,
final Clock clock,
List<Interceptor> interceptors,
final long startTimestampNanoseconds) {}
context = SpanContextImpl.fromParent(parentContext);
if (startTimestamp == null) {
reportUsageError("Cannot create span without timestamp: %s", trace);
throw new TraceException(String.format("Cannot create span without timestamp: %s", trace));
}
this.startTimestamp = startTimestamp;
service = trace.getTracer().getDefaultServiceName();
interceptors = trace.getTracer().getInterceptors();
for (final Interceptor interceptor : interceptors) {
interceptor.afterSpanStarted(this);
}
}
@Override
public Trace getTrace() {
return null;
return trace;
}
@Override
public void finish() {}
@Override
public void finish(long finishTimestampNanoseconds) {}
@Override
public boolean isFinished() {
return false;
}
@Override
public void attachThrowable(Throwable t) {}
@Override
public void setError(boolean isErrored) {}
@Override
public SpanContext getContext() {
return null;
return context;
}
@Override
public Object getMeta(String key) {
return null;
public Timestamp getStartTimestamp() {
return startTimestamp;
}
@Override
public void setMeta(String key, String value) {}
@Override
public void setMeta(String key, boolean value) {}
@Override
public void setMeta(String key, Number value) {}
@Override
public String getName() {
return null;
public Long getDuration() {
return duration;
}
@Override
public void setName(String newName) {}
@Override
public String getResource() {
return null;
public boolean isFinished() {
return duration != null;
}
@Override
public void setResource(String newResource) {}
@Override
public String getService() {
return null;
return service;
}
@Override
public void setService(String newService) {}
public synchronized void setService(final String service) {
if (isFinished()) {
reportSetterUsageError("service");
} else {
this.service = service;
}
}
@Override
public String getResource() {
return resource;
}
@Override
public synchronized void setResource(final String resource) {
if (isFinished()) {
reportSetterUsageError("resource");
} else {
this.resource = resource;
}
}
@Override
public String getType() {
return null;
return type;
}
@Override
public void setType(String newType) {}
public synchronized void setType(final String type) {
if (isFinished()) {
reportSetterUsageError("type");
} else {
this.type = type;
}
}
@Override
public String getName() {
return name;
}
@Override
public synchronized void setName(final String name) {
if (isFinished()) {
reportSetterUsageError("name");
} else {
this.name = name;
}
}
@Override
public boolean isErrored() {
return false;
return errored;
}
@Override
public synchronized void attachThrowable(final Throwable throwable) {
if (isFinished()) {
reportSetterUsageError("throwable");
} else {
setErrored(true);
setMeta(DDTags.ERROR_MSG, throwable.getMessage());
setMeta(DDTags.ERROR_TYPE, throwable.getClass().getName());
final StringWriter errorString = new StringWriter();
throwable.printStackTrace(new PrintWriter(errorString));
setMeta(DDTags.ERROR_STACK, errorString.toString());
}
}
@Override
public synchronized void setErrored(final boolean errored) {
if (isFinished()) {
reportSetterUsageError("errored");
} else {
this.errored = errored;
}
}
@Override
public synchronized Object getMeta(final String key) {
return meta.get(key);
}
protected synchronized void setMeta(final String key, final Object value) {
if (isFinished()) {
reportSetterUsageError("meta value " + key);
} else {
if (value == null) {
meta.remove(key);
} else {
meta.put(key, value);
}
}
}
@Override
public void setMeta(final String key, final String value) {
setMeta(key, (Object) value);
}
@Override
public void setMeta(final String key, final Boolean value) {
setMeta(key, (Object) value);
}
@Override
public void setMeta(final String key, final Number value) {
setMeta(key, (Object) value);
}
@Override
public synchronized void finish() {
if (isFinished()) {
reportUsageError("Attempted to finish span that is already finished: %s", this);
} else {
finishSpan(startTimestamp.getDuration(), false);
}
}
@Override
public synchronized void finish(final long finishTimestampNanoseconds) {
if (isFinished()) {
reportUsageError("Attempted to finish span that is already finish: %s", this);
} else {
finishSpan(startTimestamp.getDuration(finishTimestampNanoseconds), false);
}
}
// TODO: we may want to reconsider usage of 'finalize'. One of the problems seems to be that
// exceptions thrown in finalizer are eaten up and ignored, and may not even be logged by default.
// This may lead to fun debugging sessions.
@Override
protected synchronized void finalize() {
// Note: according to docs finalize is only called once for a given instance - even if instance
// if 'revived' from the dead by passing reference to some other object and then dies again.
if (!isFinished()) {
trace
.getTracer()
.reportWarning(
"Finishing span due to GC, this will prevent trace from being reported: %s", this);
finishSpan(startTimestamp.getDuration(), true);
}
}
/**
* Helper method to perform operations to finish the span.
*
* <p>Note: This has to be called under object lock.
*
* @param duration duration of the span.
* @param fromGC true iff we are closing span because it is being GCed, this will make trace
* invalid.
*/
private void finishSpan(final long duration, final boolean fromGC) {
// Run interceptors in 'reverse' order
for (int i = interceptors.size() - 1; i >= 0; i--) {
interceptors.get(i).beforeSpanFinished(this);
}
this.duration = duration;
trace.finishSpan(this, fromGC);
}
private void reportUsageError(final String message, final Object... args) {
trace.getTracer().reportError(message, args);
}
private void reportSetterUsageError(final String fieldName) {
reportUsageError("Attempted to set '%s' when span is already finished: %s", fieldName, this);
}
}

View File

@ -0,0 +1,80 @@
package datadog.trace.tracer;
import static java.lang.Math.max;
import lombok.EqualsAndHashCode;
/**
* Class that encapsulations notion of a given timestamp, or instant in time.
*
* <p>Timestamps are created by a [@link Clock} instance.
*/
@EqualsAndHashCode
public class Timestamp {
private final Clock clock;
private final long nanoTicks;
/**
* Create timestamp for a given clock and given nanoTicks state
*
* @param clock clock instance
*/
Timestamp(final Clock clock) {
this.clock = clock;
nanoTicks = clock.nanoTicks();
}
/** @return clock instance used by this timestamp */
public Clock getClock() {
return clock;
}
/** @return duration in nanoseconds from this time stamp to current time. */
public long getDuration() {
return getDuration(new Timestamp(clock));
}
/**
* Get duration in nanoseconds from this time stamp to provided finish timestamp.
*
* @param finishTimestamp finish timestamp to use as period's end.
* @return duration in nanoseconds.
*/
public long getDuration(final Timestamp finishTimestamp) {
if (clock != finishTimestamp.clock) {
clock
.getTracer()
.reportError(
"Trying to find duration between two timestamps created by different clocks. Current clock: %s, finish timestamp clock: %s",
clock, finishTimestamp.clock);
// Do our best to try to calculate nano-second time using millisecond clock start time and
// nanosecond offset.
return max(
0,
(finishTimestamp.clock.getStartTimeNano() + finishTimestamp.startTicksOffset())
- (clock.getStartTimeNano() + startTicksOffset()));
}
return max(0, finishTimestamp.nanoTicks - nanoTicks);
}
/**
* Duration in nanoseconds for external finish time.
*
* <p>Note: since we can only get time with millisecond precision in Java this ends up being
* effectively millisecond precision duration converted to nanoseconds.
*
* @param finishTimeNanoseconds
* @return duration in nanoseconds (with millisecond precision).
*/
public long getDuration(final long finishTimeNanoseconds) {
// This is calculated as the difference between finish time and clock start time and then
// subtracting difference between timestamp nanoticks and clock start nanoticks to account for
// time after clock has been created and before timestamp has been created.
return max(0, finishTimeNanoseconds - clock.getStartTimeNano() - startTicksOffset());
}
private long startTicksOffset() {
return nanoTicks - clock.getStartNanoTicks();
}
}

View File

@ -1,5 +1,7 @@
package datadog.trace.tracer;
import java.util.List;
/**
* A tree of {@link Span}s with a single root node plus logic to determine when to report said tree
* to the backend.
@ -7,23 +9,44 @@ package datadog.trace.tracer;
* <p>A trace will be written when all of its spans are finished and all trace continuations are
* closed.
*
* <p>To create a Trace, see {@link Tracer#buildTrace()}
* <p>To create a Trace, see {@link Tracer#buildTrace(SpanContext parentContext)}
*/
public interface Trace {
/** Get the tracer which created this trace. */
/** @return the tracer which created this trace. */
Tracer getTracer();
/** Get the root span for this trace. This will never be null. */
/** @return the root span for this trace. This will never be null. */
Span getRootSpan();
/**
* Create a new span in this trace as a child of the given parentSpan.
* @return list of spans for this trace. Note: if trace is not finished this will report error.
*/
List<Span> getSpans();
/** @return true iff trace is valid (invalid traces should not be reported). */
boolean isValid();
/** @return current timestamp using this trace's clock */
Timestamp createCurrentTimestamp();
/**
* Create a new span in this trace as a child of the given parent context.
*
* @param parentSpan the parent to use. Must be a span in this trace.
* @param parentContext the parent to use. Must be a span in this trace.
* @return the new span. It is the caller's responsibility to ensure {@link Span#finish()} is
* eventually invoked on this span.
*/
Span createSpan(Span parentSpan);
Span createSpan(final SpanContext parentContext);
/**
* Create a new span in this trace as a child of the given parent context.
*
* @param parentContext the parent to use. Must be a span in this trace.
* @param startTimestamp timestamp to use as start timestamp for a new span.
* @return the new span. It is the caller's responsibility to ensure {@link Span#finish()} is
* eventually invoked on this span.
*/
Span createSpan(final SpanContext parentContext, final Timestamp startTimestamp);
/**
* Create a new continuation for this trace
@ -33,27 +56,4 @@ public interface Trace {
* Continuation#close()} is eventually invoked on this continuation.
*/
Continuation createContinuation(Span parentSpan);
interface Interceptor {
/**
* Invoked when a trace is eligible for writing but hasn't been handed off to its writer yet.
*
* @param trace The intercepted trace.
*/
void beforeTraceWritten(Trace trace);
}
/** A way to prevent a trace from reporting without creating a span. */
interface Continuation {
/**
* Close the continuation. Continuation's trace will not block reporting on account of this
* continuation.
*
* <p>Has no effect after the first invocation.
*/
void close();
// TODO: doc
Span span();
}
}

View File

@ -0,0 +1,54 @@
package datadog.trace.tracer;
/** Tracer-specific runtime exception. */
public class TraceException extends RuntimeException {
/**
* Constructs a new trace exception with {@code null} as its detail message. The cause is not
* initialized, and may subsequently be initialized by a call to {@link #initCause}.
*/
public TraceException() {
super();
}
/**
* Constructs a new trace exception with the specified detail message. The cause is not
* initialized, and may subsequently be initialized by a call to {@link #initCause}.
*
* @param message the detail message. The detail message is saved for later retrieval by the
* {@link #getMessage()} method.
*/
public TraceException(final String message) {
super(message);
}
/**
* Constructs a new trace exception with the specified detail message and cause.
*
* <p>Note that the detail message associated with {@code cause} is <i>not</i> automatically
* incorporated in this runtime exception's detail message.
*
* @param message the detail message (which is saved for later retrieval by the {@link
* #getMessage()} method).
* @param cause the cause (which is saved for later retrieval by the {@link #getCause()} method).
* (A <tt>null</tt> value is permitted, and indicates that the cause is nonexistent or
* unknown.)
*/
public TraceException(final String message, final Throwable cause) {
super(message, cause);
}
/**
* Constructs a new runtime exception with the specified cause and a detail message of
* <tt>(cause==null ? null : cause.toString())</tt> (which typically contains the class and detail
* message of <tt>cause</tt>). This constructor is useful for runtime exceptions that are little
* more than wrappers for other throwables.
*
* @param cause the cause (which is saved for later retrieval by the {@link #getCause()} method).
* (A <tt>null</tt> value is permitted, and indicates that the cause is nonexistent or
* unknown.)
*/
public TraceException(final Throwable cause) {
super(cause);
}
}

View File

@ -1,23 +1,36 @@
package datadog.trace.tracer;
import datadog.trace.tracer.writer.Writer;
import java.lang.ref.WeakReference;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import java.util.Set;
import java.util.WeakHashMap;
public class TraceImpl implements Trace {
private final Writer writer = null;
class TraceImpl implements TraceInternal {
// TODO: Document approach to weak-referencdes and cleanup. If a span has to be closed by our GC
// logic the trace should increment the writer's count but not report (invalid api usage produces
// suspect data).
private final Set<WeakReference<Span>> inFlightSpans = null;
private final Set<WeakReference<Trace.Continuation>> inFlightContinuations = null;
/* We use weakly referenced sets to track 'in-flight' spans and continuations. We use span/continuation's
finalizer to notify trace that span/continuation is being GCed.
If any part of the trace (span or continuation) has been was finished (closed) via GC then trace would be
marked as 'invalid' and will not be reported the the backend. Instead only writer's counter would be incremented.
This allows us not to report traces that have wrong timing information.
Note: instead of using {@link WeakHashMap} we may want to consider using more fancy implementations from
{@link datadog.trace.agent.tooling.WeakMapSuppliers}. If we do this care should be taken to avoid creating
cleanup threads per trace.
*/
private final Set<Span> inFlightSpans =
Collections.newSetFromMap(new WeakHashMap<Span, Boolean>());
private final Set<Continuation> inFlightContinuations =
Collections.newSetFromMap(new WeakHashMap<Continuation, Boolean>());
/** Strong refs to spans which are closed */
private final List<Span> finishedSpans = null;
private final List<Span> finishedSpans = new ArrayList();
private final Span rootSpan = null;
private final Tracer tracer;
private final Clock clock;
private final Span rootSpan;
private boolean valid = true;
private boolean finished = false;
/**
* Create a new Trace.
@ -25,30 +38,160 @@ public class TraceImpl implements Trace {
* @param tracer the Tracer to apply settings from.
*/
TraceImpl(
Tracer tracer,
SpanContext rootSpanParentContext,
final long rootSpanStartTimestampNanoseconds) {}
final Tracer tracer,
final SpanContext rootSpanParentContext,
final Timestamp rootSpanStartTimestamp) {
this.tracer = tracer;
clock = rootSpanStartTimestamp.getClock();
rootSpan = new SpanImpl(this, rootSpanParentContext, rootSpanStartTimestamp);
inFlightSpans.add(rootSpan);
}
@Override
public Tracer getTracer() {
return null;
return tracer;
}
@Override
public Span getRootSpan() {
return null;
return rootSpan;
}
@Override
public Span createSpan(Span parentSpan) {
return null;
public synchronized List<Span> getSpans() {
if (!finished) {
tracer.reportError("Cannot get spans, trace is not finished yet: %s", this);
return Collections.EMPTY_LIST;
}
return Collections.unmodifiableList(finishedSpans);
}
@Override
public Continuation createContinuation(Span parentSpan) {
return null;
public synchronized boolean isValid() {
return valid;
}
// TODO methods to inform the trace that continuations and spans finished/closed. Also be able to
// inform trace when a span finishes due to GC.
@Override
public Timestamp createCurrentTimestamp() {
return clock.createCurrentTimestamp();
}
@Override
public Span createSpan(final SpanContext parentContext) {
return createSpan(parentContext, createCurrentTimestamp());
}
@Override
public synchronized Span createSpan(
final SpanContext parentContext, final Timestamp startTimestamp) {
checkTraceFinished("create span");
if (parentContext == null) {
throw new TraceException("Got null parent context, trace: " + this);
}
if (!parentContext.getTraceId().equals(rootSpan.getContext().getTraceId())) {
throw new TraceException(
String.format(
"Wrong trace id when creating a span. Got %s, expected %s",
parentContext.getTraceId(), rootSpan.getContext().getTraceId()));
}
final Span span = new SpanImpl(this, parentContext, startTimestamp);
inFlightSpans.add(span);
return span;
}
@Override
public synchronized Continuation createContinuation(final Span span) {
checkTraceFinished("create continuation");
if (span == null) {
throw new TraceException("Got null parent span, trace: " + this);
}
if (!span.getContext().getTraceId().equals(rootSpan.getContext().getTraceId())) {
throw new TraceException(
String.format(
"Wrong trace id when creating a span. Got %s, expected %s",
span.getContext().getTraceId(), rootSpan.getContext().getTraceId()));
}
final Continuation continuation = new ContinuationImpl(this, span);
inFlightContinuations.add(continuation);
return continuation;
}
@Override
public synchronized void finishSpan(final Span span, final boolean invalid) {
checkTraceFinished("finish span");
if (!inFlightSpans.contains(span)) {
tracer.reportError("Trace doesn't contain continuation to finish: %s, trace: %s", span, this);
return;
}
if (invalid) {
valid = false;
}
inFlightSpans.remove(span);
finishedSpans.add(span);
checkAndWriteTrace();
}
@Override
public synchronized void closeContinuation(
final Continuation continuation, final boolean invalid) {
checkTraceFinished("close continuation");
if (!inFlightContinuations.contains(continuation)) {
tracer.reportError(
"Trace doesn't contain continuation to finish: %s, trace: %s", continuation, this);
return;
}
if (invalid) {
valid = false;
}
inFlightContinuations.remove(continuation);
checkAndWriteTrace();
}
/**
* Helper to check if trace is ready to be written and write it if it is.
*
* <p>Note: This has to be called under object lock.
*/
private void checkAndWriteTrace() {
if (inFlightSpans.isEmpty() && inFlightContinuations.isEmpty()) {
final Writer writer = tracer.getWriter();
writer.incrementTraceCount();
final Trace trace = runInterceptorsBeforeTraceWritten(this);
if (trace != null && tracer.getSampler().sample(trace)) {
writer.write(trace);
}
finished = true;
}
}
/**
* Helper to run interceptor hooks before trace is finished.
*
* <p>Note: This has to be called under object lock.
*/
private Trace runInterceptorsBeforeTraceWritten(Trace trace) {
final List<Interceptor> interceptors = tracer.getInterceptors();
// Run interceptors in 'reverse' order
for (int i = interceptors.size() - 1; i >= 0; i--) {
// TODO: we probably should handle exceptions in interceptors more or less gracefully
trace = interceptors.get(i).beforeTraceWritten(trace);
if (trace == null) {
break;
}
}
return trace;
}
/**
* Helper to check if trace is finished and report an error if it is.
*
* <p>This has to be called under object lock
*
* @param action action to report error with.
*/
private void checkTraceFinished(final String action) {
if (finished) {
tracer.reportError("Cannot %s, trace has already been finished: %s", action, this);
}
}
}

View File

@ -0,0 +1,21 @@
package datadog.trace.tracer;
/** Trace interface that provides additional methods used internally */
interface TraceInternal extends Trace {
/**
* Called by the span to inform trace that span is finished.
*
* @param span span to finish.
* @param invalid true iff span is 'invalid'.
*/
void finishSpan(final Span span, final boolean invalid);
/**
* Called by the continuation to inform trace that span is closed.
*
* @param continuation continuation to close.
* @param invalid true iff span is 'invalid'.
*/
void closeContinuation(final Continuation continuation, final boolean invalid);
}

View File

@ -1,40 +1,110 @@
package datadog.trace.tracer;
import datadog.trace.api.Config;
import datadog.trace.tracer.sampling.AllSampler;
import datadog.trace.tracer.sampling.Sampler;
import datadog.trace.tracer.writer.LoggingWriter;
import datadog.trace.tracer.writer.Writer;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import lombok.extern.slf4j.Slf4j;
/** A Tracer creates {@link Trace}s and holds common settings across traces. */
@Slf4j
public class Tracer {
/** Default service name if none provided on the trace or span */
private final String defaultServiceName = null;
/** Writer is an charge of reporting traces and spans to the desired endpoint */
private final Writer writer = null;
private final Writer writer;
/** Sampler defines the sampling policy in order to reduce the number of traces for instance */
private final Sampler sampler = null;
private final Sampler sampler;
/** Settings for this tracer. */
private final Config config = null;
/** The clock to use for tracing. */
private final Clock clock = null;
private final Config config;
/** Interceptors to be called on certain trace and span events */
private final List<Interceptor> interceptors;
public Tracer() {
this(Config.get());
}
public Tracer(final List<Interceptor> interceptors) {
this(Config.get(), interceptors);
}
public Tracer(final Config config) {
this(config, Collections.<Interceptor>emptyList());
}
public Tracer(final Config config, final List<Interceptor> interceptors) {
// TODO: implement and include "standard" interceptors
this(
config,
new LoggingWriter(),
new AllSampler(),
Collections.unmodifiableList(new ArrayList<>(interceptors)));
}
Tracer(
final Config config,
final Writer writer,
final Sampler sampler,
final List<Interceptor> interceptors) {
this.config = config;
// TODO: we probably need to implement some sort of 'close' method for Tracer
this.writer = writer;
this.sampler = sampler;
this.interceptors = Collections.unmodifiableList(new ArrayList<>(interceptors));
}
/** @return {@link Writer} used by this tracer */
public Writer getWriter() {
return writer;
}
/** @return {@link Sampler} used by this tracer. */
public Sampler getSampler() {
return sampler;
}
/** @return unmodifiable list of trace/span interceptors. */
public List<Interceptor> getInterceptors() {
return interceptors;
}
/** @return service name to use on span by default. */
String getDefaultServiceName() {
return config.getServiceName();
}
/**
* Construct a new trace using this tracer's settings and return the root span.
*
* @return The root span of the new trace.
* @return timestamp for current time. Note: this is mainly useful when there is no 'current'
* trace. If there is 'current' trace already then one should use it to get timestamps.
*/
public Span buildTrace(final SpanContext parentContext) {
return null;
public Timestamp createCurrentTimestamp() {
return new Clock(this).createCurrentTimestamp();
}
/**
* Construct a new trace using this tracer's settings and return the root span.
*
* @param rootSpanStartTimestampNanoseconds Epoch time in nanoseconds when the root span started.
* @param parentContext parent context of a root span in this trace. May be null.
* @return The root span of the new trace.
*/
public Span buildTrace(
final SpanContext parentContext, final long rootSpanStartTimestampNanoseconds) {
return null;
public Span buildTrace(final SpanContext parentContext) {
return buildTrace(parentContext, createCurrentTimestamp());
}
/**
* Construct a new trace using this tracer's settings and return the root span.
*
* @param parentContext parent context of a root span in this trace. May be null.
* @param timestamp root span start timestamp.
* @return The root span of the new trace.
*/
public Span buildTrace(final SpanContext parentContext, final Timestamp timestamp) {
final Trace trace = new TraceImpl(this, parentContext, timestamp);
return trace.getRootSpan();
}
// TODO: doc inject and extract
@ -44,4 +114,25 @@ public class Tracer {
public <T> SpanContext extract(final Object format, final T carrier) {
return null;
}
// TODO: we can move these two into a separate class and move all '*Impl' and '*Internal' classes
// into separate package
// TODO: provide some sort of ratelimiting here to avoid filling up disk space.
/*
Report warning to the log/console. This never throws exception
*/
void reportWarning(final String message, final Object... args) {
final String completeMessage = String.format(message, args);
log.debug(completeMessage);
}
/*
Report error to the log/console. This may throw an exception
*/
void reportError(final String message, final Object... args) {
// TODO: Provide way to do logging or throwing an exception according to config?
final String completeMessage = String.format(message, args);
log.debug(completeMessage);
throw new TraceException(completeMessage);
}
}

View File

@ -0,0 +1,11 @@
package datadog.trace.tracer.sampling;
import datadog.trace.tracer.Trace;
/** Sampler that samples all traces. */
public class AllSampler implements Sampler {
@Override
public boolean sample(final Trace trace) {
return true;
}
}

View File

@ -0,0 +1,29 @@
package datadog.trace.tracer.writer;
import datadog.trace.tracer.Trace;
import lombok.extern.slf4j.Slf4j;
/** Writer implementation that just logs traces as they are being written */
@Slf4j
public class LoggingWriter implements Writer {
@Override
public void write(final Trace trace) {
log.debug("Trace written: {}", trace);
}
@Override
public void incrementTraceCount() {
// Nothing to do here.
}
@Override
public void start() {
// TODO: do we really need this? and if we do - who is responsible for calling this?
log.debug("{} started", getClass().getSimpleName());
}
@Override
public void close() {
log.debug("{} closed", getClass().getSimpleName());
}
}

View File

@ -4,8 +4,13 @@ import datadog.trace.tracer.Trace;
/** A writer sends traces to some place. */
public interface Writer {
/**
* Write a trace represented by the entire list of all the finished spans
* Write a trace represented by the entire list of all the finished spans.
*
* <p>It is up to the tracer to decide if the trace should be written (e.g. for invalid traces).
*
* <p>This call doesn't increment trace counter, see {@code incrementTraceCount} for that
*
* @param trace the trace to write
*/

View File

@ -0,0 +1,53 @@
package datadog.trace.tracer
import nl.jqno.equalsverifier.EqualsVerifier
import nl.jqno.equalsverifier.Warning
import spock.lang.Shared
import spock.lang.Specification
import java.util.concurrent.TimeUnit
class ClockTest extends Specification {
// Assume it takes less than a minute to run this test
public static final long MINUTE = TimeUnit.MINUTES.toNanos(1)
@Shared
def tracer = Mock(Tracer)
def "test getters"() {
setup:
def currentTimeNano = TimeUnit.MILLISECONDS.toNanos(System.currentTimeMillis())
def nanoTicks = System.nanoTime()
when:
def clock = new Clock(tracer)
then:
clock.getTracer() == tracer
clock.getStartTimeNano() - currentTimeNano <= MINUTE
clock.getStartNanoTicks() - nanoTicks <= MINUTE
clock.epochTimeNano() - currentTimeNano <= MINUTE
TimeUnit.MICROSECONDS.toNanos(clock.epochTimeMicro()) - currentTimeNano <= MINUTE
clock.nanoTicks() - nanoTicks <= MINUTE
}
def "test timestamp creation"() {
setup:
def clock = new Clock(tracer)
when:
def timestamp = clock.createCurrentTimestamp()
then:
timestamp.getClock() == clock
}
def "test equals"() {
when:
EqualsVerifier.forClass(Clock).suppress(Warning.STRICT_INHERITANCE).verify()
then:
noExceptionThrown()
}
}

View File

@ -0,0 +1,93 @@
package datadog.trace.tracer
import spock.lang.Specification
class ContinuationImplTest extends Specification {
def tracer = Mock(Tracer)
def trace = Mock(TraceImpl) {
getTracer() >> tracer
}
def span = Mock(Span)
def "test getters"() {
when:
def continuation = new ContinuationImpl(trace, span)
then:
continuation.getTrace() == trace
continuation.getSpan() == span
}
def "happy lifecycle"() {
when: "continuation is created"
def continuation = new ContinuationImpl(trace, span)
then: "continuation is opened"
!continuation.isClosed()
when: "close continuation"
continuation.close()
then: "continuation is closed and no errors are reported"
continuation.isClosed()
0 * tracer.reportError(*_)
and: "continuation is reported as closed to a trace"
1 * trace.closeContinuation(continuation, false)
when: "continuation is finalized"
continuation.finalize()
then: "continuation is still closed and no errors are reported"
continuation.isClosed()
0 * tracer.reportError(*_)
and: "continuation is not reported as closed to a trace again"
0 * trace.closeContinuation(_, _)
}
def "double close"() {
setup:
def continuation = new ContinuationImpl(trace, span)
when: "close continuation"
continuation.close()
then: "continuation is closed"
continuation.isClosed()
when: "close continuation again"
continuation.close()
then: "error is reported"
1 * tracer.reportError(_, [continuation])
and: "continuation is not reported as closed to a trace again"
0 * trace.closeContinuation(_, _)
}
def "finalize"() {
setup:
def continuation = new ContinuationImpl(trace, span)
when: "finalize continuation"
continuation.finalize()
then: "continuation is closed"
continuation.isClosed()
and: "continuation is reported as closed to a trace"
1 * trace.closeContinuation(continuation, true)
and: "warning is reported"
1 * tracer.reportWarning(_, [continuation])
when: "finalize continuation again"
continuation.finalize()
then: "continuation is still closed"
continuation.isClosed()
and: "continuation is not reported as closed to a trace again"
0 * trace.closeContinuation(_, _)
and: "no error is reported"
0 * tracer.reportError(_, *_)
}
}

View File

@ -0,0 +1,54 @@
package datadog.trace.tracer
import datadog.trace.api.sampling.PrioritySampling
import nl.jqno.equalsverifier.EqualsVerifier
import nl.jqno.equalsverifier.Warning
import spock.lang.Specification
class SpanContextImplTest extends Specification {
def "test getters"() {
when:
def context = new SpanContextImpl("trace id", "parent id", "span id")
then:
context.getTraceId() == "trace id"
context.getParentId() == "parent id"
context.getSpanId() == "span id"
// TODO: this still to be implemented
context.getSamplingFlags() == PrioritySampling.SAMPLER_KEEP
}
def "create from parent"() {
setup:
def parent = new SpanContextImpl("trace id", "parent's parent id", "parent span id")
when:
def context = SpanContextImpl.fromParent(parent)
then:
context.getTraceId() == "trace id"
context.getParentId() == "parent span id"
context.getSpanId() ==~ /\d+/
}
def "create from no parent"() {
when:
def context = SpanContextImpl.fromParent(null)
then:
context.getTraceId() ==~ /\d+/
context.getParentId() == SpanContextImpl.ZERO
context.getSpanId() ==~ /\d+/
}
def "test equals"() {
when:
EqualsVerifier.forClass(SpanContextImpl).suppress(Warning.STRICT_INHERITANCE).verify()
then:
noExceptionThrown()
}
}

View File

@ -0,0 +1,280 @@
package datadog.trace.tracer
import datadog.trace.api.DDTags
import spock.lang.Specification
class SpanImplTest extends Specification {
private static final String SERVICE_NAME = "service.name"
private static final String PARENT_TRACE_ID = "trace id"
private static final String PARENT_SPAN_ID = "span id"
private static final long DURATION = 321
def interceptors = [Mock(name: "interceptor-1", Interceptor), Mock(name: "interceptor-2", Interceptor)]
def tracer = Mock(Tracer) {
getDefaultServiceName() >> SERVICE_NAME
getInterceptors() >> interceptors
}
def parentContext = Mock(SpanContextImpl) {
getTraceId() >> PARENT_TRACE_ID
getSpanId() >> PARENT_SPAN_ID
}
def startTimestamp = Mock(Timestamp) {
getDuration() >> DURATION
getDuration(_) >> { args -> args[0] + DURATION }
}
def trace = Mock(TraceImpl) {
getTracer() >> tracer
}
def "test setters and default values"() {
when: "create span"
def span = new SpanImpl(trace, parentContext, startTimestamp)
then: "span got created"
span.getTrace() == trace
span.getStartTimestamp() == startTimestamp
span.getDuration() == null
span.getContext().getTraceId() == PARENT_TRACE_ID
span.getContext().getParentId() == PARENT_SPAN_ID
span.getContext().getSpanId() ==~ /\d+/
span.getService() == SERVICE_NAME
span.getResource() == null
span.getType() == null
span.getName() == null
!span.isErrored()
when: "span settings changes"
span.setService("new.service.name")
span.setResource("resource")
span.setType("type")
span.setName("name")
span.setErrored(true)
then: "span fields get updated"
span.getService() == "new.service.name"
span.getResource() == "resource"
span.getType() == "type"
span.getName() == "name"
span.isErrored()
}
def "test setter #setter on finished span"() {
setup: "create span"
def span = new SpanImpl(trace, parentContext, startTimestamp)
span.finish()
when: "call setter on finished span"
span."$setter"(newValue)
then: "error reported"
1 * tracer.reportError(_, {
it[0] == fieldName
it[1] == span
})
and: "value unchanged"
span."$getter"() == oldValue
where:
fieldName | setter | getter | newValue | oldValue
"service" | "setService" | "getService" | "new service" | SERVICE_NAME
"resource" | "setResource" | "getResource" | "new resource" | null
"type" | "setType" | "getType" | "new type" | null
"name" | "setName" | "getName" | "new name" | null
"errored" | "setErrored" | "isErrored" | true | false
}
def "test meta set and remove for #key"() {
when:
def span = new SpanImpl(trace, parentContext, startTimestamp)
then:
span.getMeta(key) == null
when:
span.setMeta(key, value)
then:
span.getMeta(key) == value
when:
span.setMeta(key, value.class.cast(null))
then:
span.getMeta(key) == null
where:
key | value
"string.key" | "string"
"boolean.key" | true
"number.key" | 123
}
def "test meta setter on finished span for #key"() {
setup: "create span"
def span = new SpanImpl(trace, parentContext, startTimestamp)
span.finish()
when: "call setter on finished span"
span.setMeta(key, value)
then: "error reported"
1 * tracer.reportError(_, {
it[0] == "meta value " + key
it[1] == span
})
and: "value unchanged"
span.getMeta(key) == null
where:
key | value
"string.key" | "string"
"boolean.key" | true
"number.key" | 123
}
def "test attachThrowable"() {
setup:
def exception = new RuntimeException("test message")
when:
def span = new SpanImpl(trace, parentContext, startTimestamp)
then:
!span.isErrored()
span.getMeta(DDTags.ERROR_MSG) == null
span.getMeta(DDTags.ERROR_TYPE) == null
span.getMeta(DDTags.ERROR_STACK) == null
when:
span.attachThrowable(exception)
then:
span.isErrored()
span.getMeta(DDTags.ERROR_MSG) == "test message"
span.getMeta(DDTags.ERROR_TYPE) == RuntimeException.getName()
span.getMeta(DDTags.ERROR_STACK) != null
}
def "test attachThrowable on finished span"() {
setup: "create span"
def exception = new RuntimeException("test message")
def span = new SpanImpl(trace, parentContext, startTimestamp)
span.finish()
when: "attach throwable"
span.attachThrowable(exception)
then: "error reported"
1 * tracer.reportError(_, {
it[0] == "throwable"
it[1] == span
})
and: "span unchanged"
!span.isErrored()
span.getMeta(DDTags.ERROR_MSG) == null
span.getMeta(DDTags.ERROR_TYPE) == null
span.getMeta(DDTags.ERROR_STACK) == null
}
def "test no parent"() {
when:
def span = new SpanImpl(trace, null, startTimestamp)
then:
span.getContext().getTraceId() ==~ /\d+/
span.getContext().getParentId() == SpanContextImpl.ZERO
span.getContext().getSpanId() ==~ /\d+/
}
def "test lifecycle '#name'"() {
when: "create span"
def span = new SpanImpl(trace, parentContext, startTimestamp)
then: "interceptors called"
interceptors.each({ interceptor ->
then:
1 * interceptor.afterSpanStarted({
// Apparently invocation verification has to know expected value before 'when' section
// To work around this we just check parent span id
it.getContext().getParentId() == parentContext.getSpanId()
})
0 * interceptor._
})
then:
!span.isFinished()
when: "finish/finalize span"
span."$method"(*methodArgs)
then: "warning is reported"
_ * trace.getTracer() >> tracer
if (finalizeErrorReported) {
1 * tracer.reportWarning(_, span)
}
then: "interceptors called"
interceptors.reverseEach({ interceptor ->
then:
1 * interceptor.beforeSpanFinished({
it == span
it.getDuration() == null // Make sure duration is not set yet
})
0 * interceptor._
})
then: "trace is informed that span is closed"
1 * trace.finishSpan({
it == span
it.getDuration() == expectedDuration
}, finalizeErrorReported)
0 * trace._
span.isFinished()
when: "try to finish span again"
span.finish(*secondFinishCallArgs)
then: "interceptors are not called"
interceptors.each({ interceptor ->
0 * interceptor._
})
and: "trace is not informed"
0 * trace.finishSpan(_, _)
and: "error is reported"
1 * tracer.reportError(_, span)
where:
name | method | methodArgs | expectedDuration | finalizeErrorReported | secondFinishCallArgs
"happy" | "finish" | [] | DURATION | false | []
"happy" | "finish" | [] | DURATION | false | [222]
"happy with timestamp" | "finish" | [111] | DURATION + 111 | false | [222]
"happy with timestamp" | "finish" | [111] | DURATION + 111 | false | []
// Note: doing GC tests with mocks is nearly impossible because mocks hold all sort of references
// We will do 'real' GC test as part of integration testing, this is more of a unit test
"finalized" | "finalize" | [] | DURATION | true | []
"finalized" | "finalize" | [] | DURATION | true | [222]
}
def "finished span GCed without errors"() {
setup: "create span"
def span = new SpanImpl(trace, parentContext, startTimestamp)
when: "finish span"
span.finish()
then:
span.isFinished()
0 * tracer.reportError(_, *_)
when: "finalize span"
span.finalize()
then:
0 * tracer.reportError(_, *_)
}
def "span without timestamp"() {
when:
new SpanImpl(trace, parentContext, null)
then:
thrown TraceException
}
}

View File

@ -0,0 +1,21 @@
package datadog.trace.tracer;
import java.lang.ref.WeakReference;
// TODO: stop copy-pasting this!
public class TestUtils {
public static void awaitGC() {
Object obj = new Object();
final WeakReference<Object> ref = new WeakReference<>(obj);
obj = null;
awaitGC(ref);
}
public static void awaitGC(final WeakReference<?> ref) {
while (ref.get() != null) {
System.gc();
System.runFinalization();
}
}
}

View File

@ -0,0 +1,105 @@
package datadog.trace.tracer
import nl.jqno.equalsverifier.EqualsVerifier
import nl.jqno.equalsverifier.Warning
import spock.lang.Specification
class TimestampTest extends Specification {
private static final long CLOCK_START_TIME = 100
private static final long CLOCK_START_NANO_TICKS = 300
private static final long CLOCK_NANO_TICKS = 500
private static final long FINISH_NANO_TICKS = 600
private static final long FINISH_TIME = 700
def tracer = Mock(Tracer)
def clock = Mock(Clock) {
getTracer() >> tracer
}
def "test getter"() {
when:
def timestamp = new Timestamp(clock)
then:
timestamp.getClock() == clock
}
def "test getDuration with literal finish time"() {
setup:
clock.nanoTicks() >> CLOCK_NANO_TICKS
clock.getStartTimeNano() >> CLOCK_START_TIME
clock.getStartNanoTicks() >> CLOCK_START_NANO_TICKS
def timestamp = new Timestamp(clock)
when:
def duration = timestamp.getDuration(FINISH_TIME)
then:
duration == 400
0 * tracer._
}
def "test getDuration with timestamp '#name'"() {
setup:
clock.nanoTicks() >> startNanoTicks >> finishNanoTicks
def startTimestamp = new Timestamp(clock)
def finishTimestamp = new Timestamp(clock)
when:
def duration = startTimestamp.getDuration(finishTimestamp)
then:
duration == expectedDuration
0 * tracer._
where:
name | startNanoTicks | finishNanoTicks | expectedDuration
'normal' | CLOCK_START_NANO_TICKS | FINISH_NANO_TICKS | FINISH_NANO_TICKS - CLOCK_START_NANO_TICKS
'overflow' | Long.MAX_VALUE - CLOCK_START_NANO_TICKS | Long.MIN_VALUE + FINISH_NANO_TICKS | FINISH_NANO_TICKS + CLOCK_START_NANO_TICKS + 1
}
def "test getDuration with current time"() {
setup:
clock.nanoTicks() >> CLOCK_START_NANO_TICKS >> FINISH_NANO_TICKS
def timestamp = new Timestamp(clock)
when:
def duration = timestamp.getDuration()
then:
duration == FINISH_NANO_TICKS - CLOCK_START_NANO_TICKS
0 * tracer._
}
def "test getDuration with wrong clock"() {
setup:
clock.nanoTicks() >> CLOCK_NANO_TICKS
clock.getStartTimeNano() >> CLOCK_START_TIME
clock.getStartNanoTicks() >> CLOCK_START_NANO_TICKS
def timestamp = new Timestamp(clock)
def otherClock = Mock(Clock) {
getTracer() >> tracer
nanoTicks() >> CLOCK_NANO_TICKS + 400
getStartTimeNano() >> CLOCK_START_TIME + 200
getStartNanoTicks() >> CLOCK_START_NANO_TICKS + 100
}
def finishTimestamp = new Timestamp(otherClock)
when:
def duration = timestamp.getDuration(finishTimestamp)
then:
duration == 500
1 * tracer.reportError(_, clock, otherClock)
}
def "test equals"() {
when:
EqualsVerifier.forClass(Timestamp).suppress(Warning.STRICT_INHERITANCE).verify()
then:
noExceptionThrown()
}
}

View File

@ -0,0 +1,49 @@
package datadog.trace.tracer
import spock.lang.Specification
class TraceExceptionTest extends Specification {
static final MESSAGE = "message"
def "test default constructor"() {
when:
def exception = new TraceException()
then:
exception != null
}
def "test message constructor"() {
when:
def exception = new TraceException(MESSAGE)
then:
exception.getMessage() == MESSAGE
}
def "test cause constructor"() {
setup:
def cause = new RuntimeException()
when:
def exception = new TraceException(cause)
then:
exception.getCause() == cause
}
def "test cause and message constructor"() {
setup:
def cause = new RuntimeException()
when:
def exception = new TraceException(MESSAGE, cause)
then:
exception.getMessage() == MESSAGE
exception.getCause() == cause
}
}

View File

@ -0,0 +1,459 @@
package datadog.trace.tracer
import datadog.trace.tracer.sampling.Sampler
import datadog.trace.tracer.writer.Writer
import spock.lang.Specification
class TraceImplTest extends Specification {
private static final String SERVICE_NAME = "service.name"
private static final String PARENT_TRACE_ID = "trace id"
private static final String PARENT_SPAN_ID = "span id"
def interceptors = [
Mock(name: "interceptor-1", Interceptor) {
beforeTraceWritten(_) >> { args -> args[0] }
},
Mock(name: "interceptor-2", Interceptor) {
beforeTraceWritten(_) >> { args -> args[0] }
}
]
def writer = Mock(Writer)
def sampler = Mock(Sampler) {
sample(_) >> true
}
def tracer = Mock(Tracer) {
getDefaultServiceName() >> SERVICE_NAME
getInterceptors() >> interceptors
getWriter() >> writer
getSampler() >> sampler
}
def parentContext = Mock(SpanContextImpl) {
getTraceId() >> PARENT_TRACE_ID
getSpanId() >> PARENT_SPAN_ID
}
def startTimestamp = Mock(Timestamp)
def "test getters"() {
when:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
then:
trace.getTracer() == tracer
trace.getRootSpan().getTrace() == trace
trace.getRootSpan().getStartTimestamp() == startTimestamp
trace.getRootSpan().getContext().getTraceId() == PARENT_TRACE_ID
trace.getRootSpan().getContext().getParentId() == PARENT_SPAN_ID
trace.isValid()
}
def "test getSpans on unfinished spans"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when:
trace.getSpans()
then:
1 * tracer.reportError(_, trace)
}
def "test timestamp creation"() {
setup:
def newTimestamp = Mock(Timestamp)
def clock = Mock(Clock) {
createCurrentTimestamp() >> newTimestamp
}
startTimestamp.getClock() >> clock
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when:
def createdTimestamp = trace.createCurrentTimestamp()
then:
createdTimestamp == newTimestamp
}
def "finish root span"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "root span is finished"
trace.getRootSpan().finish()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then: "interceptors get called"
interceptors.reverseEach({ interceptor ->
then:
1 * interceptor.beforeTraceWritten(trace) >> trace
})
then: "trace gets sampled"
1 * sampler.sample(trace) >> { true }
then: "trace gets written"
1 * writer.write(trace)
trace.isValid()
trace.getSpans() == [trace.getRootSpan()]
when: "root span is finalized"
trace.getRootSpan().finalize()
then: "nothing happens"
0 * writer.incrementTraceCount()
interceptors.reverseEach({ interceptor ->
0 * interceptor.beforeTraceWritten(_)
})
0 * sampler.sample(_)
0 * writer.write(_)
0 * tracer.reportError(_, *_)
}
def "GC root span"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "root span is finalized"
trace.getRootSpan().finalize()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then: "interceptors get called"
interceptors.reverseEach({ interceptor ->
then:
1 * interceptor.beforeTraceWritten(trace) >> trace
})
then: "trace gets sampled"
1 * sampler.sample(trace) >> { true }
then: "trace gets written"
1 * writer.write(trace)
!trace.isValid()
}
def "finish root span dropped by interceptor"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when:
trace.getRootSpan().finish()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then:
1 * interceptors[1].beforeTraceWritten(trace) >> null
0 * interceptors[0].beforeTraceWritten(_)
0 * sampler.sample(_)
0 * writer.write(_)
}
def "finish root span replaced by interceptor"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def replacementTrace = new TraceImpl(tracer, parentContext, startTimestamp)
when:
trace.getRootSpan().finish()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then:
1 * interceptors[1].beforeTraceWritten(trace) >> replacementTrace
then:
1 * interceptors[0].beforeTraceWritten(replacementTrace) >> replacementTrace
then:
1 * sampler.sample(replacementTrace) >> true
then:
1 * writer.write(replacementTrace)
}
def "finish root span dropped by sampler"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when:
trace.getRootSpan().finish()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then:
1 * sampler.sample(trace) >> false
0 * writer.write(_)
}
def "finish root span and then finish it again by error"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "root span is finished"
trace.getRootSpan().finish()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then: "interceptors get called"
interceptors.reverseEach({ interceptor ->
then:
1 * interceptor.beforeTraceWritten(trace) >> trace
})
then: "trace gets sampled"
1 * sampler.sample(trace) >> { true }
then: "trace gets written"
1 * writer.write(trace)
when: "root span is finalized"
trace.finishSpan(trace.getRootSpan(), false)
then: "error is reported"
interceptors.reverseEach({ interceptor ->
0 * interceptor.beforeTraceWritten(_)
})
0 * sampler.sample(_)
0 * writer.incrementTraceCount()
0 * writer.write(_)
1 * tracer.reportError(_, "finish span", trace)
}
def "create and finish new span"() {
setup:
def newSpanTimestamp = Mock(Timestamp)
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "new span is created"
def span = trace.createSpan(trace.getRootSpan().getContext(), newSpanTimestamp)
then:
span.getTrace() == trace
span.getStartTimestamp() == newSpanTimestamp
span.getContext().getTraceId() == PARENT_TRACE_ID
span.getContext().getParentId() == trace.getRootSpan().getContext().getSpanId()
when: "root span is finished"
trace.getRootSpan().finish()
then: "nothing gets written"
0 * writer.incrementTraceCount()
0 * writer.write(_)
when: "new span is finished"
span.finish()
then: "trace gets written"
1 * writer.incrementTraceCount()
1 * writer.write(trace)
trace.isValid()
trace.getSpans() == [trace.getRootSpan(), span]
}
def "create and finish new span with default timestamp"() {
setup:
def newSpanTimestamp = Mock(Timestamp)
def clock = Mock(Clock) {
createCurrentTimestamp() >> newSpanTimestamp
}
startTimestamp.getClock() >> clock
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "new span is created"
def span = trace.createSpan(trace.getRootSpan().getContext())
then:
span.getTrace() == trace
span.getStartTimestamp() == newSpanTimestamp
span.getContext().getTraceId() == PARENT_TRACE_ID
span.getContext().getParentId() == trace.getRootSpan().getContext().getSpanId()
when: "root span is finished"
trace.getRootSpan().finish()
then: "nothing gets written"
0 * writer.incrementTraceCount()
0 * writer.write(_)
when: "new span is finished"
span.finish()
then: "trace gets written"
1 * writer.incrementTraceCount()
1 * writer.write(trace)
trace.isValid()
trace.getSpans() == [trace.getRootSpan(), span]
}
def "create span on finished trace"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "root span is finished"
trace.getRootSpan().finish()
then: "trace is finished"
trace.getSpans() != []
when: "new span is created"
trace.createSpan(trace.getRootSpan().getContext(), startTimestamp)
then: "error is reported"
1 * tracer.reportError(_, "create span", trace)
}
def "create span and finish it twice"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def span = trace.createSpan(trace.getRootSpan().getContext(), startTimestamp)
when: "new span is created"
span.finish()
trace.finishSpan(span, true)
then: "error is reported"
1 * tracer.reportError(_, span, trace)
}
def "create span with null parent context"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "new span with null parent context is created"
trace.createSpan(null, startTimestamp)
then: "error is reported"
thrown TraceException
}
def "create span with parent context from different trace"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def anotherParentContext = Mock(SpanContextImpl) {
getTraceId() >> "different trace"
getSpanId() >> PARENT_SPAN_ID
}
when: "new span with null parent context is created"
trace.createSpan(anotherParentContext, startTimestamp)
then: "error is reported"
thrown TraceException
}
def "create and close new continuation"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "new continuation is created"
def continuation = trace.createContinuation(trace.getRootSpan())
then:
continuation.getSpan() == trace.getRootSpan()
when: "root span is finished"
trace.getRootSpan().finish()
then: "nothing gets written"
0 * writer.incrementTraceCount()
0 * writer.write(_)
when: "new continuation is closed"
continuation.close()
then: "trace gets written"
1 * writer.incrementTraceCount()
1 * writer.write(trace)
trace.isValid()
trace.getSpans() == [trace.getRootSpan()]
}
def "GC continuation"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def continuation = trace.createContinuation(trace.getRootSpan())
trace.getRootSpan().finish()
when: "continuation finalized"
continuation.finalize()
then: "trace gets counted"
1 * writer.incrementTraceCount()
then: "interceptors get called"
interceptors.reverseEach({ interceptor ->
then:
1 * interceptor.beforeTraceWritten(trace) >> trace
})
then: "trace gets sampled"
1 * sampler.sample(trace) >> { true }
then: "trace gets written"
1 * writer.write(trace)
!trace.isValid()
}
def "create and close new continuation, then close it again"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def continuation = trace.createContinuation(trace.getRootSpan())
continuation.close()
when: "continuation is closed again"
trace.closeContinuation(continuation, true)
then: "error is reported"
1 * tracer.reportError(_, continuation, trace)
}
def "create and close new continuation, then close it in finished trace"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def continuation = trace.createContinuation(trace.getRootSpan())
continuation.close()
trace.getRootSpan().finish()
when: "continuation is closed again"
trace.closeContinuation(continuation, true)
then: "error is reported"
1 * tracer.reportError(_, "close continuation", trace)
}
def "create continuation on finished trace"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "root span is finished"
trace.getRootSpan().finish()
then: "trace is finished"
trace.getSpans() != []
when: "new continuation is created"
trace.createContinuation(trace.getRootSpan())
then: "error is reported"
1 * tracer.reportError(_, "create continuation", trace)
}
def "create continuation with null parent span"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
when: "new continuation with null parent span is created"
trace.createContinuation(null)
then: "error is reported"
thrown TraceException
}
def "create continuation with parent span from another trace"() {
setup:
def trace = new TraceImpl(tracer, parentContext, startTimestamp)
def anotherParentContext = Mock(SpanContextImpl) {
getTraceId() >> "different trace"
getSpanId() >> PARENT_SPAN_ID
}
def anotherParentSpan = Mock(SpanImpl) {
getContext() >> anotherParentContext
}
when: "new continuation from span from another trace is created"
trace.createContinuation(anotherParentSpan)
then: "error is reported"
thrown TraceException
}
}

View File

@ -0,0 +1,215 @@
package datadog.trace.tracer
import datadog.trace.api.Config
import datadog.trace.tracer.sampling.AllSampler
import datadog.trace.tracer.writer.LoggingWriter
import datadog.trace.tracer.writer.Writer
import spock.lang.Shared
import spock.lang.Specification
import java.lang.ref.WeakReference
import java.util.concurrent.TimeUnit
import java.util.concurrent.atomic.AtomicInteger
class TracerTest extends Specification {
@Shared
def config = Config.get()
def testWriter = new TestWriter()
// TODO: add more tests for different config options and interceptors
def "test getters"() {
when:
def tracer = new Tracer(config)
then:
tracer.getWriter() instanceof LoggingWriter
tracer.getSampler() instanceof AllSampler
tracer.getInterceptors() == []
tracer.getDefaultServiceName() == config.getServiceName()
}
def "test create current timestamp"() {
setup:
def tracer = new Tracer(config)
when:
def timestamp = tracer.createCurrentTimestamp()
then:
timestamp.getDuration() <= TimeUnit.MINUTES.toNanos(1) // Assume test takes less than a minute to run
}
def "test trace happy path"() {
setup:
def tracer = new Tracer(config, testWriter, new AllSampler(), [])
when:
def rootSpan = tracer.buildTrace(null)
def continuation = rootSpan.getTrace().createContinuation(rootSpan)
def span = rootSpan.getTrace().createSpan(rootSpan.getContext(), tracer.createCurrentTimestamp())
then:
rootSpan.getService() == config.getServiceName()
when:
rootSpan.finish()
continuation.close()
then:
testWriter.traces == []
when:
span.finish()
then:
testWriter.traces == [rootSpan.getContext().getTraceId()]
testWriter.validity == [true]
rootSpan.getTrace().getSpans() == [rootSpan, span]
testWriter.traceCount.get() == 1
}
def "test inject"() {
//TODO implement this test properly
setup:
def context = Mock(SpanContext)
def tracer = new Tracer(config, testWriter, new AllSampler(), [])
when:
tracer.inject(context, null, null)
then:
noExceptionThrown()
}
def "test extract"() {
//TODO implement this test properly
setup:
def tracer = new Tracer(config, testWriter, new AllSampler(), [])
when:
def context = tracer.extract(null, null)
then:
context == null
}
def testReportError() {
//TODO implement this test properly
setup:
def tracer = new Tracer(config, testWriter, new AllSampler(), [])
when:
tracer.reportError("message %s", 123)
then:
thrown TraceException
}
def "test trace that had a GCed span"() {
setup:
def tracer = new Tracer(config, testWriter, new AllSampler(), [])
when: "trace and spans get created"
def rootSpan = tracer.buildTrace(null)
def traceId = rootSpan.getContext().getTraceId()
def span = rootSpan.getTrace().createSpan(rootSpan.getContext(), tracer.createCurrentTimestamp())
rootSpan.finish()
then: "nothing is written yet"
testWriter.traces == []
when: "remove all references to traces and spans and wait for GC"
span = null
def traceRef = new WeakReference<>(rootSpan.getTrace())
rootSpan = null
TestUtils.awaitGC(traceRef)
then: "invalid trace is written"
testWriter.waitForTraces(1)
testWriter.traces == [traceId]
testWriter.validity == [false]
testWriter.traceCount.get() == 1
}
def "test trace that had a GCed continuation"() {
setup:
def tracer = new Tracer(config, testWriter, new AllSampler(), [])
when: "trace and spans get created"
def rootSpan = tracer.buildTrace(null)
def traceId = rootSpan.getContext().getTraceId()
def continuation = rootSpan.getTrace().createContinuation(rootSpan)
rootSpan.finish()
then: "nothing is written yet"
testWriter.traces == []
when: "remove all references to traces and spans and wait for GC"
continuation = null
def traceRef = new WeakReference<>(rootSpan.getTrace())
rootSpan = null
TestUtils.awaitGC(traceRef)
then: "invalid trace is written"
testWriter.waitForTraces(1)
testWriter.traces == [traceId]
testWriter.validity == [false]
testWriter.traceCount.get() == 1
}
/**
* We cannot use mocks for testing of things related to GC because mocks capture arguments with hardlinks.
* For the same reason this test writer cannot capture complete references to traces in this writer. Instead
* we capture 'strategic' values. Other values have been tested in 'lower level' tests.
*/
static class TestWriter implements Writer {
def traces = new ArrayList<String>()
def validity = new ArrayList<Boolean>()
def traceCount = new AtomicInteger()
@Override
synchronized void write(Trace trace) {
traces.add(trace.getRootSpan().getContext().getTraceId())
validity.add(trace.isValid())
}
@Override
void incrementTraceCount() {
traceCount.incrementAndGet()
}
@Override
void start() {
//nothing to do for now
}
@Override
void close() {
//nothing to do for now
}
/**
* JVM gives very little guarantees for when finalizers are run. {@link WeakReference} documentation
* says that weak reference is set to null first, and then objects are marked as finalizable. Then
* finalization happens asynchronously in separate thread.
* This means that currently we do not have a good way of knowing that all traces have been closed/GCed right
* now and only thing we can do is to bluntly wait.
* In the future we have plans to implement limiting of number of inflight traces - this might provide us with
* better way.
* @param numberOfTraces number of traces to wait for.
*/
void waitForTraces(int numberOfTraces) {
while (true) {
synchronized (this) {
if (traces.size() >= numberOfTraces && validity.size() >= numberOfTraces) {
return
}
}
Thread.sleep(500)
}
}
}
}

View File

@ -0,0 +1,40 @@
package datadog.trace.tracer.writer
import datadog.trace.tracer.Trace
import spock.lang.Shared
import spock.lang.Specification
// TODO: this test set is incomplete, fill it in
class LoggingWriterTest extends Specification {
@Shared
def writer = new LoggingWriter()
def "test start"() {
when:
writer.start()
then:
noExceptionThrown()
}
def "test close"() {
when:
writer.close()
then:
noExceptionThrown()
}
def "test write"() {
setup:
def trace = Mock(Trace)
when:
writer.write(trace)
then:
1 * trace.toString()
}
}