diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/DebugLoggingHook.java b/dd-openfeature/src/main/java/com/datadog/openfeature/DebugLoggingHook.java
new file mode 100644
index 00000000000..94f88109e80
--- /dev/null
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/DebugLoggingHook.java
@@ -0,0 +1,246 @@
+package com.datadog.openfeature;
+
+import dev.openfeature.sdk.EvaluationContext;
+import dev.openfeature.sdk.FlagEvaluationDetails;
+import dev.openfeature.sdk.Hook;
+import dev.openfeature.sdk.HookContext;
+import dev.openfeature.sdk.Structure;
+import dev.openfeature.sdk.Value;
+import java.util.Collections;
+import java.util.IdentityHashMap;
+import java.util.Map;
+import java.util.Set;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+/**
+ * Logs the raw outcome of every evaluation, to help onboarding.
+ *
+ * The evaluation context and values are logged as they are, including any personal data they
+ * carry (targeting keys, emails, user attributes), and they are not subject to the observe full
+ * evaluation data consent. The provider therefore registers this hook only when both {@code
+ * DD_TRACE_DEBUG} and the application logger allow DEBUG; do not enable them where application logs
+ * leave a trusted boundary. The error message is the one the application observes: the consent
+ * filter applies to the messages the provider produces. Each logged value is capped at {@value
+ * #MAX_VALUE_LENGTH} characters, not counting the truncation marker, and nested values are rendered
+ * within that budget and a depth limit, whatever their shape.
+ *
+ *
It is not telemetry, so the evaluation telemetry opt-out does not apply. It runs at the
+ * finally stage to report what the application observes, and a logging failure never reaches the
+ * evaluation.
+ */
+final class DebugLoggingHook implements Hook {
+ private static final Logger log = LoggerFactory.getLogger(DebugLoggingHook.class);
+
+ /** The longest rendering of a context or value, so that a large object cannot flood the log. */
+ static final int MAX_VALUE_LENGTH = 1024;
+
+ /**
+ * Tells whether the hook can log.
+ *
+ * @return whether the application logger allows DEBUG for the hook.
+ */
+ static boolean isLoggerEnabled() {
+ try {
+ return log.isDebugEnabled();
+ } catch (final RuntimeException | LinkageError e) {
+ // A failing logging backend must not prevent the provider from working.
+ return false;
+ }
+ }
+
+ /**
+ * Says that raw evaluations are logged. It goes through the logger of the hook, so that enabling
+ * DEBUG for the hook alone, as the provider warning suggests, also shows it.
+ */
+ static void announce() {
+ try {
+ log.info(
+ "DD_TRACE_DEBUG is enabled and DEBUG is enabled for {}: raw evaluation contexts and"
+ + " values, including any personal data in them, are written to the application"
+ + " logs.",
+ DebugLoggingHook.class.getName());
+ } catch (final RuntimeException | LinkageError e) {
+ // A failing logging backend must not prevent the provider from working.
+ }
+ }
+
+ @Override
+ public void finallyAfter(
+ final HookContext ctx,
+ final FlagEvaluationDetails details,
+ final Map hints) {
+ // The hook is registered when the logger allows DEBUG, which an application can change later.
+ if (details == null || !isLoggerEnabled()) {
+ return;
+ }
+ try {
+ final EvaluationContext context = ctx.getCtx();
+ log.debug(
+ "Feature Flagging evaluation: flag={}, context={}, defaultValue={}, value={}, variant={}, reason={}, errorCode={}, errorMessage={}, metadata={}",
+ raw(details.getFlagKey()),
+ raw(context),
+ raw(ctx.getDefaultValue()),
+ raw(details.getValue()),
+ raw(details.getVariant()),
+ raw(details.getReason()),
+ details.getErrorCode(),
+ raw(details.getErrorMessage()),
+ details.getFlagMetadata() == null
+ ? null
+ : raw(details.getFlagMetadata().asUnmodifiableMap()));
+ } catch (final RuntimeException | LinkageError e) {
+ // Application supplied values can fail to format, and a diagnostic must not break the
+ // evaluation.
+ try {
+ log.debug("Feature Flagging evaluation diagnostic unavailable: {}", raw(e.toString()));
+ } catch (final RuntimeException | LinkageError ignored) {
+ // Nothing more can be done.
+ }
+ }
+ }
+
+ /**
+ * Renders a value for the log, within {@link #MAX_VALUE_LENGTH} characters and without trusting
+ * its shape: structures can be user supplied, deeply nested or even refer to themselves.
+ */
+ private static String raw(final Object value) {
+ if (value instanceof Value
+ || value instanceof Structure
+ || value instanceof Map
+ || value instanceof Iterable) {
+ return new Renderer().render(value);
+ }
+ return capped(String.valueOf(value));
+ }
+
+ /** Caps a text, telling how long it was. */
+ private static String capped(final String text) {
+ if (text.length() <= MAX_VALUE_LENGTH) {
+ return text;
+ }
+ // Do not cut a surrogate pair in half.
+ final int end =
+ Character.isHighSurrogate(text.charAt(MAX_VALUE_LENGTH - 1))
+ ? MAX_VALUE_LENGTH - 1
+ : MAX_VALUE_LENGTH;
+ return text.substring(0, end) + "...(truncated, " + text.length() + " characters)";
+ }
+
+ /**
+ * Renders values within a budget, applied while walking them: the work does not grow with the
+ * size of the value: it stops walking a container once the budget is spent. Nesting is limited
+ * and a container already being rendered is not entered again, so a cycle or a very deep value
+ * cannot overflow the stack of the evaluating thread.
+ */
+ private static final class Renderer {
+ private static final int MAX_DEPTH = 8;
+
+ private final StringBuilder out = new StringBuilder();
+ private final Set path = Collections.newSetFromMap(new IdentityHashMap<>());
+ private boolean truncated;
+
+ String render(final Object value) {
+ write(value, 0);
+ if (this.truncated) {
+ final int last = this.out.length() - 1;
+ if (last >= 0 && Character.isHighSurrogate(this.out.charAt(last))) {
+ this.out.setLength(last);
+ }
+ this.out.append("...(truncated)");
+ }
+ return this.out.toString();
+ }
+
+ private void write(final Object value, final int depth) {
+ if (this.truncated) {
+ return;
+ }
+ if (value == null) {
+ text("null");
+ } else if (value instanceof Value
+ || value instanceof Structure
+ || value instanceof Map
+ || value instanceof Iterable) {
+ writeContainer(value, depth);
+ } else {
+ text(String.valueOf(value));
+ }
+ }
+
+ private void writeContainer(final Object container, final int depth) {
+ if (depth > MAX_DEPTH) {
+ text("...");
+ return;
+ }
+ if (!this.path.add(container)) {
+ text("(cycle)");
+ return;
+ }
+ try {
+ if (container instanceof Value) {
+ writeValue((Value) container, depth);
+ } else if (container instanceof Structure) {
+ // A view: the keys and values of an immutable structure are copied on each access.
+ writeEntries(((Structure) container).asUnmodifiableMap(), depth);
+ } else if (container instanceof Map) {
+ writeEntries((Map) container, depth);
+ } else {
+ text("[");
+ boolean first = true;
+ for (final Object element : (Iterable) container) {
+ if (this.truncated) {
+ break;
+ }
+ if (!first) {
+ text(", ");
+ }
+ first = false;
+ write(element, depth + 1);
+ }
+ text("]");
+ }
+ } finally {
+ this.path.remove(container);
+ }
+ }
+
+ private void writeEntries(final Map map, final int depth) {
+ text("{");
+ boolean first = true;
+ for (final Map.Entry entry : map.entrySet()) {
+ if (this.truncated) {
+ break;
+ }
+ if (!first) {
+ text(", ");
+ }
+ first = false;
+ write(entry.getKey(), depth + 1);
+ text("=");
+ write(entry.getValue(), depth + 1);
+ }
+ text("}");
+ }
+
+ /**
+ * Renders what the value wraps. It does not ask {@code isList()} or {@code asList()}: they
+ * check every element of the list, whatever the budget, and a list holding anything else than
+ * values is not one for them.
+ */
+ private void writeValue(final Value value, final int depth) {
+ write(value.asObject(), depth);
+ }
+
+ /** Appends the text, or what fits of it, and gives up on the rest of the value. */
+ private void text(final String text) {
+ final int remaining = MAX_VALUE_LENGTH - this.out.length();
+ if (text.length() > remaining) {
+ this.out.append(text, 0, Math.max(remaining, 0));
+ this.truncated = true;
+ } else {
+ this.out.append(text);
+ }
+ }
+ }
+}
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/ExposureLoggingHook.java b/dd-openfeature/src/main/java/com/datadog/openfeature/ExposureLoggingHook.java
index f0065abc6df..db6eba8a70d 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/ExposureLoggingHook.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/ExposureLoggingHook.java
@@ -47,16 +47,22 @@ public void finallyAfter(
final Map hints) {
try {
if (details == null || details.getErrorCode() != null) {
+ log.trace("Feature Flagging exposure suppressed: evaluation failed or details unavailable");
return;
}
final ImmutableMetadata metadata = details.getFlagMetadata();
if (metadata == null) {
+ log.trace("Feature Flagging exposure suppressed: metadata unavailable");
return;
}
// The ImmutableMetadata getters build a debug message for every absent key.
final Map values = metadata.asUnmodifiableMap();
- if (!Boolean.TRUE.equals(values.get(DO_LOG))
- || !Boolean.FALSE.equals(values.get(EXPOSURE_CACHE_HIT))) {
+ if (!Boolean.TRUE.equals(values.get(DO_LOG))) {
+ log.trace("Feature Flagging exposure suppressed: allocation does not log exposures");
+ return;
+ }
+ if (!Boolean.FALSE.equals(values.get(EXPOSURE_CACHE_HIT))) {
+ log.trace("Feature Flagging exposure suppressed: exposure already recorded");
return;
}
final Object allocationValue = values.get(ALLOCATION_KEY);
@@ -65,11 +71,14 @@ public void finallyAfter(
final String variantKey = details.getVariant();
final EvaluationContext context = ctx == null ? null : ctx.getCtx();
if (allocationKey == null || variantKey == null || context == null) {
+ log.trace(
+ "Feature Flagging exposure suppressed: allocation, variant, or context unavailable");
return;
}
final DDEvaluator evaluator = this.evaluatorSupplier.get();
final ExposureDeduplicationCache cache = evaluator == null ? null : evaluator.exposureCache();
if (cache == null) {
+ log.trace("Feature Flagging exposure suppressed: provider not initialized");
return;
}
final String flag = details.getFlagKey();
@@ -77,9 +86,12 @@ public void finallyAfter(
final Integer serialId = serialValue instanceof Integer ? (Integer) serialValue : null;
// The exposure is recorded even when it is not sent, so exposure hooks get the same
// decisions whether or not exposures go to Datadog.
- if (cache.recordIfChanged(
- flag, context.getTargetingKey(), allocationKey, variantKey, serialId)
- && evaluator.isExposureDeliveryEnabled()) {
+ if (!cache.recordIfChanged(
+ flag, context.getTargetingKey(), allocationKey, variantKey, serialId)) {
+ log.trace("Feature Flagging exposure suppressed: exposure already recorded");
+ } else if (!evaluator.isExposureDeliveryEnabled()) {
+ log.trace("Feature Flagging exposure suppressed: Datadog exposure delivery is disabled");
+ } else {
evaluator.recordExposure(
DDEvaluator.exposureEvent(
flag,
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/Provider.java b/dd-openfeature/src/main/java/com/datadog/openfeature/Provider.java
index e3ac093b7ad..70ac3436b8c 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/Provider.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/Provider.java
@@ -102,7 +102,7 @@ public Provider(final Options options) {
// Precompute the immutable hook list once so getProviderHooks() (called on every evaluation)
// allocates nothing, including when the gate is off.
- final List hooks = new ArrayList<>(4);
+ final List hooks = new ArrayList<>(5);
if (flagEvalMetricsHook != null) {
hooks.add(flagEvalMetricsHook);
}
@@ -117,6 +117,20 @@ public Provider(final Options options) {
hooks.set(i, new EvaluationTelemetryOptOutHook(hooks.get(i)));
}
}
+ // Local debug diagnostics are not telemetry, so the opt-out does not apply to them.
+ if (this.settings.isTraceDebug()) {
+ if (DebugLoggingHook.isLoggerEnabled()) {
+ hooks.add(new DebugLoggingHook<>());
+ DebugLoggingHook.announce();
+ } else {
+ // DD_TRACE_DEBUG cannot raise the application's logger levels, so name the second gate.
+ log.warn(
+ "DD_TRACE_DEBUG is enabled, but DEBUG is disabled for {} in the application's logging"
+ + " configuration; evaluation debug diagnostics are off. Enable DEBUG for that"
+ + " category before constructing the Provider.",
+ DebugLoggingHook.class.getName());
+ }
+ }
// Exposure hook: always registered last, and independent of evaluation telemetry opt-out; no-op
// when the evaluator is not a Datadog one or is
// not initialized.
@@ -136,21 +150,29 @@ public Provider(final Options options) {
@Override
public void initialize(final EvaluationContext context) throws Exception {
initializationState.set(InitializationState.INITIALIZING);
+ debug(
+ "Feature Flagging provider initializing: timeout={} {}",
+ options.getTimeout(),
+ options.getUnit());
try {
evaluator = buildEvaluator();
if (!evaluator.initialize(options.getTimeout(), options.getUnit(), context)) {
if (markInitialConfigReceivedReady()) {
+ debug("Feature Flagging provider ready: configuration received during initialization");
return;
}
markInitializationError();
+ debug("Feature Flagging provider initialization timed out waiting for configuration");
throw new ProviderNotReadyError(
"Provider timed-out while waiting for initial configuration");
}
if (!evaluator.hasConfiguration() || !markSuccessfulInitializationReady()) {
markInitializationError();
+ debug("Feature Flagging provider initialization timed out waiting for configuration");
throw new ProviderNotReadyError(
"Provider timed-out while waiting for initial configuration");
}
+ debug("Feature Flagging provider ready");
} catch (final RemoteConfigurationUnavailableException e) {
// No RC connector means no configuration can arrive in this JVM. Complete registration
// without waiting or switching sources. The evaluator has no runtime/configuration and
@@ -164,11 +186,25 @@ public void initialize(final EvaluationContext context) throws Exception {
throw e;
} catch (final Throwable e) {
markInitializationError();
+ // Only the type: the message of a configuration error can echo a URL with credentials.
+ debug("Feature Flagging provider initialization failed: {}", e.getClass().getName());
throw new FatalError(
"Failed to initialize Datadog Feature Flags provider: " + e.getMessage(), e);
}
}
+ /**
+ * Logs a lifecycle diagnostic. A failing logging backend must not turn a state change into a
+ * failure, such as a successful initialization into an error.
+ */
+ private static void debug(final String message, final Object... arguments) {
+ try {
+ log.debug(message, arguments);
+ } catch (final RuntimeException | LinkageError ignored) {
+ // Nothing more can be done.
+ }
+ }
+
void onConfigurationChange() {
if (evaluator == null || !evaluator.hasConfiguration()) {
onConfigurationUnavailable();
@@ -187,6 +223,7 @@ void onConfigurationChange() {
if (state == InitializationState.ERROR
&& initializationState.compareAndSet(
InitializationState.ERROR, InitializationState.READY)) {
+ debug("Feature Flagging provider recovered: configuration received after an error");
emit(
ProviderEvent.PROVIDER_READY,
ProviderEventDetails.builder().message("Provider ready").build());
@@ -195,6 +232,7 @@ void onConfigurationChange() {
if (initializationState.get() != InitializationState.READY) {
return;
}
+ debug("Feature Flagging provider configuration changed");
emit(
ProviderEvent.PROVIDER_CONFIGURATION_CHANGED,
ProviderEventDetails.builder().message("New configuration received").build());
@@ -208,6 +246,7 @@ private void onConfigurationUnavailable() {
if (!initializationState.compareAndSet(InitializationState.READY, InitializationState.ERROR)) {
return;
}
+ debug("Feature Flagging provider configuration unavailable; evaluations return defaults");
emit(
ProviderEvent.PROVIDER_ERROR,
ProviderEventDetails.builder()
@@ -273,6 +312,8 @@ public void shutdown() {
if (evaluator != null) {
evaluator.shutdown();
}
+ // Logged last: a diagnostic must not get in the way of the cleanup.
+ log.debug("Feature Flagging provider shut down");
}
// Visible for tests: expose whether span enrichment is wired (gate-on) without leaking the impl.
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/FeatureFlagsRuntime.java b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/FeatureFlagsRuntime.java
index 4466e1a53c6..b06f5386133 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/FeatureFlagsRuntime.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/FeatureFlagsRuntime.java
@@ -100,6 +100,7 @@ static FeatureFlagsRuntime create(final AgentBridge bridge, final Settings setti
throw new IllegalStateException("Feature Flags is disabled");
}
final boolean remoteConfig = CONFIGURATION_SOURCE_REMOTE_CONFIG.equals(sourceName);
+ LOGGER.debug("Feature Flags runtime starting: configurationSource={}", sourceName);
final RuntimeServices services = new RuntimeServices(bridge.healthMetrics());
final ConfigurationService source;
final EventTransport transport;
@@ -150,6 +151,11 @@ static FeatureFlagsRuntime create(final AgentBridge bridge, final Settings setti
context,
services)
: null;
+ LOGGER.debug(
+ "Feature Flags event delivery: transport={}, exposures={}, evaluationCounts={}",
+ transport.getClass().getSimpleName(),
+ exposures != null ? "enabled" : "disabled",
+ evaluations != null ? "enabled" : "disabled");
return new FeatureFlagsRuntime(source, exposures, evaluations);
}
@@ -256,6 +262,8 @@ void stop() {
if (this.exposures != null) {
this.exposures.awaitTermination(deadline);
}
+ // Logged last: a diagnostic must not get in the way of the cleanup.
+ LOGGER.debug("Feature Flags runtime stopped");
}
private void onConfiguration(@Nullable final ServerConfiguration configuration) {
@@ -272,6 +280,17 @@ private void onConfiguration(@Nullable final ServerConfiguration configuration)
LOGGER.warn("Feature Flags configuration listener failed", e);
}
}
+ // Logged last: a diagnostic must not keep the configuration from being applied.
+ if (configuration == null) {
+ LOGGER.debug("Feature Flags configuration removed");
+ } else if (LOGGER.isDebugEnabled()) {
+ LOGGER.debug(
+ "Feature Flags configuration applied: flags={}, invalidFlags={}, configurationEnv={}, createdAt={}",
+ configuration.flags == null ? "missing" : configuration.flags.size(),
+ configuration.invalidFlags == null ? 0 : configuration.invalidFlags.size(),
+ configuration.environment == null ? null : configuration.environment.name,
+ configuration.createdAt);
+ }
}
/**
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/config/Settings.java b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/config/Settings.java
index b9dc8a63c0d..aa43f1ab4cf 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/config/Settings.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/config/Settings.java
@@ -38,6 +38,7 @@ public final class Settings {
"feature.flags.exposures.datadog.logging.enabled";
static final String EVALUATION_TELEMETRY_PER_SUBJECT_OPT_OUT_ENABLED =
"feature.flags.evaluation.telemetry.per.subject.opt.out.enabled";
+ static final String TRACE_DEBUG = "trace.debug";
static final String API_KEY = "api-key";
static final String SITE = "site";
static final String ENV = "env";
@@ -174,6 +175,16 @@ public boolean isEvaluationTelemetryPerSubjectOptOutEnabled() {
return Boolean.TRUE.equals(getBoolean(EVALUATION_TELEMETRY_PER_SUBJECT_OPT_OUT_ENABLED));
}
+ /**
+ * Tells whether {@code DD_TRACE_DEBUG} is on. It gates the diagnostics that log raw evaluation
+ * contexts and values, on top of the application's logging configuration.
+ *
+ * @return whether trace debug is enabled (off by default).
+ */
+ public boolean isTraceDebug() {
+ return Boolean.TRUE.equals(getBoolean(TRACE_DEBUG));
+ }
+
/**
* @return the Datadog API key, or {@code null} if not set.
*/
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/CdnConfigurationSource.java b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/CdnConfigurationSource.java
index cfb38849cab..7eed50bb8d2 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/CdnConfigurationSource.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/CdnConfigurationSource.java
@@ -122,6 +122,16 @@ public void start(final Consumer listener) {
TimeUnit.MILLISECONDS);
}
}
+ // Logged last: a diagnostic must not keep the polling from starting.
+ LOGGER.debug(
+ "Feature Flags agentless configuration source started: endpoint={}://{}{}, pollIntervalMillis={}, requestTimeout={}",
+ // The origin only: the userinfo, the path and the query of a custom endpoint can carry a
+ // credential.
+ this.endpoint.getScheme(),
+ this.endpoint.getHost(),
+ this.endpoint.getPort() < 0 ? "" : ":" + this.endpoint.getPort(),
+ this.pollIntervalMillis,
+ this.requestTimeout);
}
@Override
@@ -146,6 +156,8 @@ public void close() {
poll.cancel(true);
}
this.executor.shutdownNow();
+ // Logged last: a diagnostic must not keep the source from being closed.
+ LOGGER.debug("Feature Flags agentless configuration source stopped");
}
/** Test seam: sets the configuration listener without starting the polling. */
@@ -212,6 +224,7 @@ private boolean fetchAndApply() {
private boolean apply(final HttpResponse response) {
final int status = response.statusCode();
if (status == HttpURLConnection.HTTP_NOT_MODIFIED) {
+ LOGGER.debug("Feature Flags agentless configuration unchanged (HTTP 304)");
return true;
}
if (status == HttpURLConnection.HTTP_UNAUTHORIZED
@@ -229,15 +242,21 @@ private boolean apply(final HttpResponse response) {
try {
configuration = UniversalFlagConfigParser.parseJsonApi(Gzip.decode(response));
} catch (final IOException | RuntimeException e) {
- LOGGER.debug("Feature Flags configuration endpoint returned a malformed payload", e);
+ LOGGER.debug(
+ "Feature Flags configuration endpoint returned a malformed payload ({}); retaining the current configuration",
+ e.getClass().getSimpleName(),
+ e);
return false;
}
if (configuration == null) {
+ LOGGER.debug(
+ "Feature Flags configuration endpoint returned no flag data; retaining the current configuration");
return false;
}
this.listener.accept(configuration);
final String nextEtag = response.headers().firstValue("ETag").orElse(null);
this.etag = nextEtag == null || nextEtag.trim().isEmpty() ? null : nextEtag;
+ LOGGER.debug("Feature Flags agentless configuration applied: etag={}", this.etag);
return true;
}
@@ -254,10 +273,20 @@ private HttpResponse fetchWithRetries() throws IOException, InterruptedE
return this.activeCall;
}
},
- (response, attempt) ->
- response == null || isRetryableStatus(response.statusCode())
- ? retryDelayMillis(this.pollIntervalMillis, attempt, this.jitter.getAsDouble())
- : -1,
+ (response, attempt) -> {
+ if (response != null && !isRetryableStatus(response.statusCode())) {
+ return -1;
+ }
+ final long delayMillis =
+ retryDelayMillis(this.pollIntervalMillis, attempt, this.jitter.getAsDouble());
+ LOGGER.debug(
+ "Feature Flags agentless configuration poll attempt {}/{} {}; retrying in {} ms",
+ attempt,
+ MAX_ATTEMPTS,
+ response == null ? "failed" : "returned HTTP " + response.statusCode(),
+ delayMillis);
+ return delayMillis;
+ },
MAX_ATTEMPTS,
this.retrySleeper,
() -> this.closed);
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/RemoteConfigurationService.java b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/RemoteConfigurationService.java
index 63cae4527cb..f0179ab3b81 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/RemoteConfigurationService.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/delivery/RemoteConfigurationService.java
@@ -25,6 +25,7 @@ public synchronized void start(final Consumer listener) {
if (this.subscription != null) {
return;
}
+ LOGGER.debug("Feature Flags subscribing to Remote Configuration");
this.subscription =
this.source.subscribe(
content -> {
@@ -36,7 +37,10 @@ public synchronized void start(final Consumer listener) {
try {
configuration = UniversalFlagConfigParser.parse(content);
} catch (final IOException | RuntimeException e) {
- LOGGER.debug("Remote Configuration returned a malformed flag configuration", e);
+ LOGGER.debug(
+ "Remote Configuration returned a malformed flag configuration ({}); retaining the current configuration",
+ e.getClass().getSimpleName(),
+ e);
return;
}
if (configuration != null) {
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/exposure/ExposurePipeline.java b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/exposure/ExposurePipeline.java
index fb0acac0989..829d74f77d7 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/exposure/ExposurePipeline.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/exposure/ExposurePipeline.java
@@ -11,6 +11,7 @@
import java.util.Map;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicLong;
import java.util.function.Consumer;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@@ -29,6 +30,7 @@ public class ExposurePipeline implements Consumer, EventPipeline
private final Thread serializerThread;
private final Object lifecycleLock = new Object();
private final AtomicBoolean closed = new AtomicBoolean();
+ private final AtomicLong droppedQueueFull = new AtomicLong();
public ExposurePipeline(
final int capacity,
@@ -39,7 +41,8 @@ public ExposurePipeline(
final RuntimeServices services) {
this.queue = new EventQueue<>(capacity);
this.serializer =
- new ExposureSerializingHandler(transport, this.queue, flushInterval, timeUnit, context);
+ new ExposureSerializingHandler(
+ transport, this.queue, flushInterval, timeUnit, context, this.droppedQueueFull);
this.serializerThread = services.newThread("exposures", this.serializer);
}
@@ -56,7 +59,12 @@ public void start() {
public void requestShutdown() {
synchronized (this.lifecycleLock) {
if (this.closed.compareAndSet(false, true)) {
+ final int queued = this.queue.size();
this.serializer.requestShutdown();
+ // Logged last: a diagnostic must not keep the worker from being signaled.
+ LOGGER.debug(
+ "Feature Flags exposure shutdown requested: queued={}; pending exposures get a final best-effort flush",
+ queued);
}
}
}
@@ -68,8 +76,9 @@ public void awaitTermination(final long deadlineNanos) {
@Override
public void accept(final ExposureEvent event) {
- if (!this.closed.get()) {
- this.queue.offer(event);
+ // Runs on the application thread: count the drops, the serializer reports them once per flush.
+ if (!this.closed.get() && !this.queue.offer(event)) {
+ this.droppedQueueFull.incrementAndGet();
}
}
@@ -91,13 +100,16 @@ private static class ExposureSerializingHandler implements Runnable {
private final List buffer = new ArrayList<>();
private final AtomicBoolean shutdownRequested = new AtomicBoolean();
+ private final AtomicLong droppedQueueFull;
ExposureSerializingHandler(
final EventTransport transport,
final EventQueue queue,
final long flushInterval,
final TimeUnit timeUnit,
- final Map context) {
+ final Map context,
+ final AtomicLong droppedQueueFull) {
+ this.droppedQueueFull = droppedQueueFull;
this.queue = queue;
this.transport = transport;
this.context = context;
@@ -163,9 +175,16 @@ protected void flushIfNecessary() {
}
private void flush() {
+ final long dropped = this.droppedQueueFull.getAndSet(0);
+ if (dropped > 0) {
+ LOGGER.debug(
+ "Feature Flags exposures dropped since the last flush: queue full, count={}", dropped);
+ }
if (this.buffer.isEmpty()) {
return;
}
+ final int count = this.buffer.size();
+ LOGGER.debug("Feature Flags exposure flush starting: count={}", count);
final byte[] payload;
try {
final ExposuresRequest exposures = new ExposuresRequest(this.context, this.buffer);
@@ -177,8 +196,13 @@ private void flush() {
}
try {
this.transport.post(EXPOSURES_ROUTE, payload);
+ LOGGER.debug("Feature Flags exposure flush delivered: count={}", count);
} catch (Exception e) {
- LOGGER.debug("Could not submit exposures", e);
+ LOGGER.debug(
+ "Feature Flags exposure flush failed: {}; dropping the batch of {} exposure(s)",
+ e.toString(),
+ count,
+ e);
} finally {
// Best-effort delivery must not retry an ambiguously accepted batch.
this.buffer.clear();
diff --git a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipeline.java b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipeline.java
index 915ce31f61b..af4dfaa2ca3 100644
--- a/dd-openfeature/src/main/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipeline.java
+++ b/dd-openfeature/src/main/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipeline.java
@@ -130,6 +130,8 @@ public void requestShutdown() {
if (closed.compareAndSet(false, true)) {
// The worker polls every 100 ms: do not interrupt a current or final HTTP request.
serializer.requestShutdown();
+ // Logged last: a diagnostic must not keep the worker from being signaled.
+ LOGGER.debug("Feature Flags flag evaluation shutdown requested");
}
}
}
@@ -220,6 +222,10 @@ FlagEvalEvent pollQueuedEventForTest() {
return queue.poll();
}
+ boolean isSerializerThreadAlive() {
+ return serializerThread.isAlive();
+ }
+
/** Test seam: flushes serializer state without starting the worker. */
void flushForTest() {
serializer.flush();
@@ -407,6 +413,10 @@ void flush() {
for (final byte[] payload : payloads.bodies) {
transport.post(FLAG_EVALUATION_ROUTE, payload);
}
+ if (!payloads.bodies.isEmpty()) {
+ LOGGER.debug(
+ "Feature Flags flag evaluation flush delivered: payloads={}", payloads.bodies.size());
+ }
} catch (Exception e) {
LOGGER.error("Could not submit flag evaluations", e);
} finally {
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/DebugLoggingTest.java b/dd-openfeature/src/test/java/com/datadog/openfeature/DebugLoggingTest.java
new file mode 100644
index 00000000000..e09e14df637
--- /dev/null
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/DebugLoggingTest.java
@@ -0,0 +1,626 @@
+package com.datadog.openfeature;
+
+import static java.util.Collections.emptyList;
+import static java.util.Collections.emptyMap;
+import static java.util.Collections.singletonList;
+import static java.util.concurrent.TimeUnit.SECONDS;
+import static org.junit.jupiter.api.Assertions.assertDoesNotThrow;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertFalse;
+import static org.junit.jupiter.api.Assertions.assertThrows;
+import static org.junit.jupiter.api.Assertions.assertTimeoutPreemptively;
+import static org.junit.jupiter.api.Assertions.assertTrue;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
+
+import com.datadog.openfeature.Provider.Options;
+import com.datadog.openfeature.internal.ufc.Allocation;
+import com.datadog.openfeature.internal.ufc.Flag;
+import com.datadog.openfeature.internal.ufc.ServerConfiguration;
+import com.datadog.openfeature.internal.ufc.Split;
+import com.datadog.openfeature.internal.ufc.ValueType;
+import com.datadog.openfeature.internal.ufc.Variant;
+import com.datadog.openfeature.testlog.CapturingServiceProvider;
+import com.datadog.openfeature.testlog.CapturingServiceProvider.Event;
+import dev.openfeature.sdk.Client;
+import dev.openfeature.sdk.EvaluationContext;
+import dev.openfeature.sdk.FlagEvaluationDetails;
+import dev.openfeature.sdk.FlagValueType;
+import dev.openfeature.sdk.HookContext;
+import dev.openfeature.sdk.ImmutableContext;
+import dev.openfeature.sdk.MutableContext;
+import dev.openfeature.sdk.MutableStructure;
+import dev.openfeature.sdk.OpenFeatureAPI;
+import dev.openfeature.sdk.Structure;
+import dev.openfeature.sdk.Value;
+import java.time.Duration;
+import java.util.AbstractList;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.Collections;
+import java.util.HashMap;
+import java.util.IdentityHashMap;
+import java.util.Iterator;
+import java.util.List;
+import java.util.Map;
+import java.util.stream.Collectors;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.slf4j.event.Level;
+
+class DebugLoggingTest {
+ private static final String TRACE_DEBUG = "dd.trace.debug";
+ private static final String AGENTLESS_BASE_URL =
+ "dd.feature.flags.configuration.source.agentless.base.url";
+
+ private static final String SDK_LOGGERS = "com.datadog.openfeature";
+
+ @BeforeEach
+ void captureLogs() {
+ CapturingServiceProvider.reset();
+ CapturingServiceProvider.enable(SDK_LOGGERS, Level.DEBUG);
+ }
+
+ @AfterEach
+ void restore() {
+ System.clearProperty(TRACE_DEBUG);
+ System.clearProperty(AGENTLESS_BASE_URL);
+ OpenFeatureAPI.getInstance().clearHooks();
+ OpenFeatureAPI.getInstance().shutdown();
+ CapturingServiceProvider.reset();
+ }
+
+ @Test
+ void logsTheRawEvaluationWhenTraceDebugIsOn() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+
+ client.getIntegerValue("flag", 5, new MutableContext("user-1").add("plan", "pro"));
+
+ final String message = singleMessage("Feature Flagging evaluation:");
+ assertTrue(message.contains("flag=flag"), message);
+ assertTrue(message.contains("targetingKey=user-1"), message);
+ assertTrue(message.contains("plan=pro"), message);
+ assertTrue(message.contains("defaultValue=5"), message);
+ assertTrue(message.contains("value=1"), message);
+ assertTrue(message.contains("variant=on"), message);
+ assertTrue(message.contains("reason=STATIC"), message);
+ assertEquals(
+ Level.DEBUG,
+ CapturingServiceProvider.events().stream()
+ .filter(e -> e.message.equals(message))
+ .findFirst()
+ .get()
+ .level);
+ }
+
+ @Test
+ void logsTheErrorOfAnEvaluation() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+
+ client.getIntegerValue("missing", 5, new MutableContext("user-1"));
+
+ final String message = singleMessage("Feature Flagging evaluation:");
+ assertTrue(message.contains("flag=missing"), message);
+ assertTrue(message.contains("errorCode=FLAG_NOT_FOUND"), message);
+ }
+
+ @Test
+ void doesNotLogRawEvaluationsWithoutTraceDebug() throws Exception {
+ // Explicit, so that a DD_TRACE_DEBUG in the environment of the test JVM does not matter.
+ System.setProperty(TRACE_DEBUG, "false");
+ final Client client = register();
+
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+
+ assertTrue(messages("Feature Flagging evaluation:").isEmpty());
+ }
+
+ @Test
+ void warnsWhenTraceDebugIsOnButTheLoggerDoesNotAllowDebug() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ CapturingServiceProvider.enable(DebugLoggingHook.class.getName(), Level.INFO);
+ final Client client = register();
+
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+
+ assertTrue(messages("Feature Flagging evaluation:").isEmpty());
+ final List warnings =
+ CapturingServiceProvider.events().stream()
+ .filter(e -> e.level == Level.WARN)
+ .filter(e -> e.message.contains("DD_TRACE_DEBUG is enabled"))
+ .collect(Collectors.toList());
+ assertEquals(1, warnings.size());
+ }
+
+ @Test
+ void stopsLoggingRawEvaluationsWhenTheLoggerIsLoweredAfterRegistration() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+ assertEquals(1, messages("Feature Flagging evaluation:").size());
+
+ CapturingServiceProvider.enable(DebugLoggingHook.class.getName(), Level.INFO);
+ client.getIntegerValue("flag", 5, new MutableContext("user-2"));
+
+ assertEquals(1, messages("Feature Flagging evaluation:").size());
+ }
+
+ @Test
+ void announcesThatRawEvaluationsAreLoggedWhenTheHookIsRegistered() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ register();
+
+ final List announcements =
+ CapturingServiceProvider.events().stream()
+ .filter(e -> e.message.contains("personal data"))
+ .collect(Collectors.toList());
+ assertEquals(1, announcements.size(), announcements.toString());
+ assertEquals(Level.INFO, announcements.get(0).level);
+ }
+
+ @Test
+ void announcesThroughTheLoggerOfTheHookAlone() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ // Only the category named by the provider warning is enabled: the provider logger is not.
+ CapturingServiceProvider.enable(SDK_LOGGERS, Level.WARN);
+ CapturingServiceProvider.enable(DebugLoggingHook.class.getName(), Level.DEBUG);
+ register();
+
+ final List announcements =
+ CapturingServiceProvider.events().stream()
+ .filter(e -> e.message.contains("personal data"))
+ .collect(Collectors.toList());
+ assertEquals(1, announcements.size(), announcements.toString());
+ assertEquals(DebugLoggingHook.class.getName(), announcements.get(0).logger);
+ assertEquals(Level.INFO, announcements.get(0).level);
+ }
+
+ @Test
+ void doesNotAnnounceRawLoggingWithoutTraceDebug() throws Exception {
+ System.setProperty(TRACE_DEBUG, "false");
+ register();
+
+ assertTrue(messages("DD_TRACE_DEBUG is enabled").isEmpty());
+ }
+
+ @Test
+ void containsAFailureToFormatTheEvaluation() {
+ final EvaluationContext failing = mock(EvaluationContext.class);
+ when(failing.asUnmodifiableMap()).thenThrow(new IllegalStateException("cannot render"));
+ final HookContext hookContext =
+ HookContext.builder()
+ .flagKey("flag")
+ .type(FlagValueType.INTEGER)
+ .defaultValue(0)
+ .ctx(failing)
+ .build();
+ final FlagEvaluationDetails details =
+ FlagEvaluationDetails.builder().flagKey("flag").value(1).build();
+
+ assertDoesNotThrow(
+ () -> new DebugLoggingHook<>().finallyAfter(hookContext, details, emptyMap()));
+
+ assertEquals(
+ 1,
+ messages("Feature Flagging evaluation diagnostic unavailable: java.lang.IllegalState")
+ .size());
+ }
+
+ @Test
+ void doesNotExplainExposureSuppressionsAtDebug() throws Exception {
+ final Client client = register();
+
+ client.getIntegerValue("missing", 5, new MutableContext("user-1"));
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+
+ assertTrue(messages("Feature Flagging exposure suppressed").isEmpty());
+ }
+
+ @Test
+ void capsTheLengthOfALoggedContextValue() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+ final String blob = "x".repeat(5_000);
+
+ client.getIntegerValue("flag", 5, new MutableContext("user-1").add("blob", blob));
+
+ final String message = singleMessage("Feature Flagging evaluation:");
+ assertTrue(message.contains("...(truncated)"), message);
+ assertFalse(message.contains(blob), message);
+ assertTrue(message.length() < 3_000, "Logged " + message.length() + " characters");
+ }
+
+ @Test
+ void rendersNestedValuesAsTheyAre() {
+ final Value nested =
+ new Value(
+ Arrays.asList(
+ new Value("a"), new Value(new MutableStructure().add("k", "v")), new Value(2)));
+
+ final String message = hookMessage(hookContext(new MutableContext("u"), nested), details());
+
+ assertTrue(message.contains("defaultValue=[a, {k=v}, 2]"), message);
+ assertTrue(message.contains("context={targetingKey=u}"), message);
+ }
+
+ @Test
+ void doesNotFollowAValueThatContainsItself() {
+ final List list = new ArrayList<>();
+ final Value cyclic = new Value(list);
+ list.add(cyclic);
+ final Map attributes = new HashMap<>();
+ attributes.put("loop", cyclic);
+
+ final String message =
+ hookMessage(hookContext(new MutableContext("u", attributes), new Value(0)), details());
+
+ assertTrue(message.contains("loop=[(cycle)]"), message);
+ }
+
+ @Test
+ @SuppressWarnings({"unchecked", "rawtypes"})
+ void doesNotFollowAListThatContainsNullAndItself() {
+ final List list = new ArrayList<>();
+ final Value cyclic = new Value((List) list);
+ list.add(null);
+ list.add(cyclic);
+
+ final String message = hookMessage(hookContext(new MutableContext("u"), cyclic), details());
+
+ assertTrue(message.contains("defaultValue=[null, (cycle)]"), message);
+ }
+
+ @Test
+ void stopsWalkingAListOnceTheBudgetIsSpent() {
+ final int[] reads = {0};
+ final List wide =
+ new AbstractList() {
+ @Override
+ public String get(final int index) {
+ reads[0]++;
+ return "element-" + index;
+ }
+
+ @Override
+ public int size() {
+ return 1_000_000;
+ }
+ };
+
+ final String message = hookMessage(hookContext(new MutableContext("u"), wide), details());
+
+ assertTrue(message.contains("...(truncated)"), message);
+ assertTrue(reads[0] < 1_000, "Read " + reads[0] + " elements");
+ }
+
+ @Test
+ void doesNotScanAWrappedListBeforeRenderingIt() {
+ final int[] reads = {0};
+ final List wide =
+ new AbstractList() {
+ @Override
+ public Value get(final int index) {
+ reads[0]++;
+ return new Value("element-" + index);
+ }
+
+ @Override
+ public int size() {
+ return 1_000_000;
+ }
+ };
+
+ final String message =
+ hookMessage(hookContext(new MutableContext("u"), new Value(wide)), details());
+
+ assertTrue(message.contains("...(truncated)"), message);
+ assertTrue(reads[0] < 1_000, "Read " + reads[0] + " elements");
+ }
+
+ @Test
+ void returnsFromAnInfiniteIterable() {
+ final Iterable infinite =
+ () ->
+ new Iterator() {
+ @Override
+ public boolean hasNext() {
+ return true;
+ }
+
+ @Override
+ public String next() {
+ return "x";
+ }
+ };
+
+ final String message =
+ assertTimeoutPreemptively(
+ Duration.ofSeconds(10),
+ () -> hookMessage(hookContext(new MutableContext("u"), infinite), details()));
+
+ assertTrue(message.contains("...(truncated)"), message);
+ }
+
+ @Test
+ void doesNotRenderAMapKeyOutsideTheGuards() {
+ final List first = new ArrayList<>();
+ final List second = new ArrayList<>();
+ first.add(second);
+ second.add(first);
+ final Map map = new IdentityHashMap<>();
+ map.put(first, "v");
+
+ final String message = hookMessage(hookContext(new MutableContext("u"), map), details());
+
+ assertTrue(message.contains("defaultValue={[[(cycle)]]=v}"), message);
+ }
+
+ @Test
+ void rendersANullStructureKey() {
+ final Value structure = new Value(new MutableStructure().add((String) null, "v"));
+
+ final String message = hookMessage(hookContext(new MutableContext("u"), structure), details());
+
+ assertTrue(message.contains("defaultValue={null=v}"), message);
+ }
+
+ @Test
+ void doesNotOverflowTheStackOnAVeryDeepValue() {
+ Value deep = new Value("leaf");
+ for (int i = 0; i < 5_000; i++) {
+ deep = new Value(Collections.singletonList(deep));
+ }
+ final Map attributes = new HashMap<>();
+ attributes.put("deep", deep);
+
+ final String message =
+ hookMessage(hookContext(new MutableContext("u", attributes), new Value(0)), details());
+
+ assertTrue(message.contains("deep=[[[[[[[[...]]]]]]]]"), message);
+ assertFalse(message.contains("leaf"), message);
+ assertTrue(message.length() < 2_000, "Logged " + message.length() + " characters");
+ }
+
+ @Test
+ void rendersAWideContextWithinTheBudget() {
+ final Map attributes = new HashMap<>();
+ for (int i = 0; i < 20_000; i++) {
+ attributes.put("attribute-" + i, new Value("value-" + i));
+ }
+
+ final String message =
+ hookMessage(hookContext(new MutableContext("u", attributes), new Value(0)), details());
+
+ assertTrue(message.contains("...(truncated)"), message);
+ assertTrue(message.length() < 2_000, "Logged " + message.length() + " characters");
+ }
+
+ @Test
+ void rendersAWideImmutableContextWithinTheBudget() {
+ final Map attributes = new HashMap<>();
+ for (int i = 0; i < 20_000; i++) {
+ attributes.put("attribute-" + i, new Value("value-" + i));
+ }
+
+ final String message =
+ hookMessage(hookContext(new ImmutableContext("u", attributes), new Value(0)), details());
+
+ assertTrue(message.contains("...(truncated)"), message);
+ assertTrue(message.length() < 2_000, "Logged " + message.length() + " characters");
+ }
+
+ @Test
+ void rendersAStructureWithoutCopyingItsKeysOrValues() {
+ final Map attributes = new HashMap<>();
+ attributes.put("plan", new Value("pro"));
+ final Structure structure = mock(Structure.class);
+ when(structure.asUnmodifiableMap()).thenReturn(Collections.unmodifiableMap(attributes));
+ when(structure.keySet()).thenThrow(new AssertionError("keySet() copies the keys"));
+ when(structure.getValue("plan")).thenThrow(new AssertionError("getValue() clones the value"));
+
+ final String message =
+ hookMessage(hookContext(new MutableContext("u"), new Value(structure)), details());
+
+ assertTrue(message.contains("defaultValue={plan=pro}"), message);
+ }
+
+ @Test
+ void capsTheVariantAndTheReason() {
+ final FlagEvaluationDetails details =
+ FlagEvaluationDetails.builder()
+ .flagKey("flag")
+ .value(1)
+ .variant("v".repeat(5_000))
+ .reason("r".repeat(5_000))
+ .build();
+
+ final String message = hookMessage(hookContext(new MutableContext("u"), new Value(0)), details);
+
+ assertTrue(
+ message.contains("variant=" + "v".repeat(1_024) + "...(truncated, 5000 characters), "),
+ message);
+ assertTrue(
+ message.contains("reason=" + "r".repeat(1_024) + "...(truncated, 5000 characters), "),
+ message);
+ }
+
+ @Test
+ void capsTheFlagKey() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+
+ client.getIntegerValue("k".repeat(5_000), 5, new MutableContext("user-1"));
+
+ final String message = singleMessage("Feature Flagging evaluation:");
+ assertTrue(
+ message.startsWith(
+ "Feature Flagging evaluation: flag="
+ + "k".repeat(1_024)
+ + "...(truncated, 5000 characters), context="),
+ message.substring(0, Math.min(message.length(), 1_200)));
+ }
+
+ @Test
+ void doesNotCutASurrogatePairAtTheLimit() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+ // The emoji is a surrogate pair whose first half is the last character below the limit.
+ final String key = "k".repeat(1_023) + "\uD83D\uDE00" + "k".repeat(100);
+
+ client.getIntegerValue(key, 5, new MutableContext("user-1"));
+
+ final String message = singleMessage("Feature Flagging evaluation:");
+ assertTrue(
+ message.startsWith(
+ "Feature Flagging evaluation: flag="
+ + "k".repeat(1_023)
+ + "...(truncated, 1125 characters), context="),
+ message.substring(0, Math.min(message.length(), 1_200)));
+ assertFalse(message.contains("\uD83D"), "A lone surrogate was logged");
+ }
+
+ @Test
+ void doesNotLogTheCredentialsOfAnInvalidEndpoint() {
+ System.setProperty(AGENTLESS_BASE_URL, "ftp://user:pw-secret@example.com/ufc?token=tok-secret");
+
+ // The provider cannot initialize: the endpoint is invalid.
+ assertThrows(
+ Exception.class,
+ () ->
+ OpenFeatureAPI.getInstance()
+ .setProviderAndWait(new Provider(new Options().initTimeout(1, SECONDS))));
+
+ assertEquals(1, messages("Feature Flagging provider initialization failed: java.lang.").size());
+ for (final Event event : CapturingServiceProvider.events()) {
+ assertFalse(event.message.contains("pw-secret"), event.toString());
+ assertFalse(event.message.contains("tok-secret"), event.toString());
+ }
+ }
+
+ @Test
+ void logsTheErrorMessageTheApplicationObserves() throws Exception {
+ System.setProperty(TRACE_DEBUG, "true");
+ final Client client = register();
+
+ // The configuration does not observe full evaluation data, so the provider drops the message.
+ client.getStringValue("flag", "default", new MutableContext("user-1"));
+
+ final String message = singleMessage("Feature Flagging evaluation:");
+ assertTrue(message.contains("errorCode=TYPE_MISMATCH"), message);
+ assertTrue(message.contains("errorMessage=null"), message);
+ }
+
+ @Test
+ void logsTheProviderLifecycle() throws Exception {
+ register();
+ OpenFeatureAPI.getInstance().shutdown();
+
+ assertEquals(1, messages("Feature Flagging provider initializing").size());
+ assertFalse(messages("Feature Flagging provider ready").isEmpty());
+ assertFalse(messages("Feature Flagging provider shut down").isEmpty());
+ }
+
+ @Test
+ void initializesWhenTheReadyLogFails() throws Exception {
+ CapturingServiceProvider.failOn("Feature Flagging provider ready");
+
+ final Client client = register();
+
+ // The registration did not fail, and the provider evaluates.
+ assertEquals(1, client.getIntegerValue("flag", 5, new MutableContext("user-1")));
+ }
+
+ @Test
+ void shuttingDownDoesNotDependOnTheLoggingBackend() {
+ final boolean[] evaluatorShutDown = {false};
+ final ExposureTestEvaluator evaluator =
+ new ExposureTestEvaluator(configuration(), true) {
+ @Override
+ public synchronized void shutdown() {
+ super.shutdown();
+ evaluatorShutDown[0] = true;
+ }
+ };
+ final Provider provider = new Provider(new Options(), evaluator);
+ CapturingServiceProvider.failOn("provider shut down");
+
+ assertThrows(IllegalStateException.class, provider::shutdown);
+
+ assertTrue(evaluatorShutDown[0], "The cleanup must not wait for the log");
+ }
+
+ @Test
+ void explainsWhyAnExposureIsSuppressed() throws Exception {
+ CapturingServiceProvider.enable(SDK_LOGGERS, Level.TRACE);
+ final Client client = register();
+
+ client.getIntegerValue("missing", 5, new MutableContext("user-1"));
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+ client.getIntegerValue("flag", 5, new MutableContext("user-1"));
+
+ assertEquals(
+ 1,
+ messages("Feature Flagging exposure suppressed: evaluation failed or details unavailable")
+ .size());
+ assertEquals(
+ 1, messages("Feature Flagging exposure suppressed: exposure already recorded").size());
+ }
+
+ private static HookContext hookContext(
+ final EvaluationContext context, final Object defaultValue) {
+ return HookContext.builder()
+ .flagKey("flag")
+ .type(FlagValueType.OBJECT)
+ .defaultValue(defaultValue)
+ .ctx(context)
+ .build();
+ }
+
+ private static FlagEvaluationDetails details() {
+ return FlagEvaluationDetails.builder().flagKey("flag").value(1).build();
+ }
+
+ private String hookMessage(
+ final HookContext hookContext, final FlagEvaluationDetails details) {
+ new DebugLoggingHook<>().finallyAfter(hookContext, details, emptyMap());
+ return singleMessage("Feature Flagging evaluation:");
+ }
+
+ private Client register() throws Exception {
+ final OpenFeatureAPI api = OpenFeatureAPI.getInstance();
+ api.setProviderAndWait(
+ new Provider(
+ new Options().initTimeout(10, SECONDS),
+ new ExposureTestEvaluator(configuration(), true)));
+ return api.getClient();
+ }
+
+ private String singleMessage(final String prefix) {
+ final List messages = messages(prefix);
+ assertEquals(1, messages.size(), messages.toString());
+ return messages.get(0);
+ }
+
+ private List messages(final String prefix) {
+ return CapturingServiceProvider.events().stream()
+ .map(e -> e.message)
+ .filter(message -> message.startsWith(prefix))
+ .collect(Collectors.toList());
+ }
+
+ private static ServerConfiguration configuration() {
+ final Map variations = new HashMap<>();
+ variations.put("on", new Variant("on", 1));
+ final Split split = new Split(emptyList(), "on", emptyMap(), 7);
+ final Allocation allocation =
+ new Allocation("allocation", null, null, null, singletonList(split), Boolean.TRUE);
+ final Map flags = new HashMap<>();
+ flags.put(
+ "flag", new Flag("flag", true, ValueType.INTEGER, variations, singletonList(allocation)));
+ return new ServerConfiguration("", "", false, null, flags);
+ }
+}
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/FeatureFlagsRuntimeTest.java b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/FeatureFlagsRuntimeTest.java
index 1104b34f8fc..f6924b3b4a9 100644
--- a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/FeatureFlagsRuntimeTest.java
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/FeatureFlagsRuntimeTest.java
@@ -23,6 +23,7 @@
import com.datadog.openfeature.internal.config.TestSettings;
import com.datadog.openfeature.internal.flagevaluation.FlagEvalEvent;
import com.datadog.openfeature.internal.ufc.ServerConfiguration;
+import com.datadog.openfeature.testlog.CapturingServiceProvider;
import java.nio.charset.StandardCharsets;
import java.util.List;
import java.util.Map;
@@ -33,7 +34,10 @@
import java.util.concurrent.Future;
import java.util.concurrent.TimeoutException;
import java.util.function.Consumer;
+import java.util.stream.Collectors;
+import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.Test;
+import org.slf4j.event.Level;
class FeatureFlagsRuntimeTest {
private static final byte[] EMPTY_UFC =
@@ -143,6 +147,81 @@ void remoteConfigurationDeliversParsedConfigurationsAndReplaysToLateListeners()
assertTrue(source.closed);
}
+ @AfterEach
+ void resetCapturedLogs() {
+ CapturingServiceProvider.reset();
+ }
+
+ @Test
+ void stoppingDoesNotDependOnTheLoggingBackend() {
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ CapturingServiceProvider.failOn("Feature Flags runtime stopped");
+ final TestConfigurationSource source = new TestConfigurationSource();
+ final FeatureFlagsRuntime runtime =
+ FeatureFlagsRuntime.create(
+ new TestAgentBridge(source, null),
+ TestSettings.of("feature.flags.configuration.source", "remote_config"));
+ runtime.start();
+
+ assertThrows(IllegalStateException.class, runtime::stop);
+
+ assertTrue(source.closed);
+ }
+
+ @Test
+ void appliesConfigurationsWhenTheirLogFails() {
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ CapturingServiceProvider.failOn("Feature Flags configuration");
+ final TestConfigurationSource source = new TestConfigurationSource();
+ final FeatureFlagsRuntime runtime =
+ FeatureFlagsRuntime.create(
+ new TestAgentBridge(source, null),
+ TestSettings.of("feature.flags.configuration.source", "remote_config"));
+ final List received = new CopyOnWriteArrayList<>();
+ runtime.addConfigurationListener(received::add);
+ runtime.start();
+ try {
+ assertThrows(IllegalStateException.class, () -> source.listener.accept(EMPTY_UFC));
+ assertEquals(1, received.size(), "The listener must not wait for the log");
+ assertThrows(IllegalStateException.class, () -> source.listener.accept(null));
+ assertEquals(2, received.size(), "The removal must not wait for the log");
+ assertNull(received.get(1));
+
+ final List late = new CopyOnWriteArrayList<>();
+ runtime.addConfigurationListener(late::add);
+ assertTrue(late.isEmpty(), "The removed configuration is still the current one");
+ } finally {
+ CapturingServiceProvider.reset();
+ runtime.stop();
+ }
+ }
+
+ @Test
+ void reportsAppliedAndRemovedConfigurations() {
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ final TestConfigurationSource source = new TestConfigurationSource();
+ final FeatureFlagsRuntime runtime =
+ FeatureFlagsRuntime.create(
+ new TestAgentBridge(source, null),
+ TestSettings.of("feature.flags.configuration.source", "remote_config"));
+ runtime.start();
+ try {
+ source.listener.accept(EMPTY_UFC);
+ source.listener.accept(null);
+ } finally {
+ runtime.stop();
+ }
+
+ final List messages =
+ CapturingServiceProvider.events().stream().map(e -> e.message).collect(Collectors.toList());
+ assertTrue(
+ messages.contains(
+ "Feature Flags configuration applied: flags=0, invalidFlags=0, configurationEnv=Test, createdAt=null"),
+ messages.toString());
+ assertTrue(messages.contains("Feature Flags configuration removed"), messages.toString());
+ assertTrue(messages.contains("Feature Flags runtime stopped"), messages.toString());
+ }
+
@Test
void concurrentRemovalIsDeliveredAfterTheInitialReplay() throws Exception {
final TestConfigurationSource source = new TestConfigurationSource();
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/config/SettingsTest.java b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/config/SettingsTest.java
index 9e6675a1edc..a2476b5bae7 100644
--- a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/config/SettingsTest.java
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/config/SettingsTest.java
@@ -192,6 +192,25 @@ void readsToggles() {
assertFalse(settings.isEvaluationCountsEnabled());
}
+ @Test
+ void readsTraceDebugFromTheBridgeThenSystemPropertiesThenEnvironment() {
+ final Map bridge = new HashMap<>();
+ final Map properties = new HashMap<>();
+ final Map environment = new HashMap<>();
+ final Settings settings =
+ new Settings(new SettingAgentBridge(bridge), properties::get, environment::get);
+ assertFalse(settings.isTraceDebug());
+
+ environment.put("DD_TRACE_DEBUG", "1");
+ assertTrue(settings.isTraceDebug());
+
+ properties.put("dd.trace.debug", "false");
+ assertFalse(settings.isTraceDebug());
+
+ bridge.put("trace.debug", "TRUE");
+ assertTrue(settings.isTraceDebug());
+ }
+
private static void putIfNotNull(
final Map map, final String key, final String value) {
if (value != null) {
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/delivery/DeliveryDiagnosticsTest.java b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/delivery/DeliveryDiagnosticsTest.java
new file mode 100644
index 00000000000..d8e8e46abf3
--- /dev/null
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/delivery/DeliveryDiagnosticsTest.java
@@ -0,0 +1,237 @@
+package com.datadog.openfeature.internal.delivery;
+
+import static java.nio.charset.StandardCharsets.UTF_8;
+import static java.util.concurrent.TimeUnit.MILLISECONDS;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertFalse;
+import static org.junit.jupiter.api.Assertions.assertNull;
+import static org.junit.jupiter.api.Assertions.assertThrows;
+import static org.junit.jupiter.api.Assertions.assertTrue;
+import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.ArgumentMatchers.eq;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.verify;
+
+import com.datadog.openfeature.internal.LocalHttpServer;
+import com.datadog.openfeature.internal.bridge.v1.ConfigurationSource;
+import com.datadog.openfeature.internal.ufc.ServerConfiguration;
+import com.datadog.openfeature.testlog.CapturingServiceProvider;
+import java.io.IOException;
+import java.net.URI;
+import java.net.http.HttpClient;
+import java.time.Duration;
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.function.Consumer;
+import java.util.stream.Collectors;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.slf4j.event.Level;
+
+class DeliveryDiagnosticsTest {
+ private static final String CONFIG =
+ "{\"data\":{\"type\":\"universal-flag-configuration\",\"attributes\":"
+ + "{\"createdAt\":\"2024-04-17T19:40:53.716Z\",\"environment\":{\"name\":\"Test\"},"
+ + "\"flags\":{}}}}";
+
+ private LocalHttpServer server;
+
+ @BeforeEach
+ void setUp() throws IOException {
+ this.server = new LocalHttpServer();
+ CapturingServiceProvider.reset();
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ }
+
+ @AfterEach
+ void tearDown() {
+ CapturingServiceProvider.reset();
+ this.server.close();
+ }
+
+ @Test
+ void agentlessReportsAppliedAndUnchangedConfigurations() {
+ this.server.enqueue(200, CONFIG, "ETag", "\"v1\"").enqueue(304, null);
+ final CdnConfigurationSource source = source();
+
+ assertTrue(source.pollOnce());
+ assertTrue(source.pollOnce());
+
+ assertLogged("agentless configuration applied: etag=\"v1\"");
+ assertLogged("agentless configuration unchanged (HTTP 304)");
+ // A successful poll reports its outcome once: a retry line is only for a retry.
+ assertTrue(messages("poll attempt").isEmpty(), messages("").toString());
+ }
+
+ @Test
+ void agentlessReportsAFailedAttemptWithoutItsStackTrace() {
+ final CdnConfigurationSource source = source(URI.create("http://127.0.0.1:1/ufc"), null);
+
+ assertFalse(source.pollOnce());
+
+ final List attempts =
+ CapturingServiceProvider.events().stream()
+ .filter(e -> e.message.contains("poll attempt"))
+ .collect(Collectors.toList());
+ assertEquals(2, attempts.size(), attempts.toString());
+ for (final CapturingServiceProvider.Event attempt : attempts) {
+ assertNull(attempt.throwable, attempt.toString());
+ }
+ }
+
+ @Test
+ void agentlessReportsAMalformedPayloadAsRetainingTheConfiguration() {
+ this.server.enqueue(200, "{not json");
+
+ assertFalse(source().pollOnce());
+
+ assertLogged("malformed payload");
+ assertLogged("retaining the current configuration");
+ }
+
+ @Test
+ void agentlessReportsRetriesAndTheirDelay() {
+ this.server.enqueue(503, null).enqueue(200, CONFIG);
+
+ assertTrue(source().pollOnce());
+
+ assertLogged("poll attempt 1/3 returned HTTP 503; retrying in");
+ }
+
+ @Test
+ void agentlessReportsItsLifecycleWithoutQueryOrCredentials() {
+ final CdnConfigurationSource source = source("secret");
+ this.server.enqueue(200, CONFIG);
+
+ source.start(configuration -> {});
+ source.close();
+
+ final String starting = logged("agentless configuration source started");
+ assertTrue(starting.contains("pollIntervalMillis=30000"), starting);
+ assertFalse(starting.contains("/ufc"), starting);
+ assertFalse(starting.contains("secret"), starting);
+ assertFalse(starting.contains("token"), starting);
+ assertFalse(starting.contains("hidden"), starting);
+ assertLogged("agentless configuration source stopped");
+ }
+
+ @Test
+ void agentlessStartsPollingWhenItsLogFails() {
+ final ScheduledExecutorService executor = mock(ScheduledExecutorService.class);
+ final CdnConfigurationSource source = source(this.server.uri("/ufc"), null, executor);
+ this.server.enqueue(200, CONFIG);
+ CapturingServiceProvider.failOn("agentless configuration source started");
+
+ assertThrows(IllegalStateException.class, () -> source.start(configuration -> {}));
+
+ assertEquals(1, this.server.requests().size(), "The first poll must not wait for the log");
+ verify(executor)
+ .scheduleWithFixedDelay(any(Runnable.class), eq(30_000L), eq(30_000L), eq(MILLISECONDS));
+ }
+
+ @Test
+ void agentlessClosesWhenItsLogFails() {
+ final ScheduledExecutorService executor = mock(ScheduledExecutorService.class);
+ final CdnConfigurationSource source = source(this.server.uri("/ufc"), null, executor);
+ CapturingServiceProvider.failOn("agentless configuration source stopped");
+
+ assertThrows(IllegalStateException.class, source::close);
+
+ verify(executor).shutdownNow();
+ }
+
+ @Test
+ void agentlessReportsTheOriginOfTheEndpointOnly() {
+ final URI server = this.server.uri("/ufc?token=hidden");
+ final URI endpoint =
+ URI.create(
+ "http://user:s3cret@"
+ + server.getHost()
+ + ":"
+ + server.getPort()
+ + "/path-secret/ufc?token=hidden");
+ this.server.enqueue(200, CONFIG);
+ final CdnConfigurationSource source = source(endpoint, null);
+
+ source.start(configuration -> {});
+ source.close();
+
+ final String starting = logged("agentless configuration source started");
+ assertTrue(starting.contains("http://" + server.getHost() + ":" + server.getPort()), starting);
+ assertFalse(starting.contains("user"), starting);
+ assertFalse(starting.contains("s3cret"), starting);
+ assertFalse(starting.contains("path-secret"), starting);
+ assertFalse(starting.contains("hidden"), starting);
+ }
+
+ @Test
+ void remoteConfigurationReportsItsSubscriptionAndMalformedDocuments() {
+ final CapturingSource connector = new CapturingSource();
+ final RemoteConfigurationService service = new RemoteConfigurationService(connector);
+ service.start(configuration -> {});
+
+ connector.listener.accept("{\"environment\":{\"name\":\"Test\"},\"flags\":{}}".getBytes(UTF_8));
+ connector.listener.accept("{not json".getBytes(UTF_8));
+ connector.listener.accept(null);
+
+ assertLogged("subscribing to Remote Configuration");
+ assertLogged("malformed flag configuration");
+ }
+
+ private CdnConfigurationSource source() {
+ return source(null);
+ }
+
+ private CdnConfigurationSource source(final String apiKey) {
+ return source(this.server.uri("/ufc?token=hidden"), apiKey);
+ }
+
+ private CdnConfigurationSource source(final URI endpoint, final String apiKey) {
+ return source(endpoint, apiKey, mock(ScheduledExecutorService.class));
+ }
+
+ private CdnConfigurationSource source(
+ final URI endpoint, final String apiKey, final ScheduledExecutorService executor) {
+ final CdnConfigurationSource source =
+ new CdnConfigurationSource(
+ endpoint,
+ apiKey,
+ 30_000,
+ Duration.ofSeconds(5),
+ HttpClient.newHttpClient(),
+ executor,
+ delay -> {},
+ () -> 1.0);
+ source.setListenerForTest(new CopyOnWriteArrayList()::add);
+ return source;
+ }
+
+ private void assertLogged(final String text) {
+ assertFalse(messages(text).isEmpty(), "Missing log: " + text + " in " + messages(""));
+ }
+
+ private String logged(final String text) {
+ final List found = messages(text);
+ assertEquals(1, found.size(), found.toString());
+ return found.get(0);
+ }
+
+ private static List messages(final String text) {
+ return CapturingServiceProvider.events().stream()
+ .map(e -> e.message)
+ .filter(message -> message.contains(text))
+ .collect(Collectors.toList());
+ }
+
+ private static final class CapturingSource implements ConfigurationSource {
+ volatile Consumer listener;
+
+ @Override
+ public AutoCloseable subscribe(final Consumer listener) {
+ this.listener = listener;
+ return () -> {};
+ }
+ }
+}
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/exposure/ExposurePipelineDiagnosticsTest.java b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/exposure/ExposurePipelineDiagnosticsTest.java
new file mode 100644
index 00000000000..98343ea2fbe
--- /dev/null
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/exposure/ExposurePipelineDiagnosticsTest.java
@@ -0,0 +1,152 @@
+package com.datadog.openfeature.internal.exposure;
+
+import static java.util.Collections.emptyMap;
+import static java.util.concurrent.TimeUnit.MILLISECONDS;
+import static java.util.concurrent.TimeUnit.SECONDS;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertFalse;
+import static org.junit.jupiter.api.Assertions.assertThrows;
+
+import com.datadog.openfeature.internal.RuntimeServices;
+import com.datadog.openfeature.internal.bridge.v1.EventTransport;
+import com.datadog.openfeature.internal.bridge.v1.HealthMetrics;
+import com.datadog.openfeature.testlog.CapturingServiceProvider;
+import java.io.IOException;
+import java.util.List;
+import java.util.stream.Collectors;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.slf4j.event.Level;
+
+class ExposurePipelineDiagnosticsTest {
+ private static final long AWAIT_MILLIS = SECONDS.toMillis(5);
+
+ @BeforeEach
+ void captureLogs() {
+ CapturingServiceProvider.reset();
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ }
+
+ @AfterEach
+ void restore() {
+ CapturingServiceProvider.reset();
+ }
+
+ @Test
+ void reportsTheExposuresDroppedByAFullQueueOncePerFlush() throws Exception {
+ final ExposurePipeline pipeline = pipeline(1, (route, json) -> {});
+ final int logged = pipelineEvents().size();
+
+ pipeline.accept(exposure());
+ pipeline.accept(exposure());
+ pipeline.accept(exposure());
+
+ // The producer, an application thread, does not log.
+ assertEquals(logged, pipelineEvents().size(), messages("").toString());
+ pipeline.start();
+ try {
+ awaitLog("exposures dropped since the last flush: queue full, count=2");
+ } finally {
+ pipeline.close();
+ }
+ assertEquals(1, messages("queue full").size(), messages("").toString());
+ }
+
+ @Test
+ void reportsTheShutdownRequestWithoutLoggingEachExposure() {
+ final ExposurePipeline pipeline = pipeline(16, (route, json) -> {});
+ final int logged = pipelineEvents().size();
+
+ pipeline.accept(exposure());
+ pipeline.requestShutdown();
+ pipeline.accept(exposure());
+
+ assertEquals(logged + 1, pipelineEvents().size(), messages("").toString());
+ assertEquals(1, messages("exposure shutdown requested: queued=1").size());
+ }
+
+ @Test
+ void signalsTheWorkerWhenTheShutdownLogFails() {
+ final ExposurePipeline pipeline = pipeline(16, (route, json) -> {});
+ pipeline.start();
+ CapturingServiceProvider.failOn("exposure shutdown requested");
+
+ assertThrows(IllegalStateException.class, pipeline::requestShutdown);
+
+ pipeline.awaitTermination(System.nanoTime() + SECONDS.toNanos(5));
+ assertFalse(pipeline.isSerializerThreadAlive(), "The worker was not signaled");
+ }
+
+ @Test
+ void reportsADeliveredFlush() throws Exception {
+ final ExposurePipeline pipeline = pipeline(16, (route, json) -> {});
+ pipeline.start();
+ try {
+ pipeline.accept(exposure());
+
+ awaitLog("exposure flush delivered: count=1");
+ } finally {
+ pipeline.close();
+ }
+
+ assertFalse(messages("exposure flush starting: count=1").isEmpty());
+ }
+
+ @Test
+ void reportsAFailedFlushAsDroppingTheBatch() throws Exception {
+ final ExposurePipeline pipeline =
+ pipeline(
+ 16,
+ (route, json) -> {
+ throw new IOException("returned error response 503");
+ });
+ pipeline.start();
+ try {
+ pipeline.accept(exposure());
+
+ awaitLog("exposure flush failed: java.io.IOException: returned error response 503");
+ } finally {
+ pipeline.close();
+ }
+
+ assertFalse(messages("dropping the batch of 1 exposure(s)").isEmpty());
+ }
+
+ private static ExposurePipeline pipeline(final int capacity, final EventTransport transport) {
+ return new ExposurePipeline(
+ capacity, 10, MILLISECONDS, transport, emptyMap(), new RuntimeServices(HealthMetrics.NOOP));
+ }
+
+ private static ExposureEvent exposure() {
+ return new ExposureEvent(
+ 1L,
+ new Allocation("allocation"),
+ new Flag("flag"),
+ new Variant("variant"),
+ new Subject("subject", emptyMap()),
+ 1);
+ }
+
+ private static void awaitLog(final String text) throws InterruptedException {
+ final long deadline = System.currentTimeMillis() + AWAIT_MILLIS;
+ while (messages(text).isEmpty() && System.currentTimeMillis() < deadline) {
+ Thread.sleep(10);
+ }
+ assertFalse(messages(text).isEmpty(), "Missing log: " + text + " in " + messages(""));
+ }
+
+ /** The events of the pipeline only: other threads of the JVM can log in the same window. */
+ private static List pipelineEvents() {
+ return CapturingServiceProvider.events().stream()
+ .filter(e -> e.logger.equals(ExposurePipeline.class.getName()))
+ .collect(Collectors.toList());
+ }
+
+ private static List messages(final String text) {
+ return CapturingServiceProvider.events().stream()
+ .map(e -> e.message)
+ .filter(message -> message.contains(text))
+ .collect(Collectors.toList());
+ }
+}
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipelineTest.java b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipelineTest.java
index 269c37f3b48..433e8e26135 100644
--- a/dd-openfeature/src/test/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipelineTest.java
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/internal/flagevaluation/FlagEvaluationPipelineTest.java
@@ -14,19 +14,24 @@
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertNotNull;
import static org.junit.jupiter.api.Assertions.assertNull;
+import static org.junit.jupiter.api.Assertions.assertThrows;
import static org.junit.jupiter.api.Assertions.assertTrue;
import com.datadog.openfeature.internal.EventQueue;
import com.datadog.openfeature.internal.RuntimeServices;
import com.datadog.openfeature.internal.flagevaluation.FlagEvaluationTestSupport.CapturingTransport;
import com.datadog.openfeature.internal.flagevaluation.FlagEvaluationTestSupport.RecordingMetrics;
+import com.datadog.openfeature.testlog.CapturingServiceProvider;
import java.util.HashMap;
+import java.util.List;
import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
+import java.util.stream.Collectors;
import org.junit.jupiter.api.Test;
+import org.slf4j.event.Level;
class FlagEvaluationPipelineTest {
@@ -58,6 +63,48 @@ void degradedCapOverflowTelemetryIsEmittedOnFlush() {
"reason:" + FlagEvaluationPipeline.DROP_REASON_DEGRADED_CAP));
}
+ @Test
+ void reportsADeliveredFlushAndTheShutdownRequest() {
+ CapturingServiceProvider.reset();
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ try {
+ final FlagEvaluationTestSupport.TestWriterSetup setup = buildTestWriter();
+ setup.handler.add(simpleEvent("logged-flag", "on"));
+ flushAndCapture(setup);
+ writer(16, Long.MAX_VALUE, TimeUnit.NANOSECONDS).requestShutdown();
+
+ final List messages =
+ CapturingServiceProvider.events().stream()
+ .map(e -> e.message)
+ .collect(Collectors.toList());
+ assertTrue(
+ messages.contains("Feature Flags flag evaluation flush delivered: payloads=1"),
+ messages.toString());
+ assertTrue(
+ messages.contains("Feature Flags flag evaluation shutdown requested"),
+ messages.toString());
+ } finally {
+ CapturingServiceProvider.reset();
+ }
+ }
+
+ @Test
+ void signalsTheWorkerWhenTheShutdownLogFails() {
+ CapturingServiceProvider.reset();
+ CapturingServiceProvider.enable("com.datadog.openfeature", Level.DEBUG);
+ CapturingServiceProvider.failOn("flag evaluation shutdown requested");
+ final FlagEvaluationPipeline writer = writer(16, 10L, TimeUnit.SECONDS);
+ writer.start();
+ try {
+ assertThrows(IllegalStateException.class, writer::requestShutdown);
+
+ writer.awaitTermination(System.nanoTime() + TimeUnit.SECONDS.toNanos(5));
+ assertFalse(writer.isSerializerThreadAlive(), "The worker was not signaled");
+ } finally {
+ CapturingServiceProvider.reset();
+ }
+ }
+
@Test
void queueOverflowIncrementsObservableDropCounter() {
final FlagEvaluationPipeline writer = writer(2, 10L, TimeUnit.SECONDS);
diff --git a/dd-openfeature/src/test/java/com/datadog/openfeature/testlog/CapturingServiceProvider.java b/dd-openfeature/src/test/java/com/datadog/openfeature/testlog/CapturingServiceProvider.java
new file mode 100644
index 00000000000..c1a8bba0e9a
--- /dev/null
+++ b/dd-openfeature/src/test/java/com/datadog/openfeature/testlog/CapturingServiceProvider.java
@@ -0,0 +1,208 @@
+package com.datadog.openfeature.testlog;
+
+import java.util.List;
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentMap;
+import java.util.concurrent.CopyOnWriteArrayList;
+import org.slf4j.ILoggerFactory;
+import org.slf4j.IMarkerFactory;
+import org.slf4j.Marker;
+import org.slf4j.event.Level;
+import org.slf4j.helpers.AbstractLogger;
+import org.slf4j.helpers.BasicMarkerFactory;
+import org.slf4j.helpers.MessageFormatter;
+import org.slf4j.helpers.NOPMDCAdapter;
+import org.slf4j.spi.MDCAdapter;
+import org.slf4j.spi.SLF4JServiceProvider;
+
+/**
+ * Test SLF4J provider that captures log events. The module has no SLF4J 2 compatible logging
+ * backend, so this one lets tests assert diagnostics. Nothing is enabled or captured until a test
+ * calls {@link #enable(String, Level)}, which keeps the other tests as quiet as without a backend.
+ */
+public final class CapturingServiceProvider implements SLF4JServiceProvider {
+ private static final ConcurrentMap LEVELS = new ConcurrentHashMap<>();
+ private static final List EVENTS = new CopyOnWriteArrayList<>();
+ private static volatile String failOn;
+
+ /** A captured log event. */
+ public static final class Event {
+ public final String logger;
+ public final Level level;
+ public final String message;
+ public final Throwable throwable;
+
+ Event(final String logger, final Level level, final String message, final Throwable throwable) {
+ this.logger = logger;
+ this.level = level;
+ this.message = message;
+ this.throwable = throwable;
+ }
+
+ @Override
+ public String toString() {
+ return level + " " + logger + ": " + message;
+ }
+ }
+
+ private final ILoggerFactory loggerFactory = name -> new CapturingLogger(name);
+ private final IMarkerFactory markerFactory = new BasicMarkerFactory();
+ private final MDCAdapter mdcAdapter = new NOPMDCAdapter();
+
+ /**
+ * Enables a level and captures the events of the loggers whose name starts with the prefix. The
+ * longest matching prefix decides.
+ *
+ * @param prefix the logger name prefix.
+ * @param level the lowest enabled level, or {@code null} to disable the prefix.
+ */
+ public static void enable(final String prefix, final Level level) {
+ if (level == null) {
+ LEVELS.remove(prefix);
+ } else {
+ LEVELS.put(prefix, level);
+ }
+ }
+
+ /**
+ * Makes the logging calls throw, as a failing logging backend would: an enabled event whose
+ * message contains the text is captured, then the logging call throws.
+ *
+ * @param text the text of the messages that fail, or {@code null} to stop failing.
+ */
+ public static void failOn(final String text) {
+ failOn = text;
+ }
+
+ /** Disables every logger, stops the failures and forgets the captured events. */
+ public static void reset() {
+ LEVELS.clear();
+ EVENTS.clear();
+ failOn = null;
+ }
+
+ /**
+ * @return the captured events, oldest first.
+ */
+ public static List events() {
+ return EVENTS;
+ }
+
+ @Override
+ public ILoggerFactory getLoggerFactory() {
+ return this.loggerFactory;
+ }
+
+ @Override
+ public IMarkerFactory getMarkerFactory() {
+ return this.markerFactory;
+ }
+
+ @Override
+ public MDCAdapter getMDCAdapter() {
+ return this.mdcAdapter;
+ }
+
+ @Override
+ public String getRequestedApiVersion() {
+ return "2.0.99";
+ }
+
+ @Override
+ public void initialize() {}
+
+ private static final class CapturingLogger extends AbstractLogger {
+ private static final long serialVersionUID = 1L;
+
+ CapturingLogger(final String name) {
+ this.name = name;
+ }
+
+ private boolean isEnabled(final Level level) {
+ // Read the entries once: a test can reset the levels while a worker thread is logging.
+ String best = null;
+ Level threshold = null;
+ for (final Map.Entry entry : LEVELS.entrySet()) {
+ final String prefix = entry.getKey();
+ if (name.startsWith(prefix) && (best == null || prefix.length() > best.length())) {
+ best = prefix;
+ threshold = entry.getValue();
+ }
+ }
+ return threshold != null && level.toInt() >= threshold.toInt();
+ }
+
+ @Override
+ public boolean isTraceEnabled() {
+ return isEnabled(Level.TRACE);
+ }
+
+ @Override
+ public boolean isTraceEnabled(final Marker marker) {
+ return isTraceEnabled();
+ }
+
+ @Override
+ public boolean isDebugEnabled() {
+ return isEnabled(Level.DEBUG);
+ }
+
+ @Override
+ public boolean isDebugEnabled(final Marker marker) {
+ return isDebugEnabled();
+ }
+
+ @Override
+ public boolean isInfoEnabled() {
+ return isEnabled(Level.INFO);
+ }
+
+ @Override
+ public boolean isInfoEnabled(final Marker marker) {
+ return isInfoEnabled();
+ }
+
+ @Override
+ public boolean isWarnEnabled() {
+ return isEnabled(Level.WARN);
+ }
+
+ @Override
+ public boolean isWarnEnabled(final Marker marker) {
+ return isWarnEnabled();
+ }
+
+ @Override
+ public boolean isErrorEnabled() {
+ return isEnabled(Level.ERROR);
+ }
+
+ @Override
+ public boolean isErrorEnabled(final Marker marker) {
+ return isErrorEnabled();
+ }
+
+ @Override
+ protected String getFullyQualifiedCallerName() {
+ return null;
+ }
+
+ @Override
+ protected void handleNormalizedLoggingCall(
+ final Level level,
+ final Marker marker,
+ final String messagePattern,
+ final Object[] arguments,
+ final Throwable throwable) {
+ if (isEnabled(level)) {
+ final String message = MessageFormatter.arrayFormat(messagePattern, arguments).getMessage();
+ EVENTS.add(new Event(this.name, level, message, throwable));
+ final String failing = failOn;
+ if (failing != null && message.contains(failing)) {
+ throw new IllegalStateException("The logging backend failed on: " + message);
+ }
+ }
+ }
+ }
+}
diff --git a/dd-openfeature/src/test/resources/META-INF/services/org.slf4j.spi.SLF4JServiceProvider b/dd-openfeature/src/test/resources/META-INF/services/org.slf4j.spi.SLF4JServiceProvider
new file mode 100644
index 00000000000..4b23d4ccf4a
--- /dev/null
+++ b/dd-openfeature/src/test/resources/META-INF/services/org.slf4j.spi.SLF4JServiceProvider
@@ -0,0 +1 @@
+com.datadog.openfeature.testlog.CapturingServiceProvider