diff --git a/features/dd-sdk-android-trace/api/dd-sdk-android-trace.api b/features/dd-sdk-android-trace/api/dd-sdk-android-trace.api index a034427c65..feaa89a383 100644 --- a/features/dd-sdk-android-trace/api/dd-sdk-android-trace.api +++ b/features/dd-sdk-android-trace/api/dd-sdk-android-trace.api @@ -5954,7 +5954,6 @@ public class com/datadog/trace/core/CoreTracer : com/datadog/trace/bootstrap/ins public fun addTracerReportToFlare (Ljava/util/zip/ZipOutputStream;)V public synthetic fun buildSpan (Ljava/lang/String;Ljava/lang/CharSequence;)Lcom/datadog/trace/bootstrap/instrumentation/api/AgentTracer$SpanBuilder; public fun buildSpan (Ljava/lang/String;Ljava/lang/CharSequence;)Lcom/datadog/trace/core/CoreTracer$CoreSpanBuilder; - public static fun builder ()Lcom/datadog/trace/core/CoreTracer$CoreTracerBuilder; public fun captureSpan (Lcom/datadog/trace/bootstrap/instrumentation/api/AgentSpan;)Lcom/datadog/trace/bootstrap/instrumentation/api/AgentScope$Continuation; public synthetic fun captureTraceConfig ()Lcom/datadog/trace/api/TraceConfig; public fun captureTraceConfig ()Lcom/datadog/trace/core/CoreTracer$ConfigSnapshot; @@ -6028,7 +6027,7 @@ public class com/datadog/trace/core/CoreTracer$CoreSpanBuilder : com/datadog/tra } public class com/datadog/trace/core/CoreTracer$CoreTracerBuilder { - public fun ()V + public fun (Lcom/datadog/android/api/InternalLogger;)V public fun baggageMapping (Ljava/util/Map;)Lcom/datadog/trace/core/CoreTracer$CoreTracerBuilder; public fun build ()Lcom/datadog/trace/core/CoreTracer; public fun config (Lcom/datadog/trace/api/Config;)Lcom/datadog/trace/core/CoreTracer$CoreTracerBuilder; @@ -6053,7 +6052,7 @@ public class com/datadog/trace/core/CoreTracer$CoreTracerBuilder { public class com/datadog/trace/core/DDSpan : com/datadog/trace/api/profiling/TransientProfilingContextHolder, com/datadog/trace/bootstrap/instrumentation/api/AgentSpan, com/datadog/trace/bootstrap/instrumentation/api/AttachableWrapper, com/datadog/trace/core/CoreSpan { public static final field CHECKPOINTED_TAG Ljava/lang/String; - public fun (Ljava/lang/String;JLcom/datadog/trace/core/DDSpanContext;Ljava/util/List;)V + public fun (Ljava/lang/String;JLcom/datadog/trace/core/DDSpanContext;Ljava/util/List;Lcom/datadog/android/api/InternalLogger;)V public fun addLink (Lcom/datadog/trace/bootstrap/instrumentation/api/AgentSpanLink;)V public synthetic fun addThrowable (Ljava/lang/Throwable;)Lcom/datadog/trace/bootstrap/instrumentation/api/AgentSpan; public synthetic fun addThrowable (Ljava/lang/Throwable;)Lcom/datadog/trace/core/CoreSpan; @@ -6359,7 +6358,7 @@ public abstract class com/datadog/trace/core/PendingTraceBuffer : java/lang/Auto public fun ()V public abstract fun close ()V public static fun delaying (Lcom/datadog/trace/api/time/TimeSource;Lcom/datadog/trace/api/Config;Lcom/datadog/trace/core/monitor/HealthMetrics;)Lcom/datadog/trace/core/PendingTraceBuffer; - public static fun discarding ()Lcom/datadog/trace/core/PendingTraceBuffer; + public static fun discarding (Lcom/datadog/android/api/InternalLogger;)Lcom/datadog/trace/core/PendingTraceBuffer; public abstract fun enqueue (Lcom/datadog/trace/core/PendingTraceBuffer$Element;)V public abstract fun flush ()V public fun longRunningSpansEnabled ()Z @@ -6761,8 +6760,8 @@ public class com/datadog/trace/core/propagation/ptags/W3CPTagsCodec { } public final class com/datadog/trace/core/scopemanager/ContinuableScopeManager : com/datadog/trace/bootstrap/instrumentation/api/AgentScopeManager { - public fun (IZZ)V - public fun (IZZLcom/datadog/trace/bootstrap/instrumentation/api/ProfilingContextIntegration;Lcom/datadog/trace/core/monitor/HealthMetrics;)V + public fun (IZZLcom/datadog/android/api/InternalLogger;)V + public fun (IZZLcom/datadog/trace/bootstrap/instrumentation/api/ProfilingContextIntegration;Lcom/datadog/trace/core/monitor/HealthMetrics;Lcom/datadog/android/api/InternalLogger;)V public fun activate (Lcom/datadog/trace/bootstrap/instrumentation/api/AgentSpan;Lcom/datadog/trace/bootstrap/instrumentation/api/ScopeSource;)Lcom/datadog/trace/bootstrap/instrumentation/api/AgentScope; public fun activate (Lcom/datadog/trace/bootstrap/instrumentation/api/AgentSpan;Lcom/datadog/trace/bootstrap/instrumentation/api/ScopeSource;Z)Lcom/datadog/trace/bootstrap/instrumentation/api/AgentScope; public fun activateNext (Lcom/datadog/trace/bootstrap/instrumentation/api/AgentSpan;)Lcom/datadog/trace/bootstrap/instrumentation/api/AgentScope; @@ -6904,8 +6903,36 @@ public final class com/datadog/trace/lambda/ReadFromInputStreamJsonAdapter : com public synthetic fun toJson (Lcom/squareup/moshi/JsonWriter;Ljava/lang/Object;)V } +public class com/datadog/trace/logger/DatadogCoreTracerLogger : com/datadog/trace/logger/Logger { + public fun (Ljava/lang/String;Lcom/datadog/android/api/InternalLogger;)V + public fun debug (Ljava/lang/String;)V + public fun debug (Ljava/lang/String;Ljava/lang/Object;)V + public fun debug (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V + public fun debug (Ljava/lang/String;Ljava/lang/Throwable;)V + public fun debug (Ljava/lang/String;[Ljava/lang/Object;)V + public fun error (Ljava/lang/String;)V + public fun error (Ljava/lang/String;Ljava/lang/Object;)V + public fun error (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V + public fun error (Ljava/lang/String;Ljava/lang/Throwable;)V + public fun error (Ljava/lang/String;[Ljava/lang/Object;)V + public fun info (Ljava/lang/String;)V + public fun info (Ljava/lang/String;Ljava/lang/Object;)V + public fun info (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V + public fun info (Ljava/lang/String;Ljava/lang/Throwable;)V + public fun info (Ljava/lang/String;[Ljava/lang/Object;)V + public fun isDebugEnabled ()Z + public fun isInfoEnabled ()Z + public fun isWarnEnabled ()Z + public fun warn (Ljava/lang/String;)V + public fun warn (Ljava/lang/String;Ljava/lang/Object;)V + public fun warn (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V + public fun warn (Ljava/lang/String;Ljava/lang/Throwable;)V + public fun warn (Ljava/lang/String;[Ljava/lang/Object;)V +} + public abstract interface class com/datadog/trace/logger/ILoggerFactory { public abstract fun getLogger (Ljava/lang/String;)Lcom/datadog/trace/logger/Logger; + public abstract fun getLogger (Ljava/lang/String;Lcom/datadog/android/api/InternalLogger;)Lcom/datadog/trace/logger/Logger; } public abstract interface class com/datadog/trace/logger/Logger { @@ -6920,22 +6947,14 @@ public abstract interface class com/datadog/trace/logger/Logger { public abstract fun error (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V public abstract fun error (Ljava/lang/String;Ljava/lang/Throwable;)V public abstract fun error (Ljava/lang/String;[Ljava/lang/Object;)V - public abstract fun getName ()Ljava/lang/String; public abstract fun info (Ljava/lang/String;)V public abstract fun info (Ljava/lang/String;Ljava/lang/Object;)V public abstract fun info (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V public abstract fun info (Ljava/lang/String;Ljava/lang/Throwable;)V public abstract fun info (Ljava/lang/String;[Ljava/lang/Object;)V public abstract fun isDebugEnabled ()Z - public abstract fun isErrorEnabled ()Z public abstract fun isInfoEnabled ()Z - public abstract fun isTraceEnabled ()Z public abstract fun isWarnEnabled ()Z - public abstract fun trace (Ljava/lang/String;)V - public abstract fun trace (Ljava/lang/String;Ljava/lang/Object;)V - public abstract fun trace (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V - public abstract fun trace (Ljava/lang/String;Ljava/lang/Throwable;)V - public abstract fun trace (Ljava/lang/String;[Ljava/lang/Object;)V public abstract fun warn (Ljava/lang/String;)V public abstract fun warn (Ljava/lang/String;Ljava/lang/Object;)V public abstract fun warn (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V @@ -6948,6 +6967,7 @@ public final class com/datadog/trace/logger/LoggerFactory { public static fun getILoggerFactory ()Lcom/datadog/trace/logger/ILoggerFactory; public static fun getLogger (Ljava/lang/Class;)Lcom/datadog/trace/logger/Logger; public static fun getLogger (Ljava/lang/String;)Lcom/datadog/trace/logger/Logger; + public static fun getLogger (Ljava/lang/String;Lcom/datadog/android/api/InternalLogger;)Lcom/datadog/trace/logger/Logger; } public class com/datadog/trace/logger/NoOpLogger : com/datadog/trace/logger/Logger { @@ -6962,22 +6982,14 @@ public class com/datadog/trace/logger/NoOpLogger : com/datadog/trace/logger/Logg public fun error (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V public fun error (Ljava/lang/String;Ljava/lang/Throwable;)V public fun error (Ljava/lang/String;[Ljava/lang/Object;)V - public fun getName ()Ljava/lang/String; public fun info (Ljava/lang/String;)V public fun info (Ljava/lang/String;Ljava/lang/Object;)V public fun info (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V public fun info (Ljava/lang/String;Ljava/lang/Throwable;)V public fun info (Ljava/lang/String;[Ljava/lang/Object;)V public fun isDebugEnabled ()Z - public fun isErrorEnabled ()Z public fun isInfoEnabled ()Z - public fun isTraceEnabled ()Z public fun isWarnEnabled ()Z - public fun trace (Ljava/lang/String;)V - public fun trace (Ljava/lang/String;Ljava/lang/Object;)V - public fun trace (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V - public fun trace (Ljava/lang/String;Ljava/lang/Throwable;)V - public fun trace (Ljava/lang/String;[Ljava/lang/Object;)V public fun warn (Ljava/lang/String;)V public fun warn (Ljava/lang/String;Ljava/lang/Object;)V public fun warn (Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/CoreTracer.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/CoreTracer.java index fef75d48ae..cc168e984c 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/CoreTracer.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/CoreTracer.java @@ -9,6 +9,9 @@ import static java.util.concurrent.TimeUnit.NANOSECONDS; import static java.util.concurrent.TimeUnit.SECONDS; +import androidx.annotation.VisibleForTesting; + +import com.datadog.android.api.InternalLogger; import com.datadog.trace.api.Config; import com.datadog.trace.api.DDSpanId; import com.datadog.trace.api.DDTraceId; @@ -104,15 +107,12 @@ * reporting, and propagating traces */ public class CoreTracer implements AgentTracer.TracerAPI { - private static final Logger log = LoggerFactory.getLogger(CoreTracer.class); + @VisibleForTesting + final Logger log; // UINT64 max value public static final BigInteger TRACE_ID_MAX = BigInteger.valueOf(2).pow(64).subtract(BigInteger.ONE); - public static CoreTracerBuilder builder() { - return new CoreTracerBuilder(); - } - public static final String LANG_STATSD_TAG = "lang"; public static final String LANG_VERSION_STATSD_TAG = "lang_version"; public static final String LANG_INTERPRETER_STATSD_TAG = "lang_interpreter"; @@ -232,6 +232,8 @@ public static CoreTracerBuilder builder() { private final PropagationTags.Factory propagationTagsFactory; + final InternalLogger internalLogger; + @Override public ConfigSnapshot captureTraceConfig() { return dynamicConfig.captureTraceConfig(); @@ -282,6 +284,7 @@ public static class CoreTracerBuilder { private TimeSource timeSource; private ProfilingContextIntegration profilingContextIntegration = ProfilingContextIntegration.NoOp.INSTANCE; + private InternalLogger internalLogger; private boolean injectBaggageAsTags; public CoreTracerBuilder serviceName(String serviceName) { @@ -370,9 +373,10 @@ public CoreTracerBuilder injectBaggageAsTags(boolean injectBaggageAsTags) { return this; } - public CoreTracerBuilder() { + public CoreTracerBuilder(InternalLogger internalLogger) { // Apply the default values from config. config(Config.get()); + this.internalLogger = internalLogger; } public CoreTracerBuilder withProperties(final Properties properties) { @@ -417,7 +421,8 @@ public CoreTracer build() { instrumentationGateway, timeSource, profilingContextIntegration, - injectBaggageAsTags); + injectBaggageAsTags, + internalLogger); } } @@ -441,7 +446,8 @@ private CoreTracer( final InstrumentationGateway instrumentationGateway, final TimeSource timeSource, final ProfilingContextIntegration profilingContextIntegration, - final boolean injectBaggageAsTags) { + final boolean injectBaggageAsTags, + final InternalLogger internalLogger) { assert localRootSpanTags != null; assert defaultSpanTags != null; @@ -449,6 +455,8 @@ private CoreTracer( assert taggedHeaders != null; assert baggageMapping != null; + this.log = LoggerFactory.getLogger(CoreTracer.class.getSimpleName(), internalLogger); + this.rlLog = new RatelimitedLogger(log, 1, MINUTES); this.timeSource = timeSource == null ? SystemTimeSource.INSTANCE : timeSource; startTimeNano = this.timeSource.getCurrentTimeNanos(); startNanoTicks = this.timeSource.getNanoTicks(); @@ -510,7 +518,8 @@ private CoreTracer( config.isScopeStrictMode(), config.isScopeInheritAsyncPropagation(), profilingContextIntegration, - healthMetrics); + healthMetrics, + internalLogger); } else { this.scopeManager = scopeManager; } @@ -520,7 +529,7 @@ private CoreTracer( this.writer = writer; pendingTraceBuffer = strictTraceWrites - ? PendingTraceBuffer.discarding() + ? PendingTraceBuffer.discarding(internalLogger) : PendingTraceBuffer.delaying( this.timeSource, config, healthMetrics); pendingTraceFactory = @@ -577,6 +586,7 @@ private CoreTracer( } else { this.localRootSpanTags = localRootSpanTags; } + this.internalLogger = internalLogger; } /** @@ -765,7 +775,7 @@ public Timer getTimer() { return timer; } - private final RatelimitedLogger rlLog = new RatelimitedLogger(log, 1, MINUTES); + private final RatelimitedLogger rlLog; /** * We use the sampler to know if the trace has to be reported/written. The sampler is called on @@ -1073,7 +1083,12 @@ public CoreSpanBuilder ignoreActiveSpan() { private DDSpan buildSpan() { addTerminatedContextAsLinks(); - DDSpan span = DDSpan.create(instrumentationName, timestampMicro, buildSpanContext(), links); + DDSpan span = DDSpan.create( + instrumentationName, + timestampMicro, + buildSpanContext(), + links, + tracer.internalLogger); if (span.isLocalRootSpan()) { EndpointTracker tracker = tracer.onRootSpanStarted(span); span.setEndpointTracker(tracker); diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/DDSpan.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/DDSpan.java index 901d87360a..ec891cc5b8 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/DDSpan.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/DDSpan.java @@ -13,6 +13,7 @@ import androidx.annotation.Nullable; import androidx.annotation.VisibleForTesting; +import com.datadog.android.api.InternalLogger; import com.datadog.trace.api.Config; import com.datadog.trace.api.DDSpanId; import com.datadog.trace.api.DDTags; @@ -51,17 +52,16 @@ */ public class DDSpan implements AgentSpan, CoreSpan, TransientProfilingContextHolder, AttachableWrapper { - private static final Logger log = LoggerFactory.getLogger(DDSpan.class); - + private final Logger log; public static final String CHECKPOINTED_TAG = "checkpointed"; static DDSpan create( - final String instrumentationName, - final long timestampMicro, - @NonNull DDSpanContext context, - final List links) { - final DDSpan span = new DDSpan(instrumentationName, timestampMicro, context, links); - log.debug("Started span: {}", span); + final String instrumentationName, + final long timestampMicro, + @NonNull DDSpanContext context, + final List links, + final InternalLogger internalLogger) { + final DDSpan span = new DDSpan(instrumentationName, timestampMicro, context, links, internalLogger); context.getTrace().registerSpan(span); return span; } @@ -128,7 +128,8 @@ public DDSpan( @NonNull String instrumentationName, final long timestampMicro, @NonNull DDSpanContext context, - final List links) { + final List links, + final InternalLogger internalLogger) { this.context = context; this.metrics = SpanMetricRegistry.getInstance().get(instrumentationName); this.metrics.onSpanCreated(); @@ -144,6 +145,8 @@ public DDSpan( } this.links = links == null ? new CopyOnWriteArrayList<>() : new CopyOnWriteArrayList<>(links); + this.log = LoggerFactory.getLogger(DDSpan.class.getSimpleName(), internalLogger); + log.debug("Started span: {}", this); } public boolean isFinished() { diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTrace.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTrace.java index 37ab3ce2b3..c400bf7ffe 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTrace.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTrace.java @@ -47,7 +47,7 @@ */ public class PendingTrace implements AgentTrace, PendingTraceBuffer.Element { - private static final Logger log = LoggerFactory.getLogger(PendingTrace.class); + private final Logger log; static class Factory { private final CoreTracer tracer; @@ -162,6 +162,7 @@ private PendingTrace( this.strictTraceWrites = strictTraceWrites; this.healthMetrics = healthMetrics; this.spans = new ConcurrentLinkedDeque<>(); + this.log = LoggerFactory.getLogger(PendingTrace.class.getSimpleName(), tracer.internalLogger); } CoreTracer getTracer() { diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTraceBuffer.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTraceBuffer.java index 4d09de12df..898c136f5c 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTraceBuffer.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/PendingTraceBuffer.java @@ -4,6 +4,7 @@ import static com.datadog.trace.util.AgentThreadFactory.THREAD_JOIN_TIMOUT_MS; import static com.datadog.trace.util.AgentThreadFactory.newAgentThread; +import com.datadog.android.api.InternalLogger; import com.datadog.trace.api.Config; import com.datadog.trace.api.time.TimeSource; import com.datadog.trace.core.monitor.HealthMetrics; @@ -238,8 +239,11 @@ public DelayingPendingTraceBuffer( } static class DiscardingPendingTraceBuffer extends PendingTraceBuffer { - private static final Logger log = LoggerFactory.getLogger(DiscardingPendingTraceBuffer.class); + private final Logger log; + public DiscardingPendingTraceBuffer(InternalLogger internalLogger) { + log = LoggerFactory.getLogger(DiscardingPendingTraceBuffer.class.getSimpleName(), internalLogger); + } @Override public void start() {} @@ -264,8 +268,8 @@ public static PendingTraceBuffer delaying( BUFFER_SIZE, timeSource, config, healthMetrics); } - public static PendingTraceBuffer discarding() { - return new DiscardingPendingTraceBuffer(); + public static PendingTraceBuffer discarding(InternalLogger internalLogger) { + return new DiscardingPendingTraceBuffer(internalLogger); } public abstract void start(); diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/AbstractContinuation.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/AbstractContinuation.java index 0d93e528e4..307f65fce1 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/AbstractContinuation.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/AbstractContinuation.java @@ -3,6 +3,7 @@ import com.datadog.trace.bootstrap.instrumentation.api.AgentScope; import com.datadog.trace.bootstrap.instrumentation.api.AgentSpan; import com.datadog.trace.bootstrap.instrumentation.api.AgentTrace; +import com.datadog.trace.logger.Logger; /** * This class must not be a nested class of ContinuableScope to avoid an unconstrained chain of @@ -10,25 +11,31 @@ */ abstract class AbstractContinuation implements AgentScope.Continuation { - final ContinuableScopeManager scopeManager; - final AgentSpan spanUnderScope; - final byte source; - final AgentTrace trace; + final ContinuableScopeManager scopeManager; + final AgentSpan spanUnderScope; + final byte source; + final AgentTrace trace; - public AbstractContinuation( - ContinuableScopeManager scopeManager, AgentSpan spanUnderScope, byte source) { - this.scopeManager = scopeManager; - this.spanUnderScope = spanUnderScope; - this.source = source; - this.trace = spanUnderScope.context().getTrace(); - } + protected final Logger logger; - AbstractContinuation register() { - trace.registerContinuation(this); - return this; - } + public AbstractContinuation( + ContinuableScopeManager scopeManager, + AgentSpan spanUnderScope, + byte source, + Logger logger) { + this.scopeManager = scopeManager; + this.spanUnderScope = spanUnderScope; + this.source = source; + this.trace = spanUnderScope.context().getTrace(); + this.logger = logger; + } - // Called by ContinuableScopeManager when a continued scope is closed - // Can't use cancel() for SingleContinuation because of the "used" check - abstract void cancelFromContinuedScopeClose(); + AbstractContinuation register() { + trace.registerContinuation(this); + return this; + } + + // Called by ContinuableScopeManager when a continued scope is closed + // Can't use cancel() for SingleContinuation because of the "used" check + abstract void cancelFromContinuedScopeClose(); } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ConcurrentContinuation.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ConcurrentContinuation.java index f9250d45aa..f11397bc52 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ConcurrentContinuation.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ConcurrentContinuation.java @@ -2,6 +2,7 @@ import com.datadog.trace.bootstrap.instrumentation.api.AgentScope; import com.datadog.trace.bootstrap.instrumentation.api.AgentSpan; +import com.datadog.trace.logger.Logger; import java.util.concurrent.atomic.AtomicIntegerFieldUpdater; @@ -15,82 +16,85 @@ * way, and close the scopes without fear of closing the related {@link AgentSpan} prematurely. */ final class ConcurrentContinuation extends AbstractContinuation { - private static final int START = 1; - private static final int CLOSED = Integer.MIN_VALUE >> 1; - private static final int BARRIER = Integer.MIN_VALUE >> 2; - private volatile int count = START; + private static final int START = 1; + private static final int CLOSED = Integer.MIN_VALUE >> 1; + private static final int BARRIER = Integer.MIN_VALUE >> 2; + private volatile int count = START; - private static final AtomicIntegerFieldUpdater COUNT = - AtomicIntegerFieldUpdater.newUpdater(ConcurrentContinuation.class, "count"); + private static final AtomicIntegerFieldUpdater COUNT = + AtomicIntegerFieldUpdater.newUpdater(ConcurrentContinuation.class, "count"); - public ConcurrentContinuation( - ContinuableScopeManager scopeManager, AgentSpan spanUnderScope, byte source) { - super(scopeManager, spanUnderScope, source); - } - - private boolean tryActivate() { - int current = COUNT.incrementAndGet(this); - if (current < START) { - COUNT.decrementAndGet(this); + public ConcurrentContinuation( + ContinuableScopeManager scopeManager, + AgentSpan spanUnderScope, + byte source, + Logger logger) { + super(scopeManager, spanUnderScope, source, logger); } - return current > START; - } - private boolean tryClose() { - int current = COUNT.get(this); - if (current < BARRIER) { - return false; + private boolean tryActivate() { + int current = COUNT.incrementAndGet(this); + if (current < START) { + COUNT.decrementAndGet(this); + } + return current > START; } - // Now decrement the counter - current = COUNT.decrementAndGet(this); - // Try to close this if we are between START and BARRIER - while (current < START && current > BARRIER) { - if (COUNT.compareAndSet(this, current, CLOSED)) { - return true; - } - current = COUNT.get(this); + + private boolean tryClose() { + int current = COUNT.get(this); + if (current < BARRIER) { + return false; + } + // Now decrement the counter + current = COUNT.decrementAndGet(this); + // Try to close this if we are between START and BARRIER + while (current < START && current > BARRIER) { + if (COUNT.compareAndSet(this, current, CLOSED)) { + return true; + } + current = COUNT.get(this); + } + return false; } - return false; - } - @Override - public AgentScope activate() { - if (tryActivate()) { - return scopeManager.continueSpan(this, spanUnderScope, source); - } else { - return null; + @Override + public AgentScope activate() { + if (tryActivate()) { + return scopeManager.continueSpan(this, spanUnderScope, source); + } else { + return null; + } } - } - @Override - public void cancel() { - if (tryClose()) { - trace.cancelContinuation(this); + @Override + public void cancel() { + if (tryClose()) { + trace.cancelContinuation(this); + } + logger.debug( + "t_id={} -> canceling continuation {}", spanUnderScope.getTraceId(), this); } - ContinuableScopeManager.log.debug( - "t_id={} -> canceling continuation {}", spanUnderScope.getTraceId(), this); - } - @Override - public AgentSpan getSpan() { - return spanUnderScope; - } + @Override + public AgentSpan getSpan() { + return spanUnderScope; + } - @Override - void cancelFromContinuedScopeClose() { - cancel(); - } + @Override + void cancelFromContinuedScopeClose() { + cancel(); + } - @Override - public String toString() { - int c = COUNT.get(this); - String s = c < BARRIER ? "CANCELED" : String.valueOf(c); - return getClass().getSimpleName() - + "@" - + Integer.toHexString(hashCode()) - + "(" - + s - + ")->" - + spanUnderScope; - } + @Override + public String toString() { + int c = COUNT.get(this); + String s = c < BARRIER ? "CANCELED" : String.valueOf(c); + return getClass().getSimpleName() + + "@" + + Integer.toHexString(hashCode()) + + "(" + + s + + ")->" + + spanUnderScope; + } } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScope.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScope.java index 1d425070ca..c9a6c26541 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScope.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScope.java @@ -9,6 +9,8 @@ import com.datadog.trace.bootstrap.instrumentation.api.AgentSpan; import com.datadog.trace.bootstrap.instrumentation.api.AttachableWrapper; import com.datadog.trace.bootstrap.instrumentation.api.ScopeSource; +import com.datadog.trace.logger.Logger; +import com.datadog.trace.relocate.api.RatelimitedLogger; import java.util.concurrent.atomic.AtomicReferenceFieldUpdater; @@ -29,18 +31,26 @@ class ContinuableScope implements AgentScope, AttachableWrapper { AtomicReferenceFieldUpdater.newUpdater(ContinuableScope.class, Object.class, "wrapper"); private final Stateful scopeState; + + private final Logger log; + + private final RatelimitedLogger ratelimitedLogger; ContinuableScope( - final ContinuableScopeManager scopeManager, - final AgentSpan span, - final byte source, - final boolean isAsyncPropagating, - final Stateful scopeState) { + final ContinuableScopeManager scopeManager, + final AgentSpan span, + final byte source, + final boolean isAsyncPropagating, + final Stateful scopeState, + final Logger logger, + final RatelimitedLogger ratelimitedLogger) { this.scopeManager = scopeManager; this.span = span; this.flags = source; this.isAsyncPropagating = isAsyncPropagating; this.scopeState = scopeState; + this.log = logger; + this.ratelimitedLogger = ratelimitedLogger; } @Override @@ -49,8 +59,8 @@ public final void close() { // fast check first, only perform slower check when there's an inconsistency with the stack if (!scopeStack.checkTop(this) && !scopeStack.checkOverdueScopes(this)) { - if (ContinuableScopeManager.log.isDebugEnabled()) { - ContinuableScopeManager.log.debug( + if (log.isDebugEnabled()) { + log.debug( "Tried to close {} scope when not on top. Current top: {}", this, scopeStack.top); } @@ -85,7 +95,7 @@ final void onProperClose() { try { listener.afterScopeClosed(); } catch (Exception e) { - ContinuableScopeManager.log.debug("ScopeListener threw exception in close()", e); + log.debug("ScopeListener threw exception in close()", e); } } @@ -93,7 +103,7 @@ final void onProperClose() { try { listener.afterScopeClosed(); } catch (Exception e) { - ContinuableScopeManager.log.debug("ScopeListener threw exception in close()", e); + log.debug("ScopeListener threw exception in close()", e); } } } @@ -139,7 +149,7 @@ public final void setAsyncPropagation(final boolean value) { @Override public final AbstractContinuation capture() { return isAsyncPropagating - ? new SingleContinuation(scopeManager, span, source()).register() + ? new SingleContinuation(scopeManager, span, source(), log).register() : null; } @@ -151,7 +161,7 @@ public final AbstractContinuation capture() { @Override public final AbstractContinuation captureConcurrent() { return isAsyncPropagating - ? new ConcurrentContinuation(scopeManager, span, source()).register() + ? new ConcurrentContinuation(scopeManager, span, source(), log).register() : null; } @@ -164,7 +174,7 @@ public final void beforeActivated() { try { scopeState.activate(span.context()); } catch (Throwable e) { - ContinuableScopeManager.ratelimitedLog.warn( + ratelimitedLogger.warn( "ScopeState {} threw exception in beforeActivated()", scopeState.getClass(), e); } } @@ -174,7 +184,7 @@ public final void afterActivated() { try { listener.afterScopeActivated(); } catch (Throwable e) { - ContinuableScopeManager.log.debug("ScopeListener threw exception in afterActivated()", e); + log.debug("ScopeListener threw exception in afterActivated()", e); } } @@ -186,7 +196,7 @@ public final void afterActivated() { span.context().getSpanId(), span.traceConfig()); } catch (Throwable e) { - ContinuableScopeManager.log.debug( + log.debug( "ExtendedScopeListener threw exception in afterActivated()", e); } } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScopeManager.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScopeManager.java index 028fee89ab..7efa1b378e 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScopeManager.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuableScopeManager.java @@ -2,10 +2,10 @@ import static com.datadog.trace.api.ConfigDefaults.DEFAULT_ASYNC_PROPAGATING; import static com.datadog.trace.bootstrap.instrumentation.api.AgentTracer.NoopAgentSpan; -import static java.util.concurrent.TimeUnit.MINUTES; import static java.util.concurrent.TimeUnit.NANOSECONDS; import static java.util.concurrent.TimeUnit.SECONDS; +import com.datadog.android.api.InternalLogger; import com.datadog.trace.api.Config; import com.datadog.trace.api.Stateful; import com.datadog.trace.api.scopemanager.ExtendedScopeListener; @@ -39,347 +39,378 @@ * ScopeInterceptors to provide additional functionality. */ public final class ContinuableScopeManager implements AgentScopeManager { - static final Logger log = LoggerFactory.getLogger(ContinuableScopeManager.class); - static final RatelimitedLogger ratelimitedLog = new RatelimitedLogger(log, 1, MINUTES); - static final long iterationKeepAlive = - SECONDS.toMillis(Config.get().getScopeIterationKeepAlive()); - volatile ConcurrentMap rootIterationScopes; - final List scopeListeners; - final List extendedScopeListeners; - final boolean strictMode; - private final ScopeStackThreadLocal tlsScopeStack; - private final int depthLimit; - private final boolean inheritAsyncPropagation; - final HealthMetrics healthMetrics; - private final ProfilingContextIntegration profilingContextIntegration; - - /** - * Constructor with NOOP Profiling and HealthMetrics implementations. - * - * @param depthLimit The maximum scope depth limit, 0 for unlimited. - * @param strictMode Whether check if the closed spans are the active ones or not. - * @param inheritAsyncPropagation Whether the next span should inherit the active span - * asyncPropagation flag. - */ - public ContinuableScopeManager( - final int depthLimit, final boolean strictMode, final boolean inheritAsyncPropagation) { - this( - depthLimit, - strictMode, - inheritAsyncPropagation, - ProfilingContextIntegration.NoOp.INSTANCE, - HealthMetrics.NO_OP); - } - - /** - * Default constructor. - * - * @param depthLimit The maximum scope depth limit, 0 for unlimited. - * @param strictMode Whether check if the closed spans are the active ones or not. - * @param inheritAsyncPropagation Whether the next span should inherit the active span - * asyncPropagation flag. - */ - public ContinuableScopeManager( - final int depthLimit, - final boolean strictMode, - final boolean inheritAsyncPropagation, - final ProfilingContextIntegration profilingContextIntegration, - final HealthMetrics healthMetrics) { - this.depthLimit = depthLimit == 0 ? Integer.MAX_VALUE : depthLimit; - this.strictMode = strictMode; - this.inheritAsyncPropagation = inheritAsyncPropagation; - this.scopeListeners = new CopyOnWriteArrayList<>(); - this.extendedScopeListeners = new CopyOnWriteArrayList<>(); - this.healthMetrics = healthMetrics; - this.tlsScopeStack = new ScopeStackThreadLocal(profilingContextIntegration); - this.profilingContextIntegration = profilingContextIntegration; - } - - @Override - public AgentScope activate(final AgentSpan span, final ScopeSource source) { - return activate(span, source.id(), false, /* ignored */ false); - } - - @Override - public AgentScope activate( - final AgentSpan span, final ScopeSource source, boolean isAsyncPropagating) { - return activate(span, source.id(), true, isAsyncPropagating); - } - - @Override - public AgentScope.Continuation captureSpan(final AgentSpan span) { - AbstractContinuation continuation = - new SingleContinuation(this, span, ScopeSource.INSTRUMENTATION.id()); - continuation.register(); - healthMetrics.onCaptureContinuation(); - return continuation; - } - - private AgentScope activate( - final AgentSpan span, - final byte source, - final boolean overrideAsyncPropagation, - final boolean isAsyncPropagating) { - ScopeStack scopeStack = scopeStack(); - - final ContinuableScope top = scopeStack.top; - if (top != null && top.span.equals(span)) { - top.incrementReferences(); - return top; - } + private final Logger log; + private final RatelimitedLogger ratelimitedLogger; + static final long iterationKeepAlive = + SECONDS.toMillis(Config.get().getScopeIterationKeepAlive()); + volatile ConcurrentMap rootIterationScopes; + final List scopeListeners; + final List extendedScopeListeners; + final boolean strictMode; + private final ScopeStackThreadLocal tlsScopeStack; + private final int depthLimit; + private final boolean inheritAsyncPropagation; + final HealthMetrics healthMetrics; + private final ProfilingContextIntegration profilingContextIntegration; - // DQH - This check could go before the check above, since depth limit checking is fast - final int currentDepth = scopeStack.depth(); - if (depthLimit <= currentDepth) { - healthMetrics.onScopeStackOverflow(); - log.debug("Scope depth limit exceeded ({}). Returning NoopScope.", currentDepth); - return AgentTracer.NoopAgentScope.INSTANCE; + /** + * Constructor with NOOP Profiling and HealthMetrics implementations. + * + * @param depthLimit The maximum scope depth limit, 0 for unlimited. + * @param strictMode Whether check if the closed spans are the active ones or not. + * @param inheritAsyncPropagation Whether the next span should inherit the active span + * asyncPropagation flag. + */ + public ContinuableScopeManager( + final int depthLimit, final boolean strictMode, final boolean inheritAsyncPropagation, + final InternalLogger internalLogger) { + this(depthLimit, + strictMode, + inheritAsyncPropagation, + ProfilingContextIntegration.NoOp.INSTANCE, + HealthMetrics.NO_OP, + internalLogger); } - assert span != null; - - // Inherit the async propagation from the active scope unless the value is overridden - boolean asyncPropagation = - overrideAsyncPropagation - ? isAsyncPropagating - : inheritAsyncPropagation && top != null - ? top.isAsyncPropagating() - : DEFAULT_ASYNC_PROPAGATING; - - final ContinuableScope scope = - new ContinuableScope(this, span, source, asyncPropagation, createScopeState(span)); - scopeStack.push(scope); - healthMetrics.onActivateScope(); - - return scope; - } - - /** - * Activates a scope for the given {@link AbstractContinuation}. - * - * @param continuation {@code null} if a continuation is re-used - */ - ContinuableScope continueSpan( - final AbstractContinuation continuation, final AgentSpan span, final byte source) { - ScopeStack scopeStack = scopeStack(); - - // optimization: if the top scope is already keeping the same span alive - // then re-use that scope (avoids allocation) and cancel the continuation - final ContinuableScope top = scopeStack.top; - if (top != null && top.span.equals(span)) { - top.incrementReferences(); - if (continuation != null) { - continuation.cancelFromContinuedScopeClose(); - } - return top; + /** + * Default constructor. + * + * @param depthLimit The maximum scope depth limit, 0 for unlimited. + * @param strictMode Whether check if the closed spans are the active ones or not. + * @param inheritAsyncPropagation Whether the next span should inherit the active span + * asyncPropagation flag. + */ + public ContinuableScopeManager( + final int depthLimit, + final boolean strictMode, + final boolean inheritAsyncPropagation, + final ProfilingContextIntegration profilingContextIntegration, + final HealthMetrics healthMetrics, + final InternalLogger internalLogger) { + this.depthLimit = depthLimit == 0 ? Integer.MAX_VALUE : depthLimit; + this.strictMode = strictMode; + this.inheritAsyncPropagation = inheritAsyncPropagation; + this.scopeListeners = new CopyOnWriteArrayList<>(); + this.extendedScopeListeners = new CopyOnWriteArrayList<>(); + this.healthMetrics = healthMetrics; + this.profilingContextIntegration = profilingContextIntegration; + this.log = LoggerFactory.getLogger(ContinuableScopeManager.class.getSimpleName(), internalLogger); + this.ratelimitedLogger = new RatelimitedLogger(log, 1, SECONDS); + this.tlsScopeStack = new ScopeStackThreadLocal(profilingContextIntegration, ratelimitedLogger); } - Stateful scopeState = createScopeState(span); - final ContinuableScope scope; - if (continuation != null) { - scope = new ContinuingScope(this, span, source, true, continuation, scopeState); - } else { - scope = new ContinuableScope(this, span, source, true, scopeState); - } - scopeStack.push(scope); - - return scope; - } - - @Override - public void closePrevious(final boolean finishSpan) { - ScopeStack scopeStack = scopeStack(); - - // close any immediately previous iteration scope - final ContinuableScope top = scopeStack.top; - if (top != null && top.source() == ScopeSource.ITERATION.id()) { - if (iterationKeepAlive > 0) { // skip depth check because cancelling is cheap - cancelRootIterationScopeCleanup(scopeStack, top); - } - top.close(); - scopeStack.cleanup(); - if (finishSpan) { - top.span.finishWithEndToEnd(); - healthMetrics.onFinishContinuation(); - } + @Override + public AgentScope activate(final AgentSpan span, final ScopeSource source) { + return activate(span, source.id(), false, /* ignored */ false); } - } - @Override - public AgentScope activateNext(final AgentSpan span) { - ScopeStack scopeStack = scopeStack(); + @Override + public AgentScope activate( + final AgentSpan span, final ScopeSource source, boolean isAsyncPropagating) { + return activate(span, source.id(), true, isAsyncPropagating); + } - final int currentDepth = scopeStack.depth(); - if (depthLimit <= currentDepth) { - healthMetrics.onScopeStackOverflow(); - log.debug("Scope depth limit exceeded ({}). Returning NoopScope.", currentDepth); - return AgentTracer.NoopAgentScope.INSTANCE; + @Override + public AgentScope.Continuation captureSpan(final AgentSpan span) { + AbstractContinuation continuation = + new SingleContinuation(this, span, ScopeSource.INSTRUMENTATION.id(), log); + continuation.register(); + healthMetrics.onCaptureContinuation(); + return continuation; } - assert span != null; + private AgentScope activate( + final AgentSpan span, + final byte source, + final boolean overrideAsyncPropagation, + final boolean isAsyncPropagating) { + ScopeStack scopeStack = scopeStack(); + + final ContinuableScope top = scopeStack.top; + if (top != null && top.span.equals(span)) { + top.incrementReferences(); + return top; + } + + // DQH - This check could go before the check above, since depth limit checking is fast + final int currentDepth = scopeStack.depth(); + if (depthLimit <= currentDepth) { + healthMetrics.onScopeStackOverflow(); + log.debug("Scope depth limit exceeded ({}). Returning NoopScope.", currentDepth); + return AgentTracer.NoopAgentScope.INSTANCE; + } - final ContinuableScope top = scopeStack.top; + assert span != null; - boolean asyncPropagation = - inheritAsyncPropagation && top != null - ? top.isAsyncPropagating() - : DEFAULT_ASYNC_PROPAGATING; + // Inherit the async propagation from the active scope unless the value is overridden + boolean asyncPropagation = + overrideAsyncPropagation + ? isAsyncPropagating + : inheritAsyncPropagation && top != null + ? top.isAsyncPropagating() + : DEFAULT_ASYNC_PROPAGATING; - final ContinuableScope scope = - new ContinuableScope( - this, span, ScopeSource.ITERATION.id(), asyncPropagation, createScopeState(span)); + final ContinuableScope scope = + new ContinuableScope(this, span, source, asyncPropagation, createScopeState(span), log, ratelimitedLogger); + scopeStack.push(scope); + healthMetrics.onActivateScope(); - if (iterationKeepAlive > 0 && currentDepth == 0) { - // no surrounding scope to aid cleanup, so use background task instead - scheduleRootIterationScopeCleanup(scopeStack, scope); + return scope; } - scopeStack.push(scope); - - return scope; - } - - @Override - public AgentScope active() { - return scopeStack().active(); - } - - @Override - public AgentSpan activeSpan() { - final ContinuableScope active = scopeStack().active(); - return active == null ? null : active.span; - } - - /** Attach a listener to scope activation events */ - public void addScopeListener(final ScopeListener listener) { - if (listener instanceof ExtendedScopeListener) { - addExtendedScopeListener((ExtendedScopeListener) listener); - } else { - scopeListeners.add(listener); - log.debug("Added scope listener {}", listener); - AgentSpan activeSpan = activeSpan(); - if (activeSpan != null) { - // Notify the listener about the currently active scope - listener.afterScopeActivated(); - } - } - } - - private void addExtendedScopeListener(final ExtendedScopeListener listener) { - extendedScopeListeners.add(listener); - log.debug("Added scope listener {}", listener); - AgentSpan activeSpan = activeSpan(); - if (activeSpan != null && activeSpan != NoopAgentSpan.INSTANCE) { - // Notify the listener about the currently active scope - listener.afterScopeActivated( - activeSpan.getTraceId(), - activeSpan.getLocalRootSpan().getSpanId(), - activeSpan.context().getSpanId(), - activeSpan.traceConfig()); + /** + * Activates a scope for the given {@link AbstractContinuation}. + * + * @param continuation {@code null} if a continuation is re-used + */ + ContinuableScope continueSpan( + final AbstractContinuation continuation, final AgentSpan span, final byte source) { + ScopeStack scopeStack = scopeStack(); + + // optimization: if the top scope is already keeping the same span alive + // then re-use that scope (avoids allocation) and cancel the continuation + final ContinuableScope top = scopeStack.top; + if (top != null && top.span.equals(span)) { + top.incrementReferences(); + if (continuation != null) { + continuation.cancelFromContinuedScopeClose(); + } + return top; + } + + Stateful scopeState = createScopeState(span); + final ContinuableScope scope; + if (continuation != null) { + scope = new ContinuingScope( + this, + span, + source, + true, + continuation, + scopeState, + log, + ratelimitedLogger); + } else { + scope = new ContinuableScope( + this, + span, + source, + true, + scopeState, + log, + ratelimitedLogger); + } + scopeStack.push(scope); + + return scope; } - } - - private Stateful createScopeState(AgentSpan span) { - // currently this just manages things the profiler has to do per scope, but could be expanded - // to encapsulate other scope lifecycle activities - // FIXME DDSpanContext is always a ProfilerContext anyway... - if (span.context() instanceof ProfilerContext) { - return profilingContextIntegration.newScopeState((ProfilerContext) span.context()); + + @Override + public void closePrevious(final boolean finishSpan) { + ScopeStack scopeStack = scopeStack(); + + // close any immediately previous iteration scope + final ContinuableScope top = scopeStack.top; + if (top != null && top.source() == ScopeSource.ITERATION.id()) { + if (iterationKeepAlive > 0) { // skip depth check because cancelling is cheap + cancelRootIterationScopeCleanup(scopeStack, top); + } + top.close(); + scopeStack.cleanup(); + if (finishSpan) { + top.span.finishWithEndToEnd(); + healthMetrics.onFinishContinuation(); + } + } } - return Stateful.DEFAULT; - } - ScopeStack scopeStack() { - return this.tlsScopeStack.get(); - } + @Override + public AgentScope activateNext(final AgentSpan span) { + ScopeStack scopeStack = scopeStack(); + + final int currentDepth = scopeStack.depth(); + if (depthLimit <= currentDepth) { + healthMetrics.onScopeStackOverflow(); + log.debug("Scope depth limit exceeded ({}). Returning NoopScope.", currentDepth); + return AgentTracer.NoopAgentScope.INSTANCE; + } + + assert span != null; - @Override - public ScopeState newScopeState() { - return new ContinuableScopeState(); - } + final ContinuableScope top = scopeStack.top; - private class ContinuableScopeState implements ScopeState { + boolean asyncPropagation = + inheritAsyncPropagation && top != null + ? top.isAsyncPropagating() + : DEFAULT_ASYNC_PROPAGATING; - private ScopeStack localScopeStack = tlsScopeStack.initialValue(); + final ContinuableScope scope = + new ContinuableScope( + this, + span, + ScopeSource.ITERATION.id(), + asyncPropagation, + createScopeState(span), + log, + ratelimitedLogger); + + if (iterationKeepAlive > 0 && currentDepth == 0) { + // no surrounding scope to aid cleanup, so use background task instead + scheduleRootIterationScopeCleanup(scopeStack, scope); + } + + scopeStack.push(scope); + + return scope; + } @Override - public void activate() { - tlsScopeStack.set(localScopeStack); + public AgentScope active() { + return scopeStack().active(); } @Override - public void fetchFromActive() { - localScopeStack = tlsScopeStack.get(); + public AgentSpan activeSpan() { + final ContinuableScope active = scopeStack().active(); + return active == null ? null : active.span; + } + + /** + * Attach a listener to scope activation events + */ + public void addScopeListener(final ScopeListener listener) { + if (listener instanceof ExtendedScopeListener) { + addExtendedScopeListener((ExtendedScopeListener) listener); + } else { + scopeListeners.add(listener); + log.debug("Added scope listener {}", listener); + AgentSpan activeSpan = activeSpan(); + if (activeSpan != null) { + // Notify the listener about the currently active scope + listener.afterScopeActivated(); + } + } } - } - static final class ScopeStackThreadLocal extends ThreadLocal { + private void addExtendedScopeListener(final ExtendedScopeListener listener) { + extendedScopeListeners.add(listener); + log.debug("Added scope listener {}", listener); + AgentSpan activeSpan = activeSpan(); + if (activeSpan != null && activeSpan != NoopAgentSpan.INSTANCE) { + // Notify the listener about the currently active scope + listener.afterScopeActivated( + activeSpan.getTraceId(), + activeSpan.getLocalRootSpan().getSpanId(), + activeSpan.context().getSpanId(), + activeSpan.traceConfig()); + } + } - private final ProfilingContextIntegration profilingContextIntegration; + private Stateful createScopeState(AgentSpan span) { + // currently this just manages things the profiler has to do per scope, but could be expanded + // to encapsulate other scope lifecycle activities + // FIXME DDSpanContext is always a ProfilerContext anyway... + if (span.context() instanceof ProfilerContext) { + return profilingContextIntegration.newScopeState((ProfilerContext) span.context()); + } + return Stateful.DEFAULT; + } - ScopeStackThreadLocal(ProfilingContextIntegration profilingContextIntegration) { - this.profilingContextIntegration = profilingContextIntegration; + ScopeStack scopeStack() { + return this.tlsScopeStack.get(); } @Override - protected ScopeStack initialValue() { - return new ScopeStack(profilingContextIntegration); + public ScopeState newScopeState() { + return new ContinuableScopeState(); } - } - private void scheduleRootIterationScopeCleanup(ScopeStack scopeStack, ContinuableScope scope) { - if (rootIterationScopes == null) { - synchronized (this) { - if (rootIterationScopes == null) { - rootIterationScopes = new ConcurrentHashMap<>(); - RootIterationCleaner.scheduleFor(rootIterationScopes); + private class ContinuableScopeState implements ScopeState { + + private ScopeStack localScopeStack = tlsScopeStack.initialValue(); + + @Override + public void activate() { + tlsScopeStack.set(localScopeStack); + } + + @Override + public void fetchFromActive() { + localScopeStack = tlsScopeStack.get(); } - } } - rootIterationScopes.put(scopeStack, scope); - } - private void cancelRootIterationScopeCleanup(ScopeStack scopeStack, ContinuableScope scope) { - if (rootIterationScopes != null) { - rootIterationScopes.remove(scopeStack, scope); + static final class ScopeStackThreadLocal extends ThreadLocal { + + private final ProfilingContextIntegration profilingContextIntegration; + + private final RatelimitedLogger ratelimitedLogger; + + ScopeStackThreadLocal(ProfilingContextIntegration profilingContextIntegration, + RatelimitedLogger ratelimitedLogger) { + this.profilingContextIntegration = profilingContextIntegration; + this.ratelimitedLogger = ratelimitedLogger; + } + + @Override + protected ScopeStack initialValue() { + return new ScopeStack(profilingContextIntegration, ratelimitedLogger); + } } - } - - /** - * Background task to clean-up scopes from overdue root iterations that have no surrounding scope. - */ - private static final class RootIterationCleaner - implements AgentTaskScheduler.Task> { - private static final RootIterationCleaner CLEANER = new RootIterationCleaner(); - - public static void scheduleFor(Map rootIterationScopes) { - long period = Math.min(iterationKeepAlive, 10_000); - AgentTaskScheduler.INSTANCE.scheduleAtFixedRate( - CLEANER, rootIterationScopes, iterationKeepAlive, period, TimeUnit.MILLISECONDS); + + private void scheduleRootIterationScopeCleanup(ScopeStack scopeStack, ContinuableScope scope) { + if (rootIterationScopes == null) { + synchronized (this) { + if (rootIterationScopes == null) { + rootIterationScopes = new ConcurrentHashMap<>(); + RootIterationCleaner.scheduleFor(rootIterationScopes); + } + } + } + rootIterationScopes.put(scopeStack, scope); } - @Override - public void run(Map rootIterationScopes) { - Iterator> itr = - rootIterationScopes.entrySet().iterator(); + private void cancelRootIterationScopeCleanup(ScopeStack scopeStack, ContinuableScope scope) { + if (rootIterationScopes != null) { + rootIterationScopes.remove(scopeStack, scope); + } + } + + /** + * Background task to clean-up scopes from overdue root iterations that have no surrounding scope. + */ + private static final class RootIterationCleaner + implements AgentTaskScheduler.Task> { + private static final RootIterationCleaner CLEANER = new RootIterationCleaner(); + + public static void scheduleFor(Map rootIterationScopes) { + long period = Math.min(iterationKeepAlive, 10_000); + AgentTaskScheduler.INSTANCE.scheduleAtFixedRate( + CLEANER, rootIterationScopes, iterationKeepAlive, period, TimeUnit.MILLISECONDS); + } + + @Override + public void run(Map rootIterationScopes) { + Iterator> itr = + rootIterationScopes.entrySet().iterator(); - long cutOff = System.currentTimeMillis() - iterationKeepAlive; + long cutOff = System.currentTimeMillis() - iterationKeepAlive; - while (itr.hasNext()) { - Map.Entry entry = itr.next(); + while (itr.hasNext()) { + Map.Entry entry = itr.next(); - ScopeStack scopeStack = entry.getKey(); - ContinuableScope rootScope = entry.getValue(); + ScopeStack scopeStack = entry.getKey(); + ContinuableScope rootScope = entry.getValue(); - if (!rootScope.alive()) { // no need to track this anymore - itr.remove(); - } else if (NANOSECONDS.toMillis(rootScope.span.getStartTime()) < cutOff) { - // mark scope as overdue to allow cleanup and avoid further spans being attached - scopeStack.overdueRootScope = rootScope; - rootScope.span.finishWithEndToEnd(); - itr.remove(); + if (!rootScope.alive()) { // no need to track this anymore + itr.remove(); + } else if (NANOSECONDS.toMillis(rootScope.span.getStartTime()) < cutOff) { + // mark scope as overdue to allow cleanup and avoid further spans being attached + scopeStack.overdueRootScope = rootScope; + rootScope.span.finishWithEndToEnd(); + itr.remove(); + } + } } - } } - } } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuingScope.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuingScope.java index 44443c0535..8fee40fa43 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuingScope.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ContinuingScope.java @@ -2,19 +2,23 @@ import com.datadog.trace.api.Stateful; import com.datadog.trace.bootstrap.instrumentation.api.AgentSpan; +import com.datadog.trace.logger.Logger; +import com.datadog.trace.relocate.api.RatelimitedLogger; final class ContinuingScope extends ContinuableScope { /** Continuation that created this scope. */ private final AbstractContinuation continuation; ContinuingScope( - final ContinuableScopeManager scopeManager, - final AgentSpan span, - final byte source, - final boolean isAsyncPropagating, - final AbstractContinuation continuation, - final Stateful scopeState) { - super(scopeManager, span, source, isAsyncPropagating, scopeState); + final ContinuableScopeManager scopeManager, + final AgentSpan span, + final byte source, + final boolean isAsyncPropagating, + final AbstractContinuation continuation, + final Stateful scopeState, + final Logger logger, + final RatelimitedLogger ratelimitedLogger) { + super(scopeManager, span, source, isAsyncPropagating, scopeState, logger, ratelimitedLogger); this.continuation = continuation; } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ScopeStack.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ScopeStack.java index a0c69c024c..1e292b8f9f 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ScopeStack.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/ScopeStack.java @@ -2,6 +2,7 @@ import com.datadog.trace.bootstrap.instrumentation.api.ProfilingContextIntegration; import com.datadog.trace.bootstrap.instrumentation.api.ScopeSource; +import com.datadog.trace.relocate.api.RatelimitedLogger; import java.util.ArrayDeque; @@ -19,8 +20,11 @@ final class ScopeStack { // set by background task when a root iteration scope remains unclosed for too long volatile ContinuableScope overdueRootScope; - ScopeStack(ProfilingContextIntegration profilingContextIntegration) { + private final RatelimitedLogger ratelimitedLogger; + + ScopeStack(ProfilingContextIntegration profilingContextIntegration, RatelimitedLogger ratelimitedLogger) { this.profilingContextIntegration = profilingContextIntegration; + this.ratelimitedLogger = ratelimitedLogger; } ContinuableScope active() { @@ -113,7 +117,7 @@ private void onBecomeNonEmpty() { try { profilingContextIntegration.onAttach(); } catch (Throwable e) { - ContinuableScopeManager.ratelimitedLog.warn("Unexpected profiling exception", e); + ratelimitedLogger.warn("Unexpected profiling exception", e); } } @@ -122,7 +126,7 @@ private void onBecomeEmpty() { try { profilingContextIntegration.onDetach(); } catch (Throwable e) { - ContinuableScopeManager.ratelimitedLog.warn("Unexpected profiling exception", e); + ratelimitedLogger.warn("Unexpected profiling exception", e); } } } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/SingleContinuation.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/SingleContinuation.java index 6a091d8444..57b703b629 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/SingleContinuation.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/core/scopemanager/SingleContinuation.java @@ -2,6 +2,7 @@ import com.datadog.trace.bootstrap.instrumentation.api.AgentScope; import com.datadog.trace.bootstrap.instrumentation.api.AgentSpan; +import com.datadog.trace.logger.Logger; import java.util.concurrent.atomic.AtomicIntegerFieldUpdater; @@ -17,8 +18,9 @@ final class SingleContinuation extends AbstractContinuation { SingleContinuation( final ContinuableScopeManager scopeManager, final AgentSpan spanUnderScope, - final byte source) { - super(scopeManager, spanUnderScope, source); + final byte source, + final Logger logger) { + super(scopeManager, spanUnderScope, source, logger); } @Override @@ -26,7 +28,7 @@ public AgentScope activate() { if (USED.compareAndSet(this, 0, 1)) { return scopeManager.continueSpan(this, spanUnderScope, source); } else { - ContinuableScopeManager.log.debug( + logger.debug( "Failed to activate continuation. Reusing a continuation not allowed. Spans may be reported separately."); return scopeManager.continueSpan(null, spanUnderScope, source); } @@ -37,7 +39,7 @@ public void cancel() { if (USED.compareAndSet(this, 0, 1)) { trace.cancelContinuation(this); } else { - ContinuableScopeManager.log.debug("Failed to close continuation {}. Already used.", this); + logger.debug("Failed to close continuation {}. Already used.", this); } } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/DatadogCoreTracerLogger.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/DatadogCoreTracerLogger.java new file mode 100644 index 0000000000..16f6f9a882 --- /dev/null +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/DatadogCoreTracerLogger.java @@ -0,0 +1,300 @@ +/* + * Unless explicitly stated otherwise all files in this repository are licensed under the Apache License Version 2.0. + * This product includes software developed at Datadog (https://www.datadoghq.com/). + * Copyright 2016-Present Datadog, Inc. + */ + +package com.datadog.trace.logger; + + +import com.datadog.android.api.InternalLogger; + +import java.util.Arrays; +import java.util.Locale; + +public class DatadogCoreTracerLogger implements Logger { + + + // region Static + private static final String LEGACY_ARG_PLACEHOLDER = "{}"; + + static String generateLogMessage(String title, final String format, Object... args) { + final String sanitizedFormat = format.replace(LEGACY_ARG_PLACEHOLDER, "%s"); + return String.format(Locale.US, title + ": " + sanitizedFormat, args); + } + + + static String bundleMessageWithTitle(final String title, String message) { + return String.format(Locale.US, "%s: %s", title, message); + } + + // endregion + + private final InternalLogger internalLogger; + + private final String loggerName; + + public DatadogCoreTracerLogger(String loggerName, InternalLogger internalLogger) { + this.internalLogger = internalLogger; + this.loggerName = loggerName; + } + + // region Logger + + @Override + public boolean isDebugEnabled() { + return false; + } + + @Override + public void debug(String msg) { + internalLogger.log( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + () -> bundleMessageWithTitle(loggerName, msg), + null, + false, + null + ); + } + + @Override + public void debug(String format, Object arg) { + internalLogger.log( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + () -> generateLogMessage(loggerName, format, arg), + null, + false, + null + ); + } + + @Override + public void debug(String format, Object arg1, Object arg2) { + internalLogger.log( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + () -> generateLogMessage(loggerName, format, arg1, arg2), + null, + false, + null + ); + } + + @Override + public void debug(String format, Object... arguments) { + internalLogger.log( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + () -> generateLogMessage(loggerName, format, arguments), + null, + false, + null + ); + } + + @Override + public void debug(String msg, Throwable t) { + internalLogger.log( + InternalLogger.Level.DEBUG, + Arrays.asList(InternalLogger.Target.MAINTAINER, InternalLogger.Target.TELEMETRY), + () -> bundleMessageWithTitle(loggerName, msg), + t, + false, + null + ); + } + + @Override + public boolean isInfoEnabled() { + return true; + } + + @Override + public void info(String msg) { + internalLogger.log( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + () -> bundleMessageWithTitle(loggerName, msg), + null, + false, + null + ); + } + + @Override + public void info(String format, Object arg) { + internalLogger.log( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + () -> generateLogMessage(loggerName, format, arg), + null, + false, + null + ); + } + + @Override + public void info(String format, Object arg1, Object arg2) { + internalLogger.log( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + () -> generateLogMessage(loggerName, format, arg1, arg2), + null, + false, + null + ); + } + + @Override + public void info(String format, Object... arguments) { + internalLogger.log( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + () -> generateLogMessage(loggerName, format, arguments), + null, + false, + null + ); + } + + @Override + public void info(String msg, Throwable t) { + internalLogger.log( + InternalLogger.Level.INFO, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> bundleMessageWithTitle(loggerName, msg), + t, + false, + null + ); + } + + @Override + public boolean isWarnEnabled() { + return true; + } + + @Override + public void warn(String msg) { + internalLogger.log( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + () -> bundleMessageWithTitle(loggerName, msg), + null, + false, + null + ); + } + + @Override + public void warn(String format, Object arg) { + internalLogger.log( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + () -> generateLogMessage(loggerName, format, arg), + null, + false, + null + ); + } + + @Override + public void warn(String format, Object arg1, Object arg2) { + internalLogger.log( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + () -> generateLogMessage(loggerName, format, arg1, arg2), + null, + false, + null + ); + } + + @Override + public void warn(String format, Object... arguments) { + internalLogger.log( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + () -> generateLogMessage(loggerName, format, arguments), + null, + false, + null + ); + } + + @Override + public void warn(String msg, Throwable t) { + internalLogger.log( + InternalLogger.Level.WARN, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> bundleMessageWithTitle(loggerName, msg), + t, + false, + null + ); + } + + @Override + public void error(String msg) { + internalLogger.log( + InternalLogger.Level.ERROR, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> bundleMessageWithTitle(loggerName, msg), + null, + false, + null + ); + } + + @Override + public void error(String format, Object arg) { + internalLogger.log( + InternalLogger.Level.ERROR, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> generateLogMessage(loggerName, format, arg), + null, + false, + null + ); + } + + @Override + public void error(String format, Object arg1, Object arg2) { + internalLogger.log( + InternalLogger.Level.ERROR, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> generateLogMessage(loggerName, format, arg1, arg2), + null, + false, + null + ); + } + + @Override + public void error(String format, Object... arguments) { + internalLogger.log( + InternalLogger.Level.ERROR, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> generateLogMessage(loggerName, format, arguments), + null, + false, + null + ); + } + + @Override + public void error(String msg, Throwable t) { + internalLogger.log( + InternalLogger.Level.ERROR, + Arrays.asList(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + () -> bundleMessageWithTitle(loggerName, msg), + t, + false, + null + ); + } + + // endregion +} diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/ILoggerFactory.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/ILoggerFactory.java index e072222e28..9c7636552d 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/ILoggerFactory.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/ILoggerFactory.java @@ -6,7 +6,16 @@ package com.datadog.trace.logger; +import androidx.annotation.NonNull; + +import com.datadog.android.api.InternalLogger; + public interface ILoggerFactory { + @NonNull Logger getLogger(String name); + + @NonNull + Logger getLogger(String name, InternalLogger internalLogger); + } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/Logger.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/Logger.java index 8fa40ae562..32696e1fbc 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/Logger.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/Logger.java @@ -8,16 +8,10 @@ package com.datadog.trace.logger; public interface Logger { public static String ROOT_LOGGER_NAME = "ROOT"; - public String getName(); - public void trace(String msg); - public void trace(String format, Object arg); - public void trace(String format, Object arg1, Object arg2); - public void trace(String format, Object... argArray); - public void trace(String msg, Throwable t); - public boolean isTraceEnabled(); + public boolean isInfoEnabled(); public boolean isWarnEnabled(); - public boolean isErrorEnabled(); + public boolean isDebugEnabled(); public void debug(String msg); public void debug(String format, Object arg); diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/LoggerFactory.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/LoggerFactory.java index 97e17f3e69..339c5dba77 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/LoggerFactory.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/LoggerFactory.java @@ -6,12 +6,22 @@ package com.datadog.trace.logger; +import androidx.annotation.NonNull; + +import com.datadog.android.api.InternalLogger; + public final class LoggerFactory { + @NonNull public static Logger getLogger(String name) { return new NoOpLogger(); } + @NonNull + public static Logger getLogger(String name, InternalLogger internalLogger) { + return new DatadogCoreTracerLogger(name, internalLogger); + } + @NonNull public static Logger getLogger(Class clazz) { return new NoOpLogger(); } @@ -22,6 +32,11 @@ public static ILoggerFactory getILoggerFactory() { public Logger getLogger(String name) { return new NoOpLogger(); } + + @Override + public Logger getLogger(String name, InternalLogger internalLogger) { + return new DatadogCoreTracerLogger(name, internalLogger); + } }; } } diff --git a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/NoOpLogger.java b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/NoOpLogger.java index 73f9454c4b..a99d59808d 100644 --- a/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/NoOpLogger.java +++ b/features/dd-sdk-android-trace/src/main/java/com/datadog/trace/logger/NoOpLogger.java @@ -6,8 +6,6 @@ package com.datadog.trace.logger; - -// TODO: 04/03/2024 https://datadoghq.atlassian.net/browse/RUM-3405 Add a proper implementation here public class NoOpLogger implements Logger { @Override @@ -15,41 +13,6 @@ public boolean isDebugEnabled() { return false; } - @Override - public String getName() { - return ""; - } - - @Override - public boolean isTraceEnabled() { - return false; - } - - @Override - public void trace(String msg) { - - } - - @Override - public void trace(String format, Object arg) { - - } - - @Override - public void trace(String format, Object arg1, Object arg2) { - - } - - @Override - public void trace(String format, Object... argArray) { - - } - - @Override - public void trace(String msg, Throwable t) { - - } - @Override public void debug(String msg) { @@ -135,11 +98,6 @@ public void warn(String msg, Throwable t) { } - @Override - public boolean isErrorEnabled() { - return false; - } - @Override public void error(String msg) { diff --git a/features/dd-sdk-android-trace/src/main/kotlin/com/datadog/android/trace/OtelTracerProvider.kt b/features/dd-sdk-android-trace/src/main/kotlin/com/datadog/android/trace/OtelTracerProvider.kt index 34079345fd..79e116c8bb 100644 --- a/features/dd-sdk-android-trace/src/main/kotlin/com/datadog/android/trace/OtelTracerProvider.kt +++ b/features/dd-sdk-android-trace/src/main/kotlin/com/datadog/android/trace/OtelTracerProvider.kt @@ -134,8 +134,7 @@ class OtelTracerProvider( { TRACING_NOT_ENABLED_ERROR_MESSAGE } ) } - // TODO: RUM-0000 Add a logs handler here maybe - val coreTracer = CoreTracer.CoreTracerBuilder() + val coreTracer = CoreTracer.CoreTracerBuilder(sdkCore.internalLogger) .withProperties(properties()) .serviceName(serviceName) .writer(tracingFeature?.otelDataWriter ?: NoOpOtelWriter()) diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/android/trace/OtelTracerBuilderProviderTest.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/android/trace/OtelTracerBuilderProviderTest.kt index 400cbbbc37..5622dab01c 100644 --- a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/android/trace/OtelTracerBuilderProviderTest.kt +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/android/trace/OtelTracerBuilderProviderTest.kt @@ -16,6 +16,7 @@ import com.datadog.android.trace.utils.verifyLog import com.datadog.android.utils.forge.Configurator import com.datadog.opentelemetry.trace.OtelSpan import com.datadog.opentelemetry.trace.OtelSpanContext +import com.datadog.opentelemetry.trace.OtelTracer import com.datadog.tools.unit.getFieldValue import com.datadog.trace.api.Config import com.datadog.trace.api.config.TracerConfig @@ -421,6 +422,19 @@ internal class OtelTracerBuilderProviderTest { assertThat(agentSpanContext.tags).containsEntry(key, value) } + @Test + fun `M use the internalLogger in the CoreTracer W build`() { + // When + val tracerProvider = testedOtelTracerProviderBuilder + .build() + val tracer = tracerProvider.tracerBuilder(fakeInstrumentationName).build() as OtelTracer + + // Then + val coreTracer: CoreTracer = tracer.getFieldValue("tracer") + val internalLogger: InternalLogger = coreTracer.getFieldValue("internalLogger") + assertThat(internalLogger).isSameAs(mockInternalLogger) + } + // endregion // region Sampling priority diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/CoreTracerTest.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/CoreTracerTest.kt index 311b900b12..503a77b0b8 100644 --- a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/CoreTracerTest.kt +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/CoreTracerTest.kt @@ -18,6 +18,7 @@ import com.datadog.trace.common.sampling.RateByServiceTraceSampler import com.datadog.trace.common.writer.ListWriter import com.datadog.trace.common.writer.NoOpWriter import com.datadog.trace.common.writer.Writer +import com.datadog.trace.logger.DatadogCoreTracerLogger import org.assertj.core.api.Assertions.assertThat import org.junit.jupiter.api.Test import org.junit.jupiter.params.ParameterizedTest @@ -31,12 +32,14 @@ internal class CoreTracerTest : DDCoreSpecification() { @Test fun `verify defaults on tracer`() { // When - val tracer = CoreTracer.builder().build() + val tracer = CoreTracer.CoreTracerBuilder(mockLogger).build() // Then assertThat(tracer.serviceName).isNotEmpty assertThat(tracer.initialSampler).isInstanceOf(RateByServiceTraceSampler::class.java) assertThat(tracer.writer).isInstanceOf(NoOpWriter::class.java) + assertThat(tracer.internalLogger).isSameAs(mockLogger) + assertThat(tracer.log).isInstanceOf(DatadogCoreTracerLogger::class.java) // Tear down tracer.close() diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/DDCoreSpecification.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/DDCoreSpecification.kt index 6a33207adc..faf8888e15 100644 --- a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/DDCoreSpecification.kt +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/DDCoreSpecification.kt @@ -6,6 +6,7 @@ package com.datadog.trace.core +import com.datadog.android.api.InternalLogger import com.datadog.tools.unit.getFieldValue import com.datadog.trace.DDSpecification import com.datadog.trace.api.DDSpanId @@ -19,6 +20,7 @@ import com.datadog.trace.core.propagation.PropagationTags import com.datadog.trace.core.tagprocessor.TagsPostProcessorFactory import org.junit.jupiter.api.AfterEach import org.junit.jupiter.api.BeforeEach +import org.mockito.kotlin.mock internal abstract class DDCoreSpecification : DDSpecification() { @@ -27,6 +29,8 @@ internal abstract class DDCoreSpecification : DDSpecification() { protected val instrumentationName = "test" + protected val mockLogger: InternalLogger = mock() + @BeforeEach override fun setup() { super.setup() @@ -40,7 +44,7 @@ internal abstract class DDCoreSpecification : DDSpecification() { } protected fun tracerBuilder(): CoreTracerBuilder { - val builder = CoreTracer.builder() + val builder = CoreTracerBuilder(mockLogger) return builder.strictTraceWrites(useStrictTraceWrites()) } @@ -101,7 +105,7 @@ internal abstract class DDCoreSpecification : DDSpecification() { true ) - val span = DDSpan.create("test", timestamp, context, null) + val span = DDSpan.create("test", timestamp, context, null, mockLogger) for ((key, value) in tags.entries) { span.setTag(key, value) } diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceBufferTest.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceBufferTest.kt index ae2addae4f..49ebf2be29 100644 --- a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceBufferTest.kt +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceBufferTest.kt @@ -6,6 +6,7 @@ package com.datadog.trace.core +import com.datadog.android.api.InternalLogger import com.datadog.tools.unit.getFieldValue import com.datadog.trace.DDSpecification import com.datadog.trace.api.DDSpanId @@ -35,11 +36,12 @@ import org.mockito.kotlin.whenever @Timeout(5) internal class PendingTraceBufferTest : DDSpecification() { + private val mockInternalLogger: InternalLogger = mock() private val buffer = PendingTraceBuffer.delaying(SystemTimeSource.INSTANCE, mock(), null) private val bufferSpy = spy(buffer) private val tracer = mock() private val traceConfig = mock() - private val scopeManager = ContinuableScopeManager(10, true, true) + private val scopeManager = ContinuableScopeManager(10, true, true, mockInternalLogger) private val factory = PendingTrace.Factory(tracer, bufferSpy, SystemTimeSource.INSTANCE, false, HealthMetrics.NO_OP) private val continuations = mutableListOf() @@ -148,7 +150,7 @@ internal class PendingTraceBufferTest : DDSpecification() { false, PropagationTags.factory().empty() ) - return DDSpan.create("test", 0, context, null) + return DDSpan.create("test", 0, context, null, mockInternalLogger) } private fun PendingTraceBuffer.worker(): Thread { diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceTest.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceTest.kt index e4b3ddba48..38c176da66 100644 --- a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceTest.kt +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/core/PendingTraceTest.kt @@ -216,7 +216,8 @@ internal class PendingTraceTest : PendingTraceTestBase() { false, PropagationTags.factory().empty() ), - null + null, + mockLogger ) } } diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/logger/DatadogCoreTracerLoggerTest.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/logger/DatadogCoreTracerLoggerTest.kt new file mode 100644 index 0000000000..1a52748ef2 --- /dev/null +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/logger/DatadogCoreTracerLoggerTest.kt @@ -0,0 +1,335 @@ +/* + * Unless explicitly stated otherwise all files in this repository are licensed under the Apache License Version 2.0. + * This product includes software developed at Datadog (https://www.datadoghq.com/). + * Copyright 2016-Present Datadog, Inc. + */ + +package com.datadog.trace.logger + +import com.datadog.android.api.InternalLogger +import com.datadog.android.trace.utils.verifyLog +import com.datadog.android.utils.forge.Configurator +import fr.xgouchet.elmyr.Forge +import fr.xgouchet.elmyr.annotation.StringForgery +import fr.xgouchet.elmyr.annotation.StringForgeryType +import fr.xgouchet.elmyr.junit5.ForgeConfiguration +import fr.xgouchet.elmyr.junit5.ForgeExtension +import org.junit.jupiter.api.BeforeEach +import org.junit.jupiter.api.Test +import org.junit.jupiter.api.extension.ExtendWith +import org.junit.jupiter.api.extension.Extensions +import org.mockito.Mock +import org.mockito.junit.jupiter.MockitoExtension +import org.mockito.junit.jupiter.MockitoSettings +import org.mockito.quality.Strictness +import java.util.Locale + +@Extensions( + ExtendWith(MockitoExtension::class), + ExtendWith(ForgeExtension::class) +) +@MockitoSettings(strictness = Strictness.LENIENT) +@ForgeConfiguration(value = Configurator::class) +internal class DatadogCoreTracerLoggerTest { + + private lateinit var testedLogger: DatadogCoreTracerLogger + + @StringForgery + lateinit var fakeMessage: String + + private lateinit var expectedMessage: String + + @StringForgery(StringForgeryType.ALPHABETICAL) + lateinit var fakeLoggerName: String + + @Mock + lateinit var mockInternalLogger: InternalLogger + + private val fakeArg1 = Object() + private val fakeArg2 = Object() + lateinit var fakeArgs: Array + + private lateinit var fakeThrowable: Throwable + + @BeforeEach + fun `set up`(forge: Forge) { + fakeArgs = forge.aList(size = forge.aSmallInt()) { Object() }.toTypedArray() + fakeThrowable = forge.getForgery() + expectedMessage = String.format(Locale.US, "%s: %s", fakeLoggerName, fakeMessage) + testedLogger = + DatadogCoreTracerLogger(fakeLoggerName, mockInternalLogger) + } + + // region debug logs + + @Test + fun `M send a debug log W debug`() { + // When + testedLogger.debug(fakeMessage) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + expectedMessage + ) + } + + @Test + fun `M send a debug log W debug { throwable }`() { + // When + testedLogger.debug(fakeMessage, fakeThrowable) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.DEBUG, + listOf(InternalLogger.Target.MAINTAINER, InternalLogger.Target.TELEMETRY), + expectedMessage, + fakeThrowable + ) + } + + @Test + fun `M send a debug log W debug { arg1, arg2 }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, fakeArg1, fakeArg2) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, fakeArg1, fakeArg2) + + // When + testedLogger.debug(fakeMessageFormat, fakeArg1, fakeArg2) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + expectedMessage + ) + } + + @Test + fun `M send a debug log W debug { array of Args }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, *fakeArgs) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, *fakeArgs) + + // When + testedLogger.debug(fakeMessageFormat, *fakeArgs) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.DEBUG, + InternalLogger.Target.MAINTAINER, + expectedMessage + ) + } + + // endregion + + // region info logs + + @Test + fun `M send an info log W info`() { + // When + testedLogger.info(fakeMessage) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + expectedMessage + ) + } + + @Test + fun `M send an info log W info { throwable }`() { + // When + testedLogger.info(fakeMessage, fakeThrowable) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.INFO, + listOf(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + expectedMessage, + fakeThrowable + ) + } + + @Test + fun `M send an info log W debug { arg1, arg2 }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, fakeArg1, fakeArg2) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, fakeArg1, fakeArg2) + + // When + testedLogger.info(fakeMessageFormat, fakeArg1, fakeArg2) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + expectedMessage + ) + } + + @Test + fun `M send an info log W debug { array of Args }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, *fakeArgs) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, *fakeArgs) + + // When + testedLogger.info(fakeMessageFormat, *fakeArgs) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.INFO, + InternalLogger.Target.USER, + expectedMessage + ) + } + + // endregion + + // region warn logs + + @Test + fun `M send an warn log W warn`() { + // When + testedLogger.warn(fakeMessage) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + expectedMessage + ) + } + + @Test + fun `M send a warn log W warn { throwable }`() { + // When + testedLogger.warn(fakeMessage, fakeThrowable) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.WARN, + listOf(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + expectedMessage, + fakeThrowable + ) + } + + @Test + fun `M send a warn log W warn { arg1, arg2 }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, fakeArg1, fakeArg2) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, fakeArg1, fakeArg2) + + // When + testedLogger.warn(fakeMessageFormat, fakeArg1, fakeArg2) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + expectedMessage + ) + } + + @Test + fun `M send a warn log W warn { array of Args }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, *fakeArgs) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, *fakeArgs) + + // When + testedLogger.warn(fakeMessageFormat, *fakeArgs) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.WARN, + InternalLogger.Target.USER, + expectedMessage + ) + } + + // endregion + + // region error logs + + @Test + fun `M send an error log W error`() { + // When + testedLogger.error(fakeMessage) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.ERROR, + listOf(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + expectedMessage + ) + } + + @Test + fun `M send an error log W error { throwable }`() { + // When + testedLogger.error(fakeMessage, fakeThrowable) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.ERROR, + listOf(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + expectedMessage, + fakeThrowable + ) + } + + @Test + fun `M send an error log W error { arg1, arg2 }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, fakeArg1, fakeArg2) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, fakeArg1, fakeArg2) + + // When + testedLogger.error(fakeMessageFormat, fakeArg1, fakeArg2) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.ERROR, + listOf(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + expectedMessage + ) + } + + @Test + fun `M send an error log W error { array of Args }`(forge: Forge) { + // Given + val fakeMessageFormat = resolveFakeArgsMessageFormat(forge, *fakeArgs) + val expectedMessage = resolveExpectedArgsMessage(fakeMessageFormat, *fakeArgs) + + // When + testedLogger.error(fakeMessageFormat, *fakeArgs) + + // Then + mockInternalLogger.verifyLog( + InternalLogger.Level.ERROR, + listOf(InternalLogger.Target.USER, InternalLogger.Target.TELEMETRY), + expectedMessage + ) + } + + // endregion + + // region Internal + + private fun resolveFakeArgsMessageFormat(forge: Forge, vararg args: Any): String { + return args.joinToString(separator = " ") { forge.anAlphabeticalString() + " {}" } + } + + private fun resolveExpectedArgsMessage(format: String, vararg args: Any): String { + val sanitizedFormat = format.replace("{}", "%s") + return String.format(Locale.US, "$fakeLoggerName: $sanitizedFormat", *args) + } + + // endregion +} diff --git a/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/logger/LoggerFactoryTest.kt b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/logger/LoggerFactoryTest.kt new file mode 100644 index 0000000000..d89464552a --- /dev/null +++ b/features/dd-sdk-android-trace/src/test/kotlin/com/datadog/trace/logger/LoggerFactoryTest.kt @@ -0,0 +1,63 @@ +/* + * Unless explicitly stated otherwise all files in this repository are licensed under the Apache License Version 2.0. + * This product includes software developed at Datadog (https://www.datadoghq.com/). + * Copyright 2016-Present Datadog, Inc. + */ + +package com.datadog.trace.logger + +import com.datadog.android.api.InternalLogger +import com.datadog.android.utils.forge.Configurator +import fr.xgouchet.elmyr.annotation.StringForgery +import fr.xgouchet.elmyr.junit5.ForgeConfiguration +import fr.xgouchet.elmyr.junit5.ForgeExtension +import org.assertj.core.api.Assertions.assertThat +import org.junit.jupiter.api.Test +import org.junit.jupiter.api.extension.ExtendWith +import org.junit.jupiter.api.extension.Extensions +import org.mockito.Mock +import org.mockito.junit.jupiter.MockitoExtension +import org.mockito.junit.jupiter.MockitoSettings +import org.mockito.quality.Strictness + +@Extensions( + ExtendWith(MockitoExtension::class), + ExtendWith(ForgeExtension::class) +) +@MockitoSettings(strictness = Strictness.LENIENT) +@ForgeConfiguration(value = Configurator::class) +internal class LoggerFactoryTest { + + @StringForgery + lateinit var fakeName: String + + @Mock + lateinit var mockInternalLogger: InternalLogger + + @Test + fun `M return NoOpLogger W getLogger { name }`() { + // When + val logger = LoggerFactory.getLogger(fakeName) + + // Then + assertThat(logger).isInstanceOf(NoOpLogger::class.java) + } + + @Test + fun `M return NoOpLogger W getLogger { class }`() { + // When + val logger = LoggerFactory.getLogger(Any::class.java) + + // Then + assertThat(logger).isInstanceOf(NoOpLogger::class.java) + } + + @Test + fun `M return DatadogTracerLogger W getLogger { name, internalLogger }`() { + // When + val logger = LoggerFactory.getLogger(fakeName, mockInternalLogger) + + // Then + assertThat(logger).isInstanceOf(DatadogCoreTracerLogger::class.java) + } +}