From 36138695f20645619849a104b70bfe9543afe662 Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Thu, 15 Oct 2026 19:06:30 +0000 Subject: [PATCH 1/9] Add debug logging for feature flag onboarding --- .../featureflag/FeatureFlaggingSystem.java | 7 + .../feature-flagging-api/README.md | 32 ++++ .../feature-flagging-api/build.gradle.kts | 2 + .../feature-flagging-api/gradle.lockfile | 4 +- .../trace/api/openfeature/DDEvaluator.java | 3 + .../api/openfeature/DebugLoggingHook.java | 37 ++++ .../api/openfeature/ExposureLoggingHook.java | 6 + .../trace/api/openfeature/Provider.java | 23 ++- .../api/openfeature/DebugLoggingHookTest.java | 176 ++++++++++++++++++ .../trace/api/openfeature/ProviderTest.java | 11 +- .../AgentlessConfigurationSource.java | 77 +++++++- .../featureflag/ExposureWriterImpl.java | 27 ++- .../featureflag/RemoteConfigServiceImpl.java | 17 ++ .../UniversalFlagConfigParser.java | 9 +- .../AgentlessConfigurationSourceTest.java | 126 ++++++++++++- .../featureflag/ExposureWriterTests.java | 55 ++++++ 16 files changed, 589 insertions(+), 23 deletions(-) create mode 100644 products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java create mode 100644 products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java diff --git a/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java b/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java index 1ef61e70328..fb8561f3518 100644 --- a/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java +++ b/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java @@ -52,6 +52,10 @@ static synchronized void start( return; } + LOGGER.debug( + "Feature Flagging enabled; configuration source={}, env={}", + config.getFeatureFlaggingConfigurationSource(), + config.getEnv()); if (CONFIGURATION_SOURCE_AGENTLESS.equals(config.getFeatureFlaggingConfigurationSource())) { final FeatureFlaggingGateway.ActivationListener activationListener = () -> activateAgentless(sco, config, systemInitializer); @@ -93,6 +97,8 @@ private static void initializeOrRollBack( SHUTDOWN_HOOK = hook; } } catch (final RuntimeException | Error e) { + LOGGER.debug( + "Feature Flagging system initialization failed: {}", e.getClass().getSimpleName()); stop(); throw e; } @@ -164,6 +170,7 @@ static ConfigurationSourceService createConfigurationSourceService( final String configurationSource = config.getFeatureFlaggingConfigurationSource(); if (CONFIGURATION_SOURCE_REMOTE_CONFIG.equals(configurationSource)) { if (!config.isRemoteConfigEnabled()) { + LOGGER.warn("Feature Flagging remote_config source requires DD_REMOTE_CONFIG_ENABLED=true"); throw new IllegalStateException("Feature Flagging system started without RC"); } return new RemoteConfigServiceImpl(sco, config); diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index 5aa7153906c..079027d7fee 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -253,3 +253,35 @@ This setting stops exposures only. Flag evaluation events have their own setting Configuration path. `offline` is reserved for startup-provided UFC bytes; until those bytes are implemented, no network source starts and evaluations use defaults. + +## Onboarding diagnostics + +Enable `DD_TRACE_DEBUG=true` for the Java agent's configuration and exposure-delivery logs. +The provider uses the application's SLF4J backend: enable DEBUG for +`datadog.trace.api.openfeature` before constructing the provider to include initialization, +readiness changes, evaluation outcomes, and exposure suppression. The evaluation debug hook is +registered only when its logger is enabled; no additional feature flag setting is required. + +Look for messages prefixed with `Feature Flagging`: + +- Startup reports the configuration source and effective environment. Agentless startup reports + the endpoint origin and polling settings, and warns if the Datadog endpoint requires a missing + `DD_API_KEY`. +- Polling reports HTTP status, transport exception type, and retry delay. `unchanged` means HTTP + 304; `applied` appears only after configuration dispatch succeeds. Rejected responses retain + the current configuration. Remote Config removal and provider recovery are logged separately. +- Evaluations report the flag key, variant, reason, and error code. An `ERROR` reason identifies + fallback to the caller's default. Flag values, defaults, targeting keys and attributes, arbitrary + metadata, and error messages are omitted. Flag keys, variant identifiers, environment names, + configuration timestamps, and Remote Config keys are included for diagnosis. +- Exposure logs distinguish suppression, queueing, queue overflow, flush attempts, delivery, and + failed batches that are dropped. Queueing or dispatch to listeners does not confirm delivery. + The exposure writer currently stops without flushing pending exposures on shutdown; its stop + message makes that limitation explicit. + +Endpoint paths, queries, credentials, response bodies, and raw transport/parse error messages are +omitted from these configuration diagnostics. Per-evaluation and per-exposure debug logs can be +verbose; disable DEBUG after troubleshooting. + +Coverage follows the [SDK debug logging checklist](https://datadoghq.atlassian.net/wiki/spaces/PANA/pages/7276692209) +and the [Node.js reference implementation](https://github.com/DataDog/dd-trace-js/pull/10468). diff --git a/products/feature-flagging/feature-flagging-api/build.gradle.kts b/products/feature-flagging/feature-flagging-api/build.gradle.kts index ea58de3cd84..e78f2ef3db3 100644 --- a/products/feature-flagging/feature-flagging-api/build.gradle.kts +++ b/products/feature-flagging/feature-flagging-api/build.gradle.kts @@ -56,6 +56,8 @@ dependencies { testImplementation(libs.bundles.junit5) testImplementation(libs.bundles.mockito) testImplementation(libs.moshi) + // OpenFeature uses SLF4J 2; the shared Java 8 test binding targets SLF4J 1.7. + testImplementation("ch.qos.logback:logback-classic:1.6.5") // The main source set gets the bootstrap/config types as compileOnly, so the JMH source set // needs them on its own compile and runtime classpath to drive the hook end to end. diff --git a/products/feature-flagging/feature-flagging-api/gradle.lockfile b/products/feature-flagging/feature-flagging-api/gradle.lockfile index fa0bfccc495..c8a2044ae9a 100644 --- a/products/feature-flagging/feature-flagging-api/gradle.lockfile +++ b/products/feature-flagging/feature-flagging-api/gradle.lockfile @@ -2,8 +2,8 @@ # Manual edits can break the build and are not advised. # This file is expected to be part of source control. # To regenerate this file, run: ./gradlew :products:feature-flagging:feature-flagging-api:dependencies --write-locks -ch.qos.logback:logback-classic:1.2.13=jmhRuntimeClasspath,testCompileClasspath,testRuntimeClasspath -ch.qos.logback:logback-core:1.2.13=jmhRuntimeClasspath,testCompileClasspath,testRuntimeClasspath +ch.qos.logback:logback-classic:1.6.5=jmhRuntimeClasspath,testCompileClasspath,testRuntimeClasspath +ch.qos.logback:logback-core:1.6.5=jmhRuntimeClasspath,testCompileClasspath,testRuntimeClasspath com.github.javaparser:javaparser-core:3.25.6=codenarc com.github.spotbugs:spotbugs-annotations:4.10.4=compileClasspath,jmhCompileClasspath,spotbugs com.github.spotbugs:spotbugs:4.10.4=spotbugs diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java index 2afec791851..2dc48aeae06 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java @@ -225,6 +225,9 @@ public boolean initialize( final long timeout, final TimeUnit unit, final EvaluationContext context) throws Exception { FeatureFlaggingGateway.activate(); FeatureFlaggingGateway.addConfigListener(this); + log.debug( + "Feature Flagging provider configuration available at subscription: {}", + hasConfiguration()); return initializationLatch.await(timeout, unit) || hasConfiguration(); } diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java new file mode 100644 index 00000000000..2fe8116b038 --- /dev/null +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java @@ -0,0 +1,37 @@ +package datadog.trace.api.openfeature; + +import dev.openfeature.sdk.FlagEvaluationDetails; +import dev.openfeature.sdk.Hook; +import dev.openfeature.sdk.HookContext; +import java.util.Map; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** Logs final evaluation outcomes without flag values, targeting context, or error messages. */ +final class DebugLoggingHook implements Hook { + private static final Logger log = LoggerFactory.getLogger(DebugLoggingHook.class); + + static DebugLoggingHook createIfEnabled() { + return log.isDebugEnabled() ? new DebugLoggingHook() : null; + } + + @Override + public void finallyAfter( + final HookContext context, + final FlagEvaluationDetails details, + final Map hints) { + if (!log.isDebugEnabled() || details == null) { + return; + } + try { + log.debug( + "Feature Flagging evaluation: flag={}, reason={}, variant={}, errorCode={}", + details.getFlagKey(), + details.getReason(), + details.getVariant(), + details.getErrorCode()); + } catch (RuntimeException ignored) { + // Diagnostics must not affect evaluation, even if an application logging backend fails. + } + } +} diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java index 67ab6b27cfd..207846a56cc 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java @@ -45,6 +45,7 @@ public void finallyAfter( final Map hints) { try { if (details == null || details.getErrorCode() != null) { + log.debug("Feature Flagging exposure suppressed: evaluation failed or details unavailable"); return; } final ImmutableMetadata metadata = details.getFlagMetadata(); @@ -55,6 +56,8 @@ public void finallyAfter( final Map values = metadata.asUnmodifiableMap(); if (!Boolean.TRUE.equals(values.get(DDEvaluator.METADATA_DO_LOG)) || !Boolean.FALSE.equals(values.get(DDEvaluator.METADATA_EXPOSURE_CACHE_HIT))) { + log.debug( + "Feature Flagging exposure suppressed: allocation logging disabled or exposure already recorded"); return; } final String flag = details.getFlagKey(); @@ -81,6 +84,9 @@ public void finallyAfter( serialId, SplitFeatureMetadata.featuresWithPrefix( metadata, DDEvaluator.METADATA_EXPOSURE_FEATURE_PREFIX))); + log.debug("Feature Flagging exposure dispatched to agent listeners"); + } else { + log.debug("Feature Flagging exposure suppressed: Datadog exposure logging disabled"); } } catch (LinkageError e) { // Never let exposure reporting break flag evaluation. diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java index b5dc224392c..47654cdc4f7 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java @@ -89,7 +89,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,10 @@ public Provider(final Options options) { } catch (LinkageError e) { log.warn("Feature flag exposure reporting is unavailable with the installed agent", e); } + final DebugLoggingHook debugLoggingHook = DebugLoggingHook.createIfEnabled(); + if (debugLoggingHook != null) { + hooks.add(debugLoggingHook); + } this.providerHooks = hooks.isEmpty() ? Collections.emptyList() : Collections.unmodifiableList(hooks); @@ -131,26 +135,39 @@ public Provider(final Options options) { @Override public void initialize(final EvaluationContext context) throws Exception { + log.debug( + "Feature Flagging provider initializing; timeout={} {}", + options.getTimeout(), + options.getUnit()); initializationState.set(InitializationState.INITIALIZING); try { evaluator = buildEvaluator(); if (!evaluator.initialize(options.getTimeout(), options.getUnit(), context)) { if (markInitialConfigReceivedReady()) { + log.debug("Feature Flagging provider initialized successfully"); return; } markInitializationError(); + log.debug( + "Feature Flagging provider initialization timed out waiting for usable configuration"); throw new ProviderNotReadyError( "Provider timed-out while waiting for initial configuration"); } if (!evaluator.hasConfiguration() || !markSuccessfulInitializationReady()) { markInitializationError(); + log.debug("Feature Flagging provider initialization failed: configuration unavailable"); throw new ProviderNotReadyError( "Provider timed-out while waiting for initial configuration"); } + log.debug("Feature Flagging provider initialized successfully"); } catch (final OpenFeatureError e) { + log.debug("Feature Flagging provider initialization failed: errorCode={}", e.getErrorCode()); markInitializationError(); throw e; } catch (final Throwable e) { + log.debug( + "Feature Flagging provider initialization failed: {}; verify the Java agent and feature flag configuration", + e.getClass().getSimpleName()); markInitializationError(); throw new FatalError("Failed to initialize provider, is the tracer configured?", e); } @@ -174,6 +191,7 @@ void onConfigurationChange() { if (state == InitializationState.ERROR && initializationState.compareAndSet( InitializationState.ERROR, InitializationState.READY)) { + log.debug("Feature Flagging provider ready after configuration recovery"); emit( ProviderEvent.PROVIDER_READY, ProviderEventDetails.builder().message("Provider ready").build()); @@ -182,6 +200,7 @@ void onConfigurationChange() { if (initializationState.get() != InitializationState.READY) { return; } + log.debug("Feature Flagging provider configuration changed"); emit( ProviderEvent.PROVIDER_CONFIGURATION_CHANGED, ProviderEventDetails.builder().message("New configuration received").build()); @@ -195,6 +214,7 @@ private void onConfigurationUnavailable() { if (!initializationState.compareAndSet(InitializationState.READY, InitializationState.ERROR)) { return; } + log.debug("Feature Flagging provider configuration unavailable"); emit( ProviderEvent.PROVIDER_ERROR, ProviderEventDetails.builder() @@ -249,6 +269,7 @@ Hook buildExposureLoggingHook() { @Override public void shutdown() { + log.debug("Feature Flagging provider shutting down"); if (flagEvalMetrics != null) { flagEvalMetrics.shutdown(); } diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java new file mode 100644 index 00000000000..496f2730982 --- /dev/null +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java @@ -0,0 +1,176 @@ +package datadog.trace.api.openfeature; + +import static java.util.Collections.emptyMap; +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.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.anyLong; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verifyNoInteractions; +import static org.mockito.Mockito.when; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import dev.openfeature.sdk.Client; +import dev.openfeature.sdk.ErrorCode; +import dev.openfeature.sdk.EvaluationContext; +import dev.openfeature.sdk.FlagEvaluationDetails; +import dev.openfeature.sdk.FlagValueType; +import dev.openfeature.sdk.Hook; +import dev.openfeature.sdk.HookContext; +import dev.openfeature.sdk.ImmutableMetadata; +import dev.openfeature.sdk.OpenFeatureAPI; +import dev.openfeature.sdk.ProviderEvaluation; +import java.util.Map; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; +import org.tabletest.junit.TableTest; + +class DebugLoggingHookTest { + private final Logger logger = (Logger) LoggerFactory.getLogger(DebugLoggingHook.class); + private final ListAppender appender = new ListAppender<>(); + private Level previousLevel; + + @BeforeEach + void setup() { + previousLevel = logger.getLevel(); + logger.setLevel(Level.DEBUG); + appender.start(); + logger.addAppender(appender); + } + + @AfterEach + void cleanup() { + logger.detachAppender(appender); + appender.stop(); + logger.setLevel(previousLevel); + } + + @TableTest({ + "Scenario | Level | Registered", + "Debug enabled | DEBUG | true ", + "Debug filtered | INFO | false ", + "Errors only | ERROR | false " + }) + void registersOnlyWhenDebugIsActive(String scenario, String level, boolean registered) { + logger.setLevel(Level.toLevel(level)); + Provider provider = + new Provider(new Provider.Options().initTimeout(1, MILLISECONDS), mock(Evaluator.class)); + try { + assertEquals( + registered, + provider.getProviderHooks().stream().anyMatch(DebugLoggingHook.class::isInstance)); + } finally { + provider.shutdown(); + } + } + + @Test + void logsOutcomeWithoutValuesContextOrArbitraryMetadata() { + EvaluationContext evaluationContext = mock(EvaluationContext.class); + HookContext context = + HookContext.builder() + .flagKey("checkout") + .type(FlagValueType.STRING) + .defaultValue("secret-default") + .ctx(evaluationContext) + .build(); + FlagEvaluationDetails details = + FlagEvaluationDetails.builder() + .flagKey("checkout") + .value("secret-value") + .variant("enabled") + .reason("TARGETING_MATCH") + .flagMetadata( + ImmutableMetadata.builder().addString("secret-key", "secret-metadata").build()) + .build(); + + DebugLoggingHook.createIfEnabled().finallyAfter(context, details, emptyMap()); + + assertEquals(1, appender.list.size()); + String message = appender.list.get(0).getFormattedMessage(); + assertTrue(message.contains("flag=checkout")); + assertTrue(message.contains("reason=TARGETING_MATCH")); + assertTrue(message.contains("variant=enabled")); + assertFalse(message.contains("secret")); + verifyNoInteractions(evaluationContext); + } + + @Test + void logsFallbackCodeWithoutPotentiallySensitiveErrorMessage() { + FlagEvaluationDetails details = + FlagEvaluationDetails.builder() + .flagKey("missing") + .value("secret-default") + .reason("ERROR") + .errorCode(ErrorCode.FLAG_NOT_FOUND) + .errorMessage("secret-error") + .build(); + + DebugLoggingHook.createIfEnabled().finallyAfter(null, details, emptyMap()); + + String message = appender.list.get(0).getFormattedMessage(); + assertTrue(message.contains("reason=ERROR")); + assertTrue(message.contains("errorCode=FLAG_NOT_FOUND")); + assertFalse(message.contains("secret")); + } + + @Test + void logsFinalFallbackWhenAnApplicationAfterHookFails() throws Exception { + Evaluator evaluator = mock(Evaluator.class); + when(evaluator.initialize(anyLong(), any(), any())).thenReturn(true); + when(evaluator.hasConfiguration()).thenReturn(true); + when(evaluator.evaluate(any(), any(), any(), any())) + .thenReturn( + ProviderEvaluation.builder() + .value(true) + .variant("enabled") + .reason("TARGETING_MATCH") + .build()); + OpenFeatureAPI api = OpenFeatureAPI.getInstance(); + try { + api.setProviderAndWait( + new Provider(new Provider.Options().initTimeout(1, MILLISECONDS), evaluator)); + Client client = api.getClient(); + client.addHooks( + new Hook() { + @Override + public void after( + HookContext context, + FlagEvaluationDetails details, + Map hints) { + throw new IllegalStateException("secret-application-error"); + } + }); + + assertFalse(client.getBooleanValue("checkout", false)); + + assertEquals(1, appender.list.size()); + String message = appender.list.get(0).getFormattedMessage(); + assertTrue(message.contains("reason=ERROR")); + assertFalse(message.contains("secret")); + } finally { + api.shutdown(); + } + } + + @Test + void doesNotInspectDetailsAfterDebugIsDisabled() { + DebugLoggingHook hook = DebugLoggingHook.createIfEnabled(); + assertNotNull(hook); + logger.setLevel(Level.INFO); + FlagEvaluationDetails details = mock(FlagEvaluationDetails.class); + + hook.finallyAfter(null, details, emptyMap()); + + verifyNoInteractions(details); + assertTrue(appender.list.isEmpty()); + } +} diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ProviderTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ProviderTest.java index 2156eae7fdf..dab26a84e35 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ProviderTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ProviderTest.java @@ -324,8 +324,9 @@ public void testGetProviderHooksReturnsFlagEvalMetricsHook() { Provider provider = new Provider(new Options().initTimeout(10, MILLISECONDS), mock(Evaluator.class)); List hooks = provider.getProviderHooks(); - // OTel FlagEvalMetricsHook (index 0), FlagEvalLoggingHook (index 1), ExposureLoggingHook (last) - assertThat(hooks.size(), equalTo(3)); + // OTel FlagEvalMetricsHook (index 0), FlagEvalLoggingHook (index 1), ExposureLoggingHook (index + // 2), optional DebugLoggingHook (last) + assertThat(hooks.stream().filter(h -> !(h instanceof DebugLoggingHook)).count(), equalTo(3L)); assertThat(hooks.get(0) instanceof FlagEvalMetricsHook, equalTo(true)); assertThat(hooks.get(1) instanceof FlagEvalLoggingHook, equalTo(true)); assertThat(hooks.get(2) instanceof ExposureLoggingHook, equalTo(true)); @@ -343,7 +344,7 @@ Hook buildFlagEvalLoggingHook() { List hooks = provider.getProviderHooks(); - assertThat(hooks.size(), equalTo(2)); + assertThat(hooks.stream().filter(h -> !(h instanceof DebugLoggingHook)).count(), equalTo(2L)); assertThat(hooks.get(0) instanceof FlagEvalMetricsHook, equalTo(true)); assertThat(hooks.get(1) instanceof ExposureLoggingHook, equalTo(true)); } @@ -412,7 +413,9 @@ public void testShutdownCleansUpEvaluator() throws Exception { verify(evaluator).shutdown(); // After shutdown, getProviderHooks still returns the OTel, logging and exposure hooks - assertThat(provider.getProviderHooks().size(), equalTo(3)); + assertThat( + provider.getProviderHooks().stream().filter(h -> !(h instanceof DebugLoggingHook)).count(), + equalTo(3L)); } private static void assertHasFlagEvalMetricsHook(final Provider provider) { diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java index f4fc35cce30..9cbd32022d1 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java @@ -123,6 +123,22 @@ public void init() { started = true; } + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging starting agentless configuration source at {}://{}:{}; pollIntervalMs={}, requestTimeoutSeconds={}, env={}", + endpoint.scheme(), + endpoint.host(), + endpoint.port(), + pollIntervalMillis, + config.getFeatureFlaggingConfigurationSourceRequestTimeoutSeconds(), + config.getEnv()); + } + if (config.getFeatureFlaggingConfigurationSourceAgentlessBaseUrl() == null + && isBlank(config.getApiKey())) { + LOGGER.warn( + "Feature Flagging agentless configuration requires DD_API_KEY for the Datadog endpoint"); + } + // Complete the first poll cycle on the activation thread. This lets OpenFeature provider // initialization observe a successful retry before it checks whether configuration is ready. // No request occurs before application code activates the provider. @@ -174,13 +190,15 @@ public void close() { activePollingThread.interrupt(); } executor.shutdownNow(); + LOGGER.debug("Feature Flagging agentless configuration source stopped"); } private void pollOnceSafely() { try { pollOnce(); } catch (final RuntimeException e) { - LOGGER.debug("Unexpected error while polling Feature Flagging HTTP configuration source", e); + LOGGER.debug( + "Feature Flagging agentless configuration poll failed: {}", e.getClass().getSimpleName()); } } @@ -203,9 +221,9 @@ private boolean fetchAndApply() { } catch (final IOException e) { if (!closed) { ratelimitedLogger.warn( - "Feature Flagging agentless endpoint request failed after {} attempts", + "Feature Flagging agentless endpoint request failed after {} attempts: {}", MAX_ATTEMPTS, - e); + e.getClass().getSimpleName()); } return false; } @@ -213,6 +231,8 @@ private boolean fetchAndApply() { private boolean apply(final UfcHttpResponse response) { if (response.status == HttpURLConnection.HTTP_NOT_MODIFIED) { + LOGGER.debug( + "Feature Flagging agentless configuration unchanged (HTTP 304); retaining current configuration"); return true; } if (response.status == HttpURLConnection.HTTP_UNAUTHORIZED @@ -222,21 +242,41 @@ private boolean apply(final UfcHttpResponse response) { response.status); return false; } - if (response.status != HttpURLConnection.HTTP_OK || response.body == null) { + if (response.status != HttpURLConnection.HTTP_OK) { + LOGGER.debug( + "Feature Flagging agentless configuration not applied: unexpected HTTP {}; retaining current configuration", + response.status); + return false; + } + if (response.body == null) { + LOGGER.debug( + "Feature Flagging agentless configuration rejected: missing response body; retaining current configuration"); return false; } final ServerConfiguration configuration; try { configuration = JsonApiUfcResponseParser.INSTANCE.parse(response.body); } catch (final IOException | RuntimeException e) { - LOGGER.debug("Feature Flagging HTTP configuration source returned malformed UFC payload", e); + LOGGER.debug( + "Feature Flagging agentless configuration rejected: malformed UFC payload ({}); retaining current configuration", + e.getClass().getSimpleName()); return false; } if (configuration == null) { + LOGGER.debug( + "Feature Flagging agentless configuration rejected: missing UFC data or flags; retaining current configuration"); return false; } FeatureFlaggingGateway.dispatch(configuration); updateEtag(response.etag); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging agentless configuration applied: flags={}, env={}, configurationEnv={}, createdAt={}", + configuration.flags == null ? 0 : configuration.flags.size(), + config.getEnv(), + configuration.environment == null ? null : configuration.environment.name, + configuration.createdAt); + } return true; } @@ -261,7 +301,7 @@ private static HttpUrl endpointFromConfiguredBaseUrl(final String configuredBase final HttpUrl parsed = HttpUrl.parse(configuredBaseUrl.trim()); if (parsed == null) { throw new IllegalArgumentException( - "Invalid Feature Flagging HTTP configuration source URL: " + configuredBaseUrl); + "Invalid Feature Flagging HTTP configuration source URL; verify DD_FEATURE_FLAGS_CONFIGURATION_SOURCE_AGENTLESS_BASE_URL"); } if ("/".equals(parsed.encodedPath()) || parsed.encodedPath().isEmpty()) { return parsed @@ -391,6 +431,7 @@ public HttpRetryPolicy create() { if (cancelled.get()) { call.cancel(); } + LOGGER.debug("Feature Flagging agentless configuration poll request starting"); return call; }; return sendWithRetries( @@ -399,6 +440,10 @@ public HttpRetryPolicy create() { request, response -> { final int status = response.code(); + if (response.isSuccessful()) { + LOGGER.debug( + "Feature Flagging agentless configuration poll returned HTTP {}", status); + } final String responseEtag = response.header("ETag"); try (ResponseBody responseBody = response.body()) { final byte[] body = responseBody != null ? responseBody.bytes() : null; @@ -453,6 +498,13 @@ static final class AgentlessRetryPolicy extends HttpRetryPolicy { @Override public boolean shouldRetry(final Exception exception) { + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging agentless configuration poll attempt {}/{} failed: {}", + retryAttempt + 1, + MAX_ATTEMPTS, + exception.getClass().getSimpleName()); + } return exception instanceof IOException && !Thread.currentThread().isInterrupted() && reserveRetry(); @@ -460,6 +512,13 @@ public boolean shouldRetry(final Exception exception) { @Override public boolean shouldRetry(@Nullable final Response response) { + if (response != null && LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging agentless configuration poll attempt {}/{} returned HTTP {}", + retryAttempt + 1, + MAX_ATTEMPTS, + response.code()); + } return response != null && isRetryableStatus(response.code()) && reserveRetry(); } @@ -478,8 +537,10 @@ public void backoff() throws IOException { throw new InterruptedIOException("Feature Flagging HTTP client is closed"); } try { - retrySleeper.sleep( - retryDelayMillis(pollIntervalMillis, retryAttempt, jitter.getAsDouble())); + final long delayMillis = + retryDelayMillis(pollIntervalMillis, retryAttempt, jitter.getAsDouble()); + LOGGER.debug("Feature Flagging agentless configuration retry in {} ms", delayMillis); + retrySleeper.sleep(delayMillis); } catch (final InterruptedException e) { Thread.currentThread().interrupt(); throw new InterruptedIOException("Feature Flagging retry interrupted"); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java index 0584e5701ad..093d69700bd 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java @@ -9,6 +9,7 @@ import datadog.common.queue.MessagePassingBlockingQueue; import datadog.common.queue.Queues; import datadog.communication.BackendApi; +import datadog.communication.HttpResponseException; import datadog.communication.ddagent.SharedCommunicationObjects; import datadog.trace.api.Config; import datadog.trace.api.featureflag.FeatureFlaggingGateway; @@ -160,7 +161,10 @@ public void accept(final ExposureEvent event) { // passes this check can race past the final drain and be dropped. Stale gateway dispatches // entering after shutdown starts are rejected without extending the shutdown wait. if (!closed.get()) { - queue.offer(event); + final boolean queued = queue.offer(event); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Feature Flagging exposure {}", queued ? "queued" : "dropped: queue full"); + } } } @@ -233,7 +237,8 @@ public void run() { } } } - LOGGER.debug("exposure processor worker exited. submitting exposures stopped."); + LOGGER.debug( + "Feature Flagging exposure processor stopped; pending exposures are not flushed on shutdown"); } private void runDutyCycle() throws InterruptedException { @@ -268,6 +273,7 @@ private boolean addToBuffer(final ExposureEvent event) { buffer.add(event); return true; } + LOGGER.debug("Feature Flagging exposure suppressed: duplicate"); return false; } @@ -286,16 +292,29 @@ private void flush() { final ExposuresRequest exposures = new ExposuresRequest(this.context, this.buffer); payload = evpPublisher.serialize(exposures); } catch (RuntimeException e) { - LOGGER.error(EXCLUDE_TELEMETRY, "Could not serialize exposures; dropping batch", e); + LOGGER.error( + EXCLUDE_TELEMETRY, + "Could not serialize exposures; dropping batch: {}", + e.getClass().getSimpleName()); this.buffer.clear(); return; } try { + LOGGER.debug("Feature Flagging exposure flush starting: count={}", this.buffer.size()); evpPublisher.post(EXPOSURES_ROUTE, payload); + LOGGER.debug("Feature Flagging exposure flush delivered: count={}", this.buffer.size()); } catch (AgentlessFeatureFlagBackendApi.UnavailableRouteException ignored) { // The shared selector reports unavailable/recovered transitions once for both writers. } catch (Exception e) { - LOGGER.debug("Could not submit exposures", e); + if (e instanceof HttpResponseException) { + LOGGER.debug( + "Feature Flagging exposure flush failed: HTTP {}; dropping batch", + ((HttpResponseException) e).getStatusCode()); + } else { + LOGGER.debug( + "Feature Flagging exposure flush failed: {}; dropping batch", + e.getClass().getSimpleName()); + } } finally { // Best-effort delivery must not retry an ambiguously accepted batch. A later definitive // proxy rejection could otherwise replay the same exposures through direct intake. diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java index e66a6231990..09b4718f35b 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java @@ -10,10 +10,14 @@ import datadog.trace.api.featureflag.FeatureFlaggingGateway; import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; import javax.annotation.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class RemoteConfigServiceImpl implements ConfigurationSourceService, ConfigurationChangesTypedListener { + private static final Logger LOGGER = LoggerFactory.getLogger(RemoteConfigServiceImpl.class); + private final ConfigurationPoller configurationPoller; public RemoteConfigServiceImpl(final SharedCommunicationObjects sco, final Config config) { @@ -22,6 +26,8 @@ public RemoteConfigServiceImpl(final SharedCommunicationObjects sco, final Confi @Override public void init() { + LOGGER.debug( + "Feature Flagging starting remote_config configuration source (Agent Remote Configuration)"); configurationPoller.addCapabilities(Capabilities.CAPABILITY_FFE_FLAG_CONFIGURATION_RULES); configurationPoller.addListener(Product.FFE_FLAGS, UniversalFlagConfigParser.INSTANCE, this); configurationPoller.start(); @@ -32,6 +38,7 @@ public void close() { configurationPoller.removeCapabilities(Capabilities.CAPABILITY_FFE_FLAG_CONFIGURATION_RULES); configurationPoller.removeListeners(Product.FFE_FLAGS); configurationPoller.stop(); + LOGGER.debug("Feature Flagging remote_config configuration source stopped"); } @Override @@ -40,5 +47,15 @@ public void accept( @Nullable final ServerConfiguration configuration, final PollingRateHinter pollingRateHinter) { FeatureFlaggingGateway.dispatch(configuration); + if (configuration == null) { + LOGGER.debug("Feature Flagging remote_config configuration removed"); + } else if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging remote_config configuration applied: key={}, flags={}, env={}, createdAt={}", + configKey, + configuration.flags == null ? 0 : configuration.flags.size(), + configuration.environment == null ? null : configuration.environment.name, + configuration.createdAt); + } } } diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java index 27fd3f70c70..4eef0798481 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java @@ -75,6 +75,11 @@ public ServerConfiguration deserialize(final byte[] content) throws IOException final ServerConfiguration configuration = parse(reader); requireEndOfDocument(reader); return configuration; + } catch (IOException | RuntimeException e) { + LOGGER.debug( + "Feature Flagging remote_config configuration rejected: malformed UFC payload ({})", + e.getClass().getSimpleName()); + throw e; } } @@ -381,9 +386,9 @@ public Map fromJson(@Nonnull final JsonReader reader) throws IOExc INVALID_FLAGS_HOLDER.get().put(flagKey, INVALID_SEMVER_COMPARAND); } LOGGER.warn( - "Dropping malformed FFE flag {} during remote config deserialization: {}", + "Feature Flagging rejected flag {} during configuration parsing: {}", flagKey, - error.toString()); + INVALID_FLAGS_HOLDER.get().get(flagKey)); } } reader.endObject(); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java index b02bd05642b..149d046dc56 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java @@ -15,6 +15,10 @@ import static org.mockito.Mockito.verifyNoInteractions; import static org.mockito.Mockito.when; +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; import datadog.communication.http.OkHttpUtils; import datadog.logging.RatelimitedLogger; import datadog.trace.agent.test.server.http.JavaTestHttpServer; @@ -49,12 +53,14 @@ import okhttp3.Response; import okhttp3.ResponseBody; import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Nested; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.mockito.ArgumentCaptor; import org.mockito.Mock; import org.mockito.junit.jupiter.MockitoExtension; +import org.slf4j.LoggerFactory; @ExtendWith(MockitoExtension.class) class AgentlessConfigurationSourceTest { @@ -793,9 +799,9 @@ void warnsRateLimitedAfterIoFailuresAreExhausted() throws Exception { assertEquals(3, requests.size()); verify(ratelimitedLogger) .warn( - "Feature Flagging agentless endpoint request failed after {} attempts", + "Feature Flagging agentless endpoint request failed after {} attempts: {}", 3, - finalFailure); + "SocketTimeoutException"); verifyNoInteractions(listener); } finally { service.close(); @@ -1204,6 +1210,122 @@ private static Response okHttpResponse( return builder.build(); } + @Nested + class Diagnostics { + private final Logger logger = + (Logger) LoggerFactory.getLogger(AgentlessConfigurationSource.class); + private final ListAppender appender = new ListAppender<>(); + private Level previousLevel; + + @BeforeEach + void captureLogs() { + previousLevel = logger.getLevel(); + logger.setLevel(Level.DEBUG); + appender.start(); + logger.addAppender(appender); + } + + @AfterEach + void restoreLogging() { + logger.detachAppender(appender); + appender.stop(); + logger.setLevel(previousLevel); + } + + @Test + void reportsAppliedUnchangedAndRejectedConfigurationWithoutPayloads() throws Exception { + final AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())) + .thenReturn( + response(200, "secret-etag", emptyConfig()), + response(304, null, null), + response(200, null, "{\"secret-payload\":")); + final ScheduledExecutorService executor = Executors.newSingleThreadScheduledExecutor(); + final AgentlessConfigurationSource service = + new AgentlessConfigurationSource( + HttpUrl.get("http://localhost" + CONFIG_PATH), + config("datadoghq.com", "production"), + 30_000, + client, + executor); + try { + assertTrue(service.pollOnce()); + assertTrue(service.pollOnce()); + assertFalse(service.pollOnce()); + assertLogged("configuration applied: flags=0, env=production, configurationEnv=Staging"); + assertLogged("configuration unchanged (HTTP 304)"); + assertLogged("configuration rejected: malformed UFC payload"); + assertEquals( + 1, + appender.list.stream() + .filter(e -> e.getFormattedMessage().contains("configuration applied:")) + .count()); + assertNoSecrets(); + } finally { + service.close(); + } + } + + @Test + void logsMissingCredentialsAndOnlyEndpointOrigin() throws Exception { + final Config config = config(); + when(config.getApiKey()).thenReturn(null); + final AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())).thenReturn(response(401, null, null)); + final ScheduledExecutorService executor = mock(ScheduledExecutorService.class); + final AgentlessConfigurationSource service = + new AgentlessConfigurationSource( + HttpUrl.get( + "https://secret-user:secret-password@example.com/secret-path?key=secret-query"), + config, + 30_000, + client, + executor); + try { + service.init(); + assertLogged("source at https://example.com:443"); + assertLogged("requires DD_API_KEY"); + assertLogged("HTTP 401; verify endpoint authentication"); + assertNoSecrets(); + } finally { + service.close(); + } + } + + @Test + void logsTransportFailureAndBackoffWithoutExceptionMessages() throws Exception { + final List requests = new ArrayList<>(); + final AgentlessConfigurationSource.OkHttpUfcHttpClient client = + scriptedClient( + requests, + delay -> {}, + () -> 1.0, + new SocketTimeoutException("secret-url"), + response(503, null, null), + response(200, null, emptyConfig())); + client.fetch(HttpUrl.get("https://example.com"), config(), null); + assertLogged("attempt 1/3 failed: SocketTimeoutException"); + assertLogged("attempt 2/3 returned HTTP 503"); + assertLogged("retry in 5000 ms"); + assertLogged("returned HTTP 200"); + assertNoSecrets(); + } + + private void assertLogged(final String text) { + assertTrue( + appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(text)), text); + } + + private void assertNoSecrets() { + for (final ILoggingEvent event : appender.list) { + assertFalse(event.getFormattedMessage().contains("secret")); + assertNull(event.getThrowableProxy()); + } + } + } + private static Config config() { return config("datadoghq.com", ""); } diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java index ca12d057578..508fb30a899 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java @@ -26,6 +26,10 @@ import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; import com.squareup.moshi.JsonAdapter; import com.squareup.moshi.Moshi; import datadog.common.queue.MessagePassingBlockingQueue; @@ -51,6 +55,7 @@ import datadog.trace.api.intake.Intake; import datadog.trace.test.util.PollingConditions; import java.io.ByteArrayInputStream; +import java.io.IOException; import java.net.ConnectException; import java.net.SocketTimeoutException; import java.util.ArrayList; @@ -65,6 +70,7 @@ import java.util.UUID; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.concurrent.CopyOnWriteArrayList; import java.util.concurrent.CountDownLatch; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; @@ -80,6 +86,7 @@ import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.mockito.ArgumentCaptor; +import org.slf4j.LoggerFactory; import org.tabletest.junit.TableTest; class ExposureWriterTests { @@ -168,6 +175,54 @@ void testExposureEventWrites(String service, String env, String version) throws } } + @TableTest({ + "Scenario | Fails | Outcome ", + "Successful delivery | false | 'flush delivered' ", + "Failed delivery | true | 'flush failed: IOException; dropping batch'" + }) + void distinguishesQueuedFromDeliveredExposures(String scenario, boolean fails, String outcome) + throws Exception { + Logger logger = (Logger) LoggerFactory.getLogger(ExposureWriterImpl.class); + Level previousLevel = logger.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.list = new CopyOnWriteArrayList<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.DEBUG); + BackendApi backend = mock(BackendApi.class); + if (fails) { + when(backend.post(any(), any(), any(), any(), eq(false))) + .thenThrow(new IOException("secret-response")); + } + Config config = mockConfig("test-service"); + BackendApiFactory backendApiFactory = mock(BackendApiFactory.class); + when(backendApiFactory.createEvpProxyApi(Intake.EVENT_PLATFORM, true)).thenReturn(backend); + FeatureFlagBackendApiFactory factory = + new FeatureFlagBackendApiFactory(config, backendApiFactory, FeatureFlagEventType.EXPOSURE); + ExposureWriterImpl writer = new ExposureWriterImpl(16, 1, MILLISECONDS, factory, config); + try { + writer.init(); + writer.accept(buildExposures(1).get(0)); + poll.eventually( + () -> + assertTrue( + appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(outcome)))); + assertTrue( + appender.list.stream() + .anyMatch(e -> e.getFormattedMessage().contains("exposure queued"))); + assertEquals( + !fails, + appender.list.stream() + .anyMatch(e -> e.getFormattedMessage().contains("flush delivered"))); + assertFalse(appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains("secret"))); + } finally { + writer.close(); + logger.detachAppender(appender); + logger.setLevel(previousLevel); + appender.stop(); + } + } + @Test void testExposureRequestsCarrySdkIdentity() throws Exception { // Exercise the production writer and factory on the fixed Remote Config EVP v2 route. From 334209bf01cad36d67ff51da6d2797e36018e268 Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Thu, 15 Oct 2026 19:44:53 +0000 Subject: [PATCH 2/9] Restore feature flag failure details and error telemetry --- .../feature-flagging-api/README.md | 10 ++- .../AgentlessConfigurationSource.java | 16 ++-- .../featureflag/ExposureWriterImpl.java | 11 ++- .../UniversalFlagConfigParser.java | 18 ++-- .../AgentlessConfigurationSourceTest.java | 83 +++++++++++++++---- .../featureflag/ExposureWriterTests.java | 37 ++++++++- .../JsonApiUfcResponseParserTest.java | 43 ++++++++++ 7 files changed, 175 insertions(+), 43 deletions(-) diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index 079027d7fee..8a0e2d19f91 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -267,7 +267,7 @@ Look for messages prefixed with `Feature Flagging`: - Startup reports the configuration source and effective environment. Agentless startup reports the endpoint origin and polling settings, and warns if the Datadog endpoint requires a missing `DD_API_KEY`. -- Polling reports HTTP status, transport exception type, and retry delay. `unchanged` means HTTP +- Polling reports HTTP status, transport exception details, and retry delay. `unchanged` means HTTP 304; `applied` appears only after configuration dispatch succeeds. Rejected responses retain the current configuration. Remote Config removal and provider recovery are logged separately. - Evaluations report the flag key, variant, reason, and error code. An `ERROR` reason identifies @@ -279,9 +279,11 @@ Look for messages prefixed with `Feature Flagging`: The exposure writer currently stops without flushing pending exposures on shutdown; its stop message makes that limitation explicit. -Endpoint paths, queries, credentials, response bodies, and raw transport/parse error messages are -omitted from these configuration diagnostics. Per-evaluation and per-exposure debug logs can be -verbose; disable DEBUG after troubleshooting. +Endpoint startup logs include only the origin, and configuration payloads are not logged directly. +Transport failures and rejected configurations retain exception details and stack traces for +troubleshooting and agent error telemetry. Rejected-flag warnings include the structural reason, +but omit invalid semantic-version comparand values. Per-evaluation and per-exposure debug logs +can be verbose; disable DEBUG after troubleshooting. Coverage follows the [SDK debug logging checklist](https://datadoghq.atlassian.net/wiki/spaces/PANA/pages/7276692209) and the [Node.js reference implementation](https://github.com/DataDog/dd-trace-js/pull/10468). diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java index 9cbd32022d1..d583a7a20dc 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java @@ -198,7 +198,9 @@ private void pollOnceSafely() { pollOnce(); } catch (final RuntimeException e) { LOGGER.debug( - "Feature Flagging agentless configuration poll failed: {}", e.getClass().getSimpleName()); + "Feature Flagging agentless configuration poll failed: {}", + e.getClass().getSimpleName(), + e); } } @@ -221,9 +223,11 @@ private boolean fetchAndApply() { } catch (final IOException e) { if (!closed) { ratelimitedLogger.warn( - "Feature Flagging agentless endpoint request failed after {} attempts: {}", + "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}", MAX_ATTEMPTS, - e.getClass().getSimpleName()); + e.getClass().getSimpleName(), + e.getMessage(), + e); } return false; } @@ -259,7 +263,8 @@ private boolean apply(final UfcHttpResponse response) { } catch (final IOException | RuntimeException e) { LOGGER.debug( "Feature Flagging agentless configuration rejected: malformed UFC payload ({}); retaining current configuration", - e.getClass().getSimpleName()); + e.getClass().getSimpleName(), + e); return false; } if (configuration == null) { @@ -503,7 +508,8 @@ public boolean shouldRetry(final Exception exception) { "Feature Flagging agentless configuration poll attempt {}/{} failed: {}", retryAttempt + 1, MAX_ATTEMPTS, - exception.getClass().getSimpleName()); + exception.getClass().getSimpleName(), + exception); } return exception instanceof IOException && !Thread.currentThread().isInterrupted() diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java index 093d69700bd..8aaa498d334 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java @@ -292,10 +292,7 @@ private void flush() { final ExposuresRequest exposures = new ExposuresRequest(this.context, this.buffer); payload = evpPublisher.serialize(exposures); } catch (RuntimeException e) { - LOGGER.error( - EXCLUDE_TELEMETRY, - "Could not serialize exposures; dropping batch: {}", - e.getClass().getSimpleName()); + LOGGER.error(EXCLUDE_TELEMETRY, "Could not serialize exposures; dropping batch", e); this.buffer.clear(); return; } @@ -309,11 +306,13 @@ private void flush() { if (e instanceof HttpResponseException) { LOGGER.debug( "Feature Flagging exposure flush failed: HTTP {}; dropping batch", - ((HttpResponseException) e).getStatusCode()); + ((HttpResponseException) e).getStatusCode(), + e); } else { LOGGER.debug( "Feature Flagging exposure flush failed: {}; dropping batch", - e.getClass().getSimpleName()); + e.getClass().getSimpleName(), + e); } } finally { // Best-effort delivery must not retry an ambiguously accepted batch. A later definitive diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java index 4eef0798481..073f8e2212c 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java @@ -78,7 +78,8 @@ public ServerConfiguration deserialize(final byte[] content) throws IOException } catch (IOException | RuntimeException e) { LOGGER.debug( "Feature Flagging remote_config configuration rejected: malformed UFC payload ({})", - e.getClass().getSimpleName()); + e.getClass().getSimpleName(), + e); throw e; } } @@ -240,9 +241,7 @@ private static void validateAndCacheSemverComparands(final String flagKey, final + allocIdx + " rule has condition with operator \"" + condition.operator - + "\" and invalid semantic version \"" - + condition.value - + "\""); + + "\" and invalid semantic version"); } condition.semverComparand = parsed; break; @@ -381,14 +380,15 @@ public Map fromJson(@Nonnull final JsonReader reader) throws IOExc flags.put(flagKey, flag); } } catch (JsonDataException | IllegalArgumentException error) { - INVALID_FLAGS_HOLDER.get().put(flagKey, INVALID_FLAG); - if (error instanceof InvalidSemverComparandException) { - INVALID_FLAGS_HOLDER.get().put(flagKey, INVALID_SEMVER_COMPARAND); - } + final String reason = + error instanceof InvalidSemverComparandException + ? INVALID_SEMVER_COMPARAND + : INVALID_FLAG; + INVALID_FLAGS_HOLDER.get().put(flagKey, reason); LOGGER.warn( "Feature Flagging rejected flag {} during configuration parsing: {}", flagKey, - INVALID_FLAGS_HOLDER.get().get(flagKey)); + error.toString()); } } reader.endObject(); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java index 149d046dc56..b3e2eb9316c 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java @@ -4,7 +4,9 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertInstanceOf; +import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertSame; import static org.junit.jupiter.api.Assertions.assertThrows; import static org.junit.jupiter.api.Assertions.assertTrue; import static org.mockito.ArgumentMatchers.any; @@ -18,6 +20,7 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.ThrowableProxy; import ch.qos.logback.core.read.ListAppender; import datadog.communication.http.OkHttpUtils; import datadog.logging.RatelimitedLogger; @@ -45,6 +48,7 @@ import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; import java.util.zip.GZIPOutputStream; +import javax.net.ssl.SSLHandshakeException; import okhttp3.Call; import okhttp3.HttpUrl; import okhttp3.MediaType; @@ -799,9 +803,11 @@ void warnsRateLimitedAfterIoFailuresAreExhausted() throws Exception { assertEquals(3, requests.size()); verify(ratelimitedLogger) .warn( - "Feature Flagging agentless endpoint request failed after {} attempts: {}", + "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}", 3, - "SocketTimeoutException"); + "SocketTimeoutException", + finalFailure.getMessage(), + finalFailure); verifyNoInteractions(listener); } finally { service.close(); @@ -1233,7 +1239,7 @@ void restoreLogging() { } @Test - void reportsAppliedUnchangedAndRejectedConfigurationWithoutPayloads() throws Exception { + void reportsAppliedUnchangedAndRejectedConfigurationWithParseFailure() throws Exception { final AgentlessConfigurationSource.UfcHttpClient client = mock(AgentlessConfigurationSource.UfcHttpClient.class); when(client.fetch(any(), any(), any())) @@ -1255,13 +1261,14 @@ void reportsAppliedUnchangedAndRejectedConfigurationWithoutPayloads() throws Exc assertFalse(service.pollOnce()); assertLogged("configuration applied: flags=0, env=production, configurationEnv=Staging"); assertLogged("configuration unchanged (HTTP 304)"); - assertLogged("configuration rejected: malformed UFC payload"); + assertNotNull( + assertLogged("configuration rejected: malformed UFC payload").getThrowableProxy()); assertEquals( 1, appender.list.stream() .filter(e -> e.getFormattedMessage().contains("configuration applied:")) .count()); - assertNoSecrets(); + assertNoSecretsInFormattedMessages(); } finally { service.close(); } @@ -1288,40 +1295,86 @@ void logsMissingCredentialsAndOnlyEndpointOrigin() throws Exception { assertLogged("source at https://example.com:443"); assertLogged("requires DD_API_KEY"); assertLogged("HTTP 401; verify endpoint authentication"); - assertNoSecrets(); + assertNoSecretsInFormattedMessages(); } finally { service.close(); } } @Test - void logsTransportFailureAndBackoffWithoutExceptionMessages() throws Exception { + void logsTransportFailureAndBackoffWithExceptionDetails() throws Exception { final List requests = new ArrayList<>(); + final SocketTimeoutException failure = new SocketTimeoutException("read timed out"); final AgentlessConfigurationSource.OkHttpUfcHttpClient client = scriptedClient( requests, delay -> {}, () -> 1.0, - new SocketTimeoutException("secret-url"), + failure, response(503, null, null), response(200, null, emptyConfig())); client.fetch(HttpUrl.get("https://example.com"), config(), null); - assertLogged("attempt 1/3 failed: SocketTimeoutException"); + assertSame( + failure, + ((ThrowableProxy) + assertLogged("attempt 1/3 failed: SocketTimeoutException").getThrowableProxy()) + .getThrowable()); assertLogged("attempt 2/3 returned HTTP 503"); assertLogged("retry in 5000 ms"); assertLogged("returned HTTP 200"); - assertNoSecrets(); } - private void assertLogged(final String text) { - assertTrue( - appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(text)), text); + @Test + void retainsTransportRootCauseAtWarnWhenDebugIsDisabled() throws Exception { + logger.setLevel(Level.WARN); + final SSLHandshakeException failure = new SSLHandshakeException("PKIX path building failed"); + final AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())).thenThrow(failure); + try (AgentlessConfigurationSource service = service(client)) { + assertFalse(service.pollOnce()); + final ILoggingEvent event = + assertLogged("SSLHandshakeException: PKIX path building failed"); + assertEquals(Level.WARN, event.getLevel()); + assertSame(failure, ((ThrowableProxy) event.getThrowableProxy()).getThrowable()); + } + } + + @Test + void retainsListenerFailureForErrorTelemetry() throws Exception { + final IllegalStateException failure = + new IllegalStateException("listener rejected configuration"); + final FeatureFlaggingGateway.ConfigListener failingListener = + configuration -> { + throw failure; + }; + FeatureFlaggingGateway.addConfigListener(failingListener); + final AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())).thenReturn(response(200, null, emptyConfig())); + try (AgentlessConfigurationSource service = service(client)) { + service.init(); + assertSame( + failure, + ((ThrowableProxy) + assertLogged("configuration poll failed: IllegalStateException") + .getThrowableProxy()) + .getThrowable()); + } finally { + FeatureFlaggingGateway.removeConfigListener(failingListener); + } + } + + private ILoggingEvent assertLogged(final String text) { + return appender.list.stream() + .filter(e -> e.getFormattedMessage().contains(text)) + .findFirst() + .orElseThrow(() -> new AssertionError("Missing log: " + text)); } - private void assertNoSecrets() { + private void assertNoSecretsInFormattedMessages() { for (final ILoggingEvent event : appender.list) { assertFalse(event.getFormattedMessage().contains("secret")); - assertNull(event.getThrowableProxy()); } } } diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java index 508fb30a899..d1a354c60f0 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java @@ -15,6 +15,7 @@ import static org.junit.jupiter.api.Assertions.assertNotEquals; import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertSame; import static org.junit.jupiter.api.Assertions.assertTrue; import static org.mockito.AdditionalAnswers.delegatesTo; import static org.mockito.ArgumentMatchers.any; @@ -29,6 +30,7 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.ThrowableProxy; import ch.qos.logback.core.read.ListAppender; import com.squareup.moshi.JsonAdapter; import com.squareup.moshi.Moshi; @@ -190,9 +192,9 @@ void distinguishesQueuedFromDeliveredExposures(String scenario, boolean fails, S logger.addAppender(appender); logger.setLevel(Level.DEBUG); BackendApi backend = mock(BackendApi.class); + IOException failure = new IOException("connection reset"); if (fails) { - when(backend.post(any(), any(), any(), any(), eq(false))) - .thenThrow(new IOException("secret-response")); + when(backend.post(any(), any(), any(), any(), eq(false))).thenThrow(failure); } Config config = mockConfig("test-service"); BackendApiFactory backendApiFactory = mock(BackendApiFactory.class); @@ -214,7 +216,14 @@ void distinguishesQueuedFromDeliveredExposures(String scenario, boolean fails, S !fails, appender.list.stream() .anyMatch(e -> e.getFormattedMessage().contains("flush delivered"))); - assertFalse(appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains("secret"))); + if (fails) { + ILoggingEvent event = + appender.list.stream() + .filter(e -> e.getFormattedMessage().contains(outcome)) + .findFirst() + .get(); + assertSame(failure, ((ThrowableProxy) event.getThrowableProxy()).getThrowable()); + } } finally { writer.close(); logger.detachAppender(appender); @@ -630,16 +639,36 @@ void testHttpFailureIsNotRetriedAtTransportLayer() throws Exception { void testSerializationFailureDoesNotPoisonFollowingExposures() throws Exception { Config config = mockConfig("test-service"); ExposureEvent validExposure = buildExposure(); + Logger logger = (Logger) LoggerFactory.getLogger(ExposureWriterImpl.class); + Level previousLevel = logger.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.list = new CopyOnWriteArrayList<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.ERROR); try (ExposureWriterImpl writer = new ExposureWriterImpl(1 << 4, 100, MILLISECONDS, sharedCommunicationObjects, config)) { writer.init(); writer.accept(buildExposure(singletonMap("invalid", (Object) Double.NaN))); - MILLISECONDS.sleep(300); // wait for the invalid batch to be dropped + poll.eventually( + () -> { + assertEquals(1, appender.list.size()); + ILoggingEvent event = appender.list.get(0); + assertTrue(event.getFormattedMessage().contains("Could not serialize exposures")); + assertNotNull(event.getThrowableProxy()); + assertEquals( + IllegalArgumentException.class.getName(), event.getThrowableProxy().getClassName()); + assertTrue(event.getThrowableProxy().getMessage().contains("NaN")); + }); writer.accept(validExposure); poll.eventually(() -> assertExposures(allExposures(), singletonList(validExposure))); + } finally { + logger.detachAppender(appender); + appender.stop(); + logger.setLevel(previousLevel); } } diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java index fae2631ce2f..e233e0672bb 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java @@ -8,6 +8,10 @@ import static org.junit.jupiter.api.Assertions.assertThrows; import static org.junit.jupiter.api.Assertions.assertTrue; +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; import com.squareup.moshi.JsonQualifier; import com.squareup.moshi.Moshi; import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; @@ -21,9 +25,48 @@ import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.ValueSource; +import org.slf4j.LoggerFactory; class JsonApiUfcResponseParserTest { + @Test + void rejectedFlagWarningsRetainStructuralReasonsWithoutSemverComparands() throws Exception { + final Logger logger = (Logger) LoggerFactory.getLogger(UniversalFlagConfigParser.class); + final Level previousLevel = logger.getLevel(); + final ListAppender appender = new ListAppender<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.WARN); + try { + final ServerConfiguration configuration = + parse( + wrap( + configWithFlags( + booleanFlag( + "missing-shards", + ",\"allocations\":[{\"key\":\"allocation\",\"splits\":[{}]}]"), + booleanFlag( + "invalid-semver", + allocation( + "allocation", + "[{\"conditions\":[{\"attribute\":\"version\",\"operator\":\"SEMVER_EQ\",\"value\":\"secret-comparand\"}]}]"))))); + + assertEquals("invalid_flag", configuration.invalidFlags.get("missing-shards")); + assertEquals("invalid_semver_comparand", configuration.invalidFlags.get("invalid-semver")); + assertEquals(2, appender.list.size()); + assertTrue(appender.list.get(0).getFormattedMessage().contains("InvalidFlagException:")); + assertTrue(appender.list.get(0).getFormattedMessage().contains("split with missing shards")); + assertTrue( + appender.list.get(1).getFormattedMessage().contains("InvalidSemverComparandException:")); + assertTrue(appender.list.get(1).getFormattedMessage().contains("invalid semantic version")); + assertFalse(appender.list.get(1).getFormattedMessage().contains("secret-comparand")); + } finally { + logger.detachAppender(appender); + appender.stop(); + logger.setLevel(previousLevel); + } + } + @Test void parsesJsonApiMembersInAnyOrder() throws Exception { final ServerConfiguration configuration = From 4f27f55cc0abddbed154540bf5655c0bc845ca2b Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Thu, 15 Oct 2026 20:59:40 +0000 Subject: [PATCH 3/9] Cover feature flag diagnostic branches on JVM 8 --- .../AgentlessConfigurationSource.java | 2 +- .../AgentlessConfigurationSourceTest.java | 41 ++++++++++ .../featureflag/ExposureWriterTests.java | 45 +++++++++-- .../RemoteConfigServiceImplTest.java | 81 +++++++++++++++++++ 4 files changed, 163 insertions(+), 6 deletions(-) diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java index d583a7a20dc..d037d247433 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java @@ -277,7 +277,7 @@ private boolean apply(final UfcHttpResponse response) { if (LOGGER.isDebugEnabled()) { LOGGER.debug( "Feature Flagging agentless configuration applied: flags={}, env={}, configurationEnv={}, createdAt={}", - configuration.flags == null ? 0 : configuration.flags.size(), + configuration.flags.size(), config.getEnv(), configuration.environment == null ? null : configuration.environment.name, configuration.createdAt); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java index b3e2eb9316c..1b5dc7cc030 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java @@ -1274,6 +1274,47 @@ void reportsAppliedUnchangedAndRejectedConfigurationWithParseFailure() throws Ex } } + @Test + void reportsAppliedConfigurationWithoutEnvironment() throws Exception { + final AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())) + .thenReturn( + response( + 200, null, jsonApiResponse("universal-flag-configuration", "{\"flags\":{}}"))); + try (AgentlessConfigurationSource service = service(client)) { + assertTrue(service.pollOnce()); + assertLogged("configuration applied: flags=0, env=, configurationEnv=null, createdAt=null"); + } + } + + @Test + void omitsDebugDetailsAndApiKeyWarningForConfiguredEndpoint() throws Exception { + logger.setLevel(Level.INFO); + final Config config = config(); + when(config.getFeatureFlaggingConfigurationSourceAgentlessBaseUrl()) + .thenReturn("https://flags.example.com"); + lenient().when(config.getApiKey()).thenReturn(null); + final AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())).thenReturn(response(200, null, emptyConfig())); + FeatureFlaggingGateway.addConfigListener(listener); + final AgentlessConfigurationSource service = + new AgentlessConfigurationSource( + HttpUrl.get("https://flags.example.com" + CONFIG_PATH), + config, + 30_000, + client, + mock(ScheduledExecutorService.class)); + try { + service.init(); + verify(listener).accept(any(ServerConfiguration.class)); + assertTrue(appender.list.isEmpty()); + } finally { + service.close(); + } + } + @Test void logsMissingCredentialsAndOnlyEndpointOrigin() throws Exception { final Config config = config(); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java index d1a354c60f0..f29ea8e17e8 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java @@ -38,6 +38,7 @@ import datadog.common.queue.Queues; import datadog.communication.BackendApi; import datadog.communication.BackendApiFactory; +import datadog.communication.HttpResponseException; import datadog.communication.IntakeApi; import datadog.communication.ddagent.DDAgentFeaturesDiscovery; import datadog.communication.ddagent.SharedCommunicationObjects; @@ -178,11 +179,12 @@ void testExposureEventWrites(String service, String env, String version) throws } @TableTest({ - "Scenario | Fails | Outcome ", - "Successful delivery | false | 'flush delivered' ", - "Failed delivery | true | 'flush failed: IOException; dropping batch'" + "Scenario | Fails | Status | Outcome ", + "Successful delivery | false | | 'flush delivered' ", + "Transport failure | true | | 'flush failed: IOException; dropping batch'", + "HTTP rejection | true | 403 | 'flush failed: HTTP 403; dropping batch' " }) - void distinguishesQueuedFromDeliveredExposures(String scenario, boolean fails, String outcome) + void distinguishesQueuedFromDeliveredExposures(boolean fails, Integer status, String outcome) throws Exception { Logger logger = (Logger) LoggerFactory.getLogger(ExposureWriterImpl.class); Level previousLevel = logger.getLevel(); @@ -192,7 +194,10 @@ void distinguishesQueuedFromDeliveredExposures(String scenario, boolean fails, S logger.addAppender(appender); logger.setLevel(Level.DEBUG); BackendApi backend = mock(BackendApi.class); - IOException failure = new IOException("connection reset"); + IOException failure = + status == null + ? new IOException("connection reset") + : new HttpResponseException(status, "exposure batch rejected"); if (fails) { when(backend.post(any(), any(), any(), any(), eq(false))).thenThrow(failure); } @@ -258,6 +263,36 @@ void testExposureRequestsCarrySdkIdentity() throws Exception { } } + @Test + void logsExposuresDroppedWhenQueueIsFull() { + Logger logger = (Logger) LoggerFactory.getLogger(ExposureWriterImpl.class); + Level previousLevel = logger.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.DEBUG); + Config config = mockConfig("test-service"); + + // The writer is not initialized, so no serializer thread drains the queue. + try (ExposureWriterImpl writer = + new ExposureWriterImpl(1 << 4, 100, MILLISECONDS, sharedCommunicationObjects, config)) { + for (ExposureEvent exposure : buildExposures(17)) { + writer.accept(exposure); + } + + assertEquals(16, writer.queueSize()); + assertEquals( + 1, + appender.list.stream() + .filter(e -> e.getFormattedMessage().contains("exposure dropped: queue full")) + .count()); + } finally { + logger.detachAppender(appender); + appender.stop(); + logger.setLevel(previousLevel); + } + } + @Test void testAgentlessExposureEventWritesDirectlyWithApiKey() throws Exception { Config config = mockConfig("test-service"); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java index f11816a9bc0..17ea30bbad3 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java @@ -17,6 +17,10 @@ import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; import com.squareup.moshi.JsonAdapter; import com.squareup.moshi.JsonReader; import com.squareup.moshi.JsonWriter; @@ -45,6 +49,8 @@ import java.util.Map; import okio.Buffer; import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Nested; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.params.ParameterizedTest; @@ -53,6 +59,7 @@ import org.mockito.Captor; import org.mockito.Mock; import org.mockito.junit.jupiter.MockitoExtension; +import org.slf4j.LoggerFactory; import org.tabletest.junit.TableTest; @ExtendWith(MockitoExtension.class) @@ -90,6 +97,80 @@ void testNewConfigReceived() throws Exception { verify(poller).removeListeners(Product.FFE_FLAGS); } + @Nested + class Diagnostics { + private final Logger logger = (Logger) LoggerFactory.getLogger(RemoteConfigServiceImpl.class); + private final ListAppender appender = new ListAppender<>(); + private Level previousLevel; + private RemoteConfigServiceImpl service; + + @BeforeEach + void captureLogs() { + previousLevel = logger.getLevel(); + logger.setLevel(Level.DEBUG); + appender.start(); + logger.addAppender(appender); + final SharedCommunicationObjects sco = mock(SharedCommunicationObjects.class); + when(sco.configurationPoller(any(Config.class))).thenReturn(mock(ConfigurationPoller.class)); + service = new RemoteConfigServiceImpl(sco, Config.get()); + FeatureFlaggingGateway.addConfigListener(listener); + } + + @AfterEach + void restoreLogging() { + FeatureFlaggingGateway.dispatch((ServerConfiguration) null); + logger.detachAppender(appender); + appender.stop(); + logger.setLevel(previousLevel); + } + + @Test + void reportsAppliedConfiguration() throws Exception { + final ServerConfiguration config = deserialize(emptyConfig()); + + service.accept("datadog/2/FFE_FLAGS/config/config", config, mock(PollingRateHinter.class)); + + verify(listener).accept(config); + assertLogged( + "configuration applied: key=datadog/2/FFE_FLAGS/config/config, flags=0, env=Test, createdAt=2024-04-17T19:40:53.716Z"); + } + + @Test + void reportsAppliedConfigurationWithoutFlagsOrEnvironment() { + final ServerConfiguration config = new ServerConfiguration(null, null, null, null, null); + + service.accept("config", config, mock(PollingRateHinter.class)); + + verify(listener).accept(config); + assertLogged("configuration applied: key=config, flags=0, env=null, createdAt=null"); + } + + @Test + void reportsRemovedConfiguration() { + service.accept("config", null, mock(PollingRateHinter.class)); + + verify(listener).accept(null); + assertLogged("configuration removed"); + } + + @Test + void omitsAppliedConfigurationDetailsWhenDebugIsDisabled() throws Exception { + logger.setLevel(Level.INFO); + final ServerConfiguration config = deserialize(emptyConfig()); + + service.accept("config", config, mock(PollingRateHinter.class)); + + verify(listener).accept(config); + assertTrue(appender.list.isEmpty()); + } + + private void assertLogged(final String text) { + assertTrue( + appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(text)), + "Missing log: " + text); + } + } + @Test void skipsMalformedFlagAllocationsAndKeepsValidFlag() throws Exception { final ServerConfiguration config = deserialize(resource("malformed-allocations.json")); From c3b331745420f689776bf7e57059c4581c16242b Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Wed, 21 Oct 2026 14:49:55 +0000 Subject: [PATCH 4/9] Complete feature flag evaluation and lifecycle diagnostics --- .../featureflag/FeatureFlaggingSystem.java | 5 +- .../feature-flagging-api/README.md | 153 +++++++++++--- .../trace/api/openfeature/DDEvaluator.java | 42 +++- .../api/openfeature/DebugLoggingHook.java | 90 ++++++++- .../api/openfeature/DiagnosticLogger.java | 115 +++++++++++ .../trace/api/openfeature/ExposureHook.java | 4 +- .../api/openfeature/ExposureLoggingHook.java | 7 +- .../api/openfeature/FlagEvalLoggingHook.java | 4 +- .../api/openfeature/FlagEvalMetrics.java | 4 +- .../trace/api/openfeature/Provider.java | 12 +- .../api/openfeature/SpanEnrichmentHook.java | 4 +- .../api/openfeature/DebugLoggingHookTest.java | 188 +++++++++++++++++- .../ExposureHookWithoutAgentTest.java | 3 +- .../AgentlessConfigurationSource.java | 61 ++++-- .../AgentlessFeatureFlagBackendApi.java | 6 +- .../datadog/featureflag/DiagnosticLogger.java | 117 +++++++++++ .../featureflag/ExposureWriterImpl.java | 18 +- .../FeatureFlagBackendApiFactory.java | 5 +- .../featureflag/FlagEvaluationWriterImpl.java | 5 +- .../featureflag/RemoteConfigServiceImpl.java | 10 +- .../SpanEnrichmentInterceptor.java | 5 +- .../featureflag/SpanEnrichmentWriter.java | 5 +- .../UniversalFlagConfigParser.java | 30 ++- .../AgentlessConfigurationSourceTest.java | 42 +++- .../featureflag/DiagnosticIsolationTest.java | 136 +++++++++++++ .../featureflag/ExposureWriterTests.java | 67 +++++++ .../JsonApiUfcResponseParserTest.java | 30 +++ .../RemoteConfigServiceImplTest.java | 5 +- 28 files changed, 1037 insertions(+), 136 deletions(-) create mode 100644 products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java create mode 100644 products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java create mode 100644 products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java diff --git a/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java b/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java index fb8561f3518..f73fa5f94c3 100644 --- a/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java +++ b/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java @@ -11,8 +11,6 @@ import datadog.trace.api.featureflag.config.FeatureFlaggingConfig; import datadog.trace.api.featureflag.flagevaluation.FlagEvaluationWriter; import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; public class FeatureFlaggingSystem { @@ -21,7 +19,8 @@ interface SystemInitializer { void initialize(SharedCommunicationObjects sco, Config config); } - private static final Logger LOGGER = LoggerFactory.getLogger(FeatureFlaggingSystem.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(FeatureFlaggingSystem.class); private static volatile ConfigurationSourceService CONFIG_SERVICE; private static volatile ExposureWriter EXPOSURE_WRITER; diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index 8a0e2d19f91..74d14311112 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -256,34 +256,125 @@ This setting stops exposures only. Flag evaluation events have their own setting ## Onboarding diagnostics -Enable `DD_TRACE_DEBUG=true` for the Java agent's configuration and exposure-delivery logs. -The provider uses the application's SLF4J backend: enable DEBUG for -`datadog.trace.api.openfeature` before constructing the provider to include initialization, -readiness changes, evaluation outcomes, and exposure suppression. The evaluation debug hook is -registered only when its logger is enabled; no additional feature flag setting is required. - -Look for messages prefixed with `Feature Flagging`: - -- Startup reports the configuration source and effective environment. Agentless startup reports - the endpoint origin and polling settings, and warns if the Datadog endpoint requires a missing - `DD_API_KEY`. -- Polling reports HTTP status, transport exception details, and retry delay. `unchanged` means HTTP - 304; `applied` appears only after configuration dispatch succeeds. Rejected responses retain - the current configuration. Remote Config removal and provider recovery are logged separately. -- Evaluations report the flag key, variant, reason, and error code. An `ERROR` reason identifies - fallback to the caller's default. Flag values, defaults, targeting keys and attributes, arbitrary - metadata, and error messages are omitted. Flag keys, variant identifiers, environment names, - configuration timestamps, and Remote Config keys are included for diagnosis. -- Exposure logs distinguish suppression, queueing, queue overflow, flush attempts, delivery, and - failed batches that are dropped. Queueing or dispatch to listeners does not confirm delivery. - The exposure writer currently stops without flushing pending exposures on shutdown; its stop - message makes that limitation explicit. - -Endpoint startup logs include only the origin, and configuration payloads are not logged directly. -Transport failures and rejected configurations retain exception details and stack traces for -troubleshooting and agent error telemetry. Rejected-flag warnings include the structural reason, -but omit invalid semantic-version comparand values. Per-evaluation and per-exposure debug logs -can be verbose; disable DEBUG after troubleshooting. - -Coverage follows the [SDK debug logging checklist](https://datadoghq.atlassian.net/wiki/spaces/PANA/pages/7276692209) -and the [Node.js reference implementation](https://github.com/DataDog/dd-trace-js/pull/10468). +Set `DD_TRACE_DEBUG=true` for the Java agent's configuration, writer, and transport logs. +Also enable DEBUG for `datadog.trace.api.openfeature` in the application's SLF4J backend **before +constructing `Provider`**. The provider and agent have separate logging backends; +`DD_TRACE_DEBUG` does not change application logger levels. No additional flag evaluation data +setting is required for raw debug logs, including when `observe_full_evaluation_data` is false. +That metadata setting continues to govern evaluation telemetry independently. + +For an application using Logback, save this as `logback-ffe-debug.xml`: + +```xml + + + System.err + + %date %-5level %logger - %msg%n%ex + + + + + + + +``` + +Launch the application with its existing SLF4J binding on the classpath: + +```shell +DD_TRACE_DEBUG=true \ +DD_FEATURE_FLAGS_ENABLED=true \ +DD_FEATURE_FLAGS_CONFIGURATION_SOURCE=agentless \ +DD_ENV=production \ +java -javaagent:/path/to/dd-java-agent.jar \ + -Dlogback.configurationFile=/path/to/logback-ffe-debug.xml \ + -jar application.jar 2>ffe-debug.log +``` + +For the managed agentless endpoint, supply `DD_API_KEY` through the environment. For a custom +endpoint, set `DD_FEATURE_FLAGS_CONFIGURATION_SOURCE_AGENTLESS_BASE_URL`; the SDK does not append +`DD_ENV` to that URL. For Agent delivery, use `DD_FEATURE_FLAGS_CONFIGURATION_SOURCE=remote_config` +and `DD_REMOTE_CONFIG_ENABLED=true`, with the Datadog Agent reachable from the application. +Register the provider with `setProviderAndWait` after logging has been configured, then evaluate +flags. With `slf4j-simple` instead of Logback, use +`-Dorg.slf4j.simpleLogger.log.datadog.trace.api.openfeature=debug` before provider construction. +With another binding, configure that category at DEBUG and allow it through appender filters. + +Both the agent's default output and the Logback example above go to stderr. Keep the full +`ffe-debug.log`: filtering only for `Feature Flagging` loses shared Remote Config and HTTP +transport logs. Relevant categories are `datadog.trace.api.openfeature` (provider), +`com.datadog.featureflag` (configuration and writers), `datadog.remoteconfig` +(Agent configuration polling), and `datadog.communication` (transport and delivery). +Agent Remote Config logs describe the Java tracer's connection to the Agent; use the Datadog +Agent's own logs to diagnose its upstream authentication and configuration fetches. + +Look for these diagnostic boundaries: + +- Setup names the source, SDK environment, timeouts, endpoint origin, and credential problems. + Agentless startup labels `requestedEnv` from the URL separately from `env`; application logs + label the delivered `configurationEnv`. `endpointMode=custom` means the SDK did not append + `DD_ENV`, even if the supplied URL already contains a `dd_env` query parameter. +- Parsing reports usable and rejected flag counts. Application reports include the configuration's + creation time, agentless ETag or Remote Config key where available. `flags=0` on an applied + configuration means an available empty configuration; a missing configuration is reported + separately. Failed refreshes report retention of the previous configuration. HTTP attempts, + retry delays, exhaustion, unchanged responses, and subsequent application are logged. +- Provider initialization reports its timeout budget, initial availability, terminal outcome, + and unavailable/recovered transitions. +- `provider resolution` records effective targeting inputs, raw default and resolved values, + variant, reason, errors, metadata, and the identity of the configuration used for that resolution. + Raw resolution errors are logged before any telemetry-specific error-message filtering. + `evaluation observed at finallyAfter` records the SDK details visible to that hook, including + fallback after an application `after` hook fails. It is an observation at that point: later + `finallyAfter` hooks can still mutate details, so it does not claim the application's final return. +- Values and context are not truncated or redacted. OpenFeature's conversion methods expand nested + lists and structures. If conversion or formatting fails (including cycles or excessive nesting + that exhaust the JVM stack), a `diagnostic formatting failed; raw detail unavailable` message is + attempted. The evaluation proceeds unchanged. Backend filters, sinks, and log collectors can + impose their own limits, so check those when collecting large values. +- Exposures report suppression reasons, queueing, overflow, flush counts, delivery, and failed + batches that are dropped. Dispatch to listeners and queueing do not confirm delivery. +- Provider shutdown detaches its configuration listener; the Java agent owns the configuration + source and exposure writer. Exposure shutdown reports queued work and whether a request is in + flight. Pending exposures are **not flushed**. The processor reports completion separately, + after any in-flight delivery outcome, with the counts left in its queue and buffer. + +To disable these diagnostics, turn off `DD_TRACE_DEBUG`, restore the application category to INFO, +and recreate the provider. When DEBUG is off, raw values and context are not traversed or formatted. +Logger and diagnostic formatting failures are isolated from provider and delivery behavior. + +### Java scenario coverage + +The implementation assessment below follows the shared A–K matrix. **Present means source coverage, +not certification that every acceptance scenario has passed against a deployed Agent or endpoint.** + +| Scenario | Assessment | Implementation / focused test evidence | +|---|---|---| +| A. Setup/settings | Present | `FeatureFlaggingSystem`, source startup and credential diagnostics | +| B. Fetch/failure/retry | Present | `AgentlessConfigurationSourceTest`, shared Remote Config/transport logs | +| C. Usable configuration + identity | Present | Parser summaries, `RemoteConfigServiceImplTest`, agentless apply/retain/ETag logs | +| D. Environment mismatch | Present | Separate SDK, URL-requested and delivered environment fields | +| E. Readiness/recovery | Present | `ProviderTest`, initial subscription availability and recovery logs | +| F. Raw evaluation details | Present | `DebugLoggingHookTest`: raw values, nested objects, defaults, context, errors, hook failure, configuration identity | +| G. Exposure lifecycle | Present | `ExposureWriterTests`, provider suppression and listener dispatch logs | +| H. Shutdown outcome | Present | Source stop, provider detach, exposure shutdown request and worker completion/delivery logs | +| I. Enable/find logs | Present | Exact startup switches, SLF4J configuration, categories and destinations above | +| J. Debug-off overhead | Present | Hook registration gate and tests that forbid context/result inspection with DEBUG off | +| K. Logger-failure isolation | Present | `DebugLoggingHookTest` and `DiagnosticIsolationTest`: throwing backends and level checks across lifecycle and delivery | + +Run the focused suites with: + +```shell +git submodule update --init -- dd-smoke-tests/openfeature/src/test/resources/ffe-system-test-data +./gradlew :products:feature-flagging:feature-flagging-api:test \ + :products:feature-flagging:feature-flagging-lib:test \ + :products:feature-flagging:feature-flagging-agent:test -PtestJvm=11 +``` + +For acceptance records, retain `git rev-parse HEAD` plus any working-tree patch, source mode, +startup command, test/reproduction command, expected messages, observed transcript, and +Pass/Fail/Not run/N/A with reason. Exercise agentless and Agent/Remote Config independently. +Persistent-cache startup is N/A: this provider has no persistent configuration cache. + +Coverage follows the [SDK debug logging checklist](https://datadoghq.atlassian.net/wiki/spaces/PANA/pages/7276692209). diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java index 2dc48aeae06..a13c59d788d 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java @@ -49,12 +49,10 @@ import java.util.concurrent.atomic.AtomicReference; import java.util.regex.Pattern; import java.util.regex.PatternSyntaxException; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; class DDEvaluator implements Evaluator, FeatureFlaggingGateway.ConfigListener { - private static final Logger log = LoggerFactory.getLogger(DDEvaluator.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(DDEvaluator.class); private static final Set> SUPPORTED_RESOLUTION_TYPES = new HashSet<>(asList(String.class, Boolean.class, Integer.class, Double.class, Value.class)); @@ -262,29 +260,42 @@ public ProviderEvaluation evaluate( // ProviderEvaluation returned, so the hook's consent decision is pinned to this evaluation's // config and cannot drift on a concurrent Remote Config swap. final ServerConfiguration config = configuration.get(); + final ProviderEvaluation result = resolve(target, key, defaultValue, context, config); + DebugLoggingHook.resolution(key, defaultValue, context, result, config); + return result; + } + + private ProviderEvaluation resolve( + final Class target, + final String key, + final T defaultValue, + final EvaluationContext context, + final ServerConfiguration config) { // Boolean.TRUE.equals covers both null (privacy-preserving default) and Boolean.FALSE without // an NPE — the field is boxed so a malformed UFC message doesn't abort the whole parse. final boolean observeFullEvaluationData = config != null && Boolean.TRUE.equals(config.observeFullEvaluationData); try { if (config == null) { - return error(defaultValue, ErrorCode.PROVIDER_NOT_READY, null, observeFullEvaluationData); + return error( + key, defaultValue, ErrorCode.PROVIDER_NOT_READY, null, observeFullEvaluationData); } if (context == null) { - return error(defaultValue, ErrorCode.INVALID_CONTEXT, null, observeFullEvaluationData); + return error(key, defaultValue, ErrorCode.INVALID_CONTEXT, null, observeFullEvaluationData); } final Flag flag = config.flags.get(key); if (flag == null) { if (config.invalidFlags != null && config.invalidFlags.containsKey(key)) { return error( + key, defaultValue, ErrorCode.PARSE_ERROR, "invalid configuration for flag " + key, observeFullEvaluationData); } - return error(defaultValue, ErrorCode.FLAG_NOT_FOUND, null, observeFullEvaluationData); + return error(key, defaultValue, ErrorCode.FLAG_NOT_FOUND, null, observeFullEvaluationData); } if (!flag.enabled) { @@ -297,6 +308,7 @@ public ProviderEvaluation evaluate( if (flag.allocations == null) { return error( + key, defaultValue, ErrorCode.GENERAL, "Missing allocations for flag " + key, @@ -335,7 +347,11 @@ public ProviderEvaluation evaluate( } else { if (targetingKey == null) { return error( - defaultValue, ErrorCode.TARGETING_KEY_MISSING, null, observeFullEvaluationData); + key, + defaultValue, + ErrorCode.TARGETING_KEY_MISSING, + null, + observeFullEvaluationData); } // To match a split, subject must match ALL underlying shards boolean allShardsMatch = true; @@ -369,12 +385,13 @@ public ProviderEvaluation evaluate( .flagMetadata(consentMetadata(observeFullEvaluationData)) .build(); } catch (final PatternSyntaxException e) { - return error(defaultValue, ErrorCode.PARSE_ERROR, e.getMessage(), observeFullEvaluationData); + return error( + key, defaultValue, ErrorCode.PARSE_ERROR, e.getMessage(), observeFullEvaluationData); } catch (final NumberFormatException e) { return error( - defaultValue, ErrorCode.TYPE_MISMATCH, e.getMessage(), observeFullEvaluationData); + key, defaultValue, ErrorCode.TYPE_MISMATCH, e.getMessage(), observeFullEvaluationData); } catch (final Exception e) { - return error(defaultValue, ErrorCode.GENERAL, e.getMessage(), observeFullEvaluationData); + return error(key, defaultValue, ErrorCode.GENERAL, e.getMessage(), observeFullEvaluationData); } } @@ -385,10 +402,12 @@ private static ImmutableMetadata consentMetadata(final boolean observeFullEvalua } private static ProviderEvaluation error( + final String key, final T defaultValue, final ErrorCode code, final String errorMessage, final boolean observeFullEvaluationData) { + DebugLoggingHook.resolutionError(key, code, errorMessage); // Under consent-off the errorMessage is dropped: exception messages from the outer catch blocks // (NumberFormatException, generic Exception) can echo raw evaluation-context values, so they // must never reach any consumer of ProviderEvaluation.getErrorMessage() — not just our own @@ -614,6 +633,7 @@ private static ProviderEvaluation resolveVariant( final Variant variant = flag.variations.get(variationKey); if (variant == null) { return error( + key, defaultValue, ErrorCode.GENERAL, "Variant not found for: " + variationKey, @@ -622,6 +642,7 @@ private static ProviderEvaluation resolveVariant( if (!isTypeCompatible(target, flag.variationType)) { return error( + key, defaultValue, ErrorCode.TYPE_MISMATCH, "Requested type " @@ -636,6 +657,7 @@ private static ProviderEvaluation resolveVariant( mappedValue = mapValue(target, variant.value); } catch (final NumberFormatException e) { return error( + key, defaultValue, ErrorCode.PARSE_ERROR, "Variant '" diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java index 2fe8116b038..94a9e5c1b48 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java @@ -1,20 +1,66 @@ package datadog.trace.api.openfeature; +import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; +import dev.openfeature.sdk.EvaluationContext; import dev.openfeature.sdk.FlagEvaluationDetails; import dev.openfeature.sdk.Hook; import dev.openfeature.sdk.HookContext; +import dev.openfeature.sdk.ImmutableStructure; +import dev.openfeature.sdk.ProviderEvaluation; +import dev.openfeature.sdk.Structure; +import dev.openfeature.sdk.Value; import java.util.Map; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; -/** Logs final evaluation outcomes without flag values, targeting context, or error messages. */ +/** Logs raw evaluation diagnostics at the provider and OpenFeature hook boundaries. */ final class DebugLoggingHook implements Hook { - private static final Logger log = LoggerFactory.getLogger(DebugLoggingHook.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(DebugLoggingHook.class); + private static final Structure VALUE_CONVERTER = new ImmutableStructure(); static DebugLoggingHook createIfEnabled() { return log.isDebugEnabled() ? new DebugLoggingHook() : null; } + static void resolution( + String key, + Object defaultValue, + EvaluationContext context, + ProviderEvaluation result, + ServerConfiguration config) { + if (!log.isDebugEnabled()) { + return; + } + try { + log.debug( + "Feature Flagging provider resolution: flag={}, targetingKey={}, context={}, defaultValue={}, resolvedValue={}, variant={}, reason={}, errorCode={}, errorMessage={}, metadata={}, configurationEnv={}, configurationCreatedAt={}", + key, + context == null ? null : context.getTargetingKey(), + raw(context), + raw(defaultValue), + raw(result.getValue()), + result.getVariant(), + result.getReason(), + result.getErrorCode(), + result.getErrorMessage(), + result.getFlagMetadata() == null + ? null + : raw(result.getFlagMetadata().asUnmodifiableMap()), + config == null || config.environment == null ? null : config.environment.name, + config == null ? null : config.createdAt); + } catch (Throwable failure) { + formattingFailed(failure); + } + } + + static void resolutionError(String key, Object code, String message) { + if (log.isDebugEnabled()) { + log.debug( + "Feature Flagging provider resolution error: flag={}, errorCode={}, errorMessage={}", + key, + code, + message); + } + } + @Override public void finallyAfter( final HookContext context, @@ -25,13 +71,39 @@ public void finallyAfter( } try { log.debug( - "Feature Flagging evaluation: flag={}, reason={}, variant={}, errorCode={}", + "Feature Flagging evaluation observed at finallyAfter: flag={}, targetingKey={}, context={}, defaultValue={}, observedValue={}, variant={}, reason={}, errorCode={}, errorMessage={}, metadata={}", details.getFlagKey(), - details.getReason(), + context == null || context.getCtx() == null ? null : context.getCtx().getTargetingKey(), + context == null ? null : raw(context.getCtx()), + context == null ? null : raw(context.getDefaultValue()), + raw(details.getValue()), details.getVariant(), - details.getErrorCode()); - } catch (RuntimeException ignored) { - // Diagnostics must not affect evaluation, even if an application logging backend fails. + details.getReason(), + details.getErrorCode(), + details.getErrorMessage(), + details.getFlagMetadata() == null + ? null + : raw(details.getFlagMetadata().asUnmodifiableMap())); + } catch (Throwable failure) { + formattingFailed(failure); } } + + /** + * Materialize inside the diagnostic boundary, including user supplied structure implementations. + */ + private static String raw(Object value) { + if (value instanceof Value) { + value = VALUE_CONVERTER.convertValue((Value) value); + } else if (value instanceof Structure) { + value = ((Structure) value).asObjectMap(); + } + return String.valueOf(value); + } + + private static void formattingFailed(Throwable failure) { + log.debug( + "Feature Flagging evaluation diagnostic formatting failed; raw detail unavailable", + failure); + } } diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java new file mode 100644 index 00000000000..67442f007aa --- /dev/null +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java @@ -0,0 +1,115 @@ +package datadog.trace.api.openfeature; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * Isolates diagnostic backend failures from feature flag behavior. + * + *

The provider owns this helper so it also works without agent classes or with an older agent. + */ +final class DiagnosticLogger { + private final Logger delegate; + + private DiagnosticLogger(Logger delegate) { + this.delegate = delegate; + } + + public static DiagnosticLogger getLogger(Class type) { + Logger logger; + try { + logger = LoggerFactory.getLogger(type); + } catch (Throwable ignored) { + logger = null; + } + return new DiagnosticLogger(logger); + } + + public boolean isDebugEnabled() { + try { + return delegate != null && delegate.isDebugEnabled(); + } catch (Throwable ignored) { + return false; + } + } + + public void debug(String message) { + try { + if (delegate != null) { + delegate.debug(message); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void debug(String message, Object argument) { + try { + if (delegate != null) { + delegate.debug(message, argument); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void debug(String message, Object first, Object second) { + try { + if (delegate != null) { + delegate.debug(message, first, second); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void debug(String message, Object... arguments) { + try { + if (delegate != null) { + delegate.debug(message, arguments); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void warn(String message) { + try { + if (delegate != null) { + delegate.warn(message); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void warn(String message, Object... arguments) { + try { + if (delegate != null) { + delegate.warn(message, arguments); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void info(String message, Object argument) { + try { + if (delegate != null) { + delegate.info(message, argument); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void error(String message, Throwable error) { + try { + if (delegate != null) { + delegate.error(message, error); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } +} diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java index 01f8a479c53..26592e40296 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java @@ -11,8 +11,6 @@ import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Consumer; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * An OpenFeature hook that hands each completed flag evaluation to a callback, with the Datadog @@ -41,7 +39,7 @@ */ public final class ExposureHook implements Hook { - private static final Logger log = LoggerFactory.getLogger(ExposureHook.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(ExposureHook.class); private final Consumer callback; private final AtomicBoolean warned = new AtomicBoolean(); diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java index 207846a56cc..f2052c8dbae 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java @@ -8,8 +8,6 @@ import dev.openfeature.sdk.ImmutableMetadata; import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * Sends the exposure for a logged allocation to the agent once the evaluation has succeeded. @@ -21,7 +19,7 @@ */ class ExposureLoggingHook implements Hook { - private static final Logger log = LoggerFactory.getLogger(ExposureLoggingHook.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(ExposureLoggingHook.class); private static final AtomicBoolean WARNED = new AtomicBoolean(); static final ExposureLoggingHook INSTANCE = @@ -50,6 +48,7 @@ public void finallyAfter( } final ImmutableMetadata metadata = details.getFlagMetadata(); if (metadata == null) { + log.debug("Feature Flagging exposure suppressed: metadata unavailable"); return; } // The ImmutableMetadata getters build a debug message for every absent key. @@ -67,6 +66,8 @@ public void finallyAfter( final String variantKey = details.getVariant(); final EvaluationContext context = ctx == null ? null : ctx.getCtx(); if (allocationKey == null || variantKey == null || context == null) { + log.debug( + "Feature Flagging exposure suppressed: allocation, variant, or context unavailable"); return; } final Object serialValue = values.get(DDEvaluator.METADATA_SPLIT_SERIAL_ID); diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java index 41426fd3683..e2416bfd36d 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java @@ -11,8 +11,6 @@ import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Supplier; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * OpenFeature Hook that captures flag evaluation events for EVP flagevaluation emission. @@ -36,7 +34,7 @@ */ class FlagEvalLoggingHook implements Hook { - private static final Logger log = LoggerFactory.getLogger(FlagEvalLoggingHook.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(FlagEvalLoggingHook.class); static final AtomicBoolean FEATURES_SUPPORTED = new AtomicBoolean(featuresSupported(FlagEvalEvent.class)); diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java index eba3b7ba4b5..dae3f10b31e 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java @@ -8,12 +8,10 @@ import io.opentelemetry.api.metrics.LongCounter; import io.opentelemetry.api.metrics.Meter; import java.io.Closeable; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; class FlagEvalMetrics implements Closeable { - private static final Logger log = LoggerFactory.getLogger(FlagEvalMetrics.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(FlagEvalMetrics.class); private static final String METER_NAME = "ddtrace.openfeature"; private static final String METRIC_NAME = "feature_flag.evaluations"; diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java index 47654cdc4f7..d3a0d01b793 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java @@ -23,12 +23,10 @@ import java.util.List; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; public class Provider extends EventProvider implements Metadata { - private static final Logger log = LoggerFactory.getLogger(Provider.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(Provider.class); static final String METADATA = "datadog-openfeature-provider"; private static final String EVALUATOR_IMPL = "datadog.trace.api.openfeature.DDEvaluator"; @@ -161,13 +159,15 @@ public void initialize(final EvaluationContext context) throws Exception { } log.debug("Feature Flagging provider initialized successfully"); } catch (final OpenFeatureError e) { - log.debug("Feature Flagging provider initialization failed: errorCode={}", e.getErrorCode()); + log.debug( + "Feature Flagging provider initialization failed: errorCode={}", e.getErrorCode(), e); markInitializationError(); throw e; } catch (final Throwable e) { log.debug( "Feature Flagging provider initialization failed: {}; verify the Java agent and feature flag configuration", - e.getClass().getSimpleName()); + e.getClass().getSimpleName(), + e); markInitializationError(); throw new FatalError("Failed to initialize provider, is the tracer configured?", e); } @@ -279,6 +279,8 @@ public void shutdown() { if (evaluator != null) { evaluator.shutdown(); } + log.debug( + "Feature Flagging provider shutdown complete; configuration listener detached; agent owns exposure delivery and shutdown"); } // Visible for tests: expose whether span enrichment is wired (gate-on) without leaking the impl. diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java index 40e998a6546..00201c2a10d 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java @@ -14,8 +14,6 @@ import java.util.LinkedHashMap; import java.util.List; import java.util.Map; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * OpenFeature {@code finally} hook that captures feature-flag evaluation metadata for APM span @@ -37,7 +35,7 @@ */ class SpanEnrichmentHook implements Hook { - private static final Logger log = LoggerFactory.getLogger(SpanEnrichmentHook.class); + private static final DiagnosticLogger log = DiagnosticLogger.getLogger(SpanEnrichmentHook.class); // The metadata keys the DDEvaluator attaches for span enrichment (single source of truth there). static final String METADATA_SERIAL_ID = DDEvaluator.METADATA_SPLIT_SERIAL_ID; diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java index 496f2730982..8a95ade2d90 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java @@ -1,10 +1,15 @@ package datadog.trace.api.openfeature; import static java.util.Collections.emptyMap; +import static java.util.Collections.singletonList; +import static java.util.Collections.singletonMap; import static java.util.concurrent.TimeUnit.MILLISECONDS; +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.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 static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyLong; @@ -15,22 +20,40 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.turbo.TurboFilter; import ch.qos.logback.core.read.ListAppender; +import ch.qos.logback.core.spi.FilterReply; +import datadog.trace.api.featureflag.FeatureFlaggingGateway; +import datadog.trace.api.featureflag.ufc.v1.Environment; +import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; import dev.openfeature.sdk.Client; import dev.openfeature.sdk.ErrorCode; import dev.openfeature.sdk.EvaluationContext; +import dev.openfeature.sdk.EventDetails; import dev.openfeature.sdk.FlagEvaluationDetails; import dev.openfeature.sdk.FlagValueType; import dev.openfeature.sdk.Hook; import dev.openfeature.sdk.HookContext; import dev.openfeature.sdk.ImmutableMetadata; +import dev.openfeature.sdk.ImmutableStructure; +import dev.openfeature.sdk.MutableContext; import dev.openfeature.sdk.OpenFeatureAPI; import dev.openfeature.sdk.ProviderEvaluation; +import dev.openfeature.sdk.ProviderEvent; +import dev.openfeature.sdk.ProviderState; +import dev.openfeature.sdk.Value; +import dev.openfeature.sdk.exceptions.ProviderNotReadyError; import java.util.Map; +import java.util.concurrent.CompletableFuture; +import java.util.concurrent.TimeUnit; +import java.util.stream.Stream; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.MethodSource; import org.slf4j.LoggerFactory; +import org.slf4j.Marker; import org.tabletest.junit.TableTest; class DebugLoggingHookTest { @@ -73,8 +96,9 @@ void registersOnlyWhenDebugIsActive(String scenario, String level, boolean regis } @Test - void logsOutcomeWithoutValuesContextOrArbitraryMetadata() { - EvaluationContext evaluationContext = mock(EvaluationContext.class); + void logsRawOutcomeContextDefaultAndMetadata() { + EvaluationContext evaluationContext = + new MutableContext("user-123", singletonMap("country", new Value("FR"))); HookContext context = HookContext.builder() .flagKey("checkout") @@ -99,12 +123,15 @@ void logsOutcomeWithoutValuesContextOrArbitraryMetadata() { assertTrue(message.contains("flag=checkout")); assertTrue(message.contains("reason=TARGETING_MATCH")); assertTrue(message.contains("variant=enabled")); - assertFalse(message.contains("secret")); - verifyNoInteractions(evaluationContext); + assertTrue(message.contains("defaultValue=secret-default")); + assertTrue(message.contains("observedValue=secret-value")); + assertTrue(message.contains("secret-key=secret-metadata")); + assertTrue(message.contains("targetingKey=user-123")); + assertTrue(message.contains("country=FR")); } @Test - void logsFallbackCodeWithoutPotentiallySensitiveErrorMessage() { + void logsRawFallbackAndErrorMessage() { FlagEvaluationDetails details = FlagEvaluationDetails.builder() .flagKey("missing") @@ -119,7 +146,8 @@ void logsFallbackCodeWithoutPotentiallySensitiveErrorMessage() { String message = appender.list.get(0).getFormattedMessage(); assertTrue(message.contains("reason=ERROR")); assertTrue(message.contains("errorCode=FLAG_NOT_FOUND")); - assertFalse(message.contains("secret")); + assertTrue(message.contains("errorMessage=secret-error")); + assertTrue(message.contains("observedValue=secret-default")); } @Test @@ -155,7 +183,8 @@ public void after( assertEquals(1, appender.list.size()); String message = appender.list.get(0).getFormattedMessage(); assertTrue(message.contains("reason=ERROR")); - assertFalse(message.contains("secret")); + assertTrue(message.contains("secret-application-error")); + assertTrue(message.contains("observedValue=false")); } finally { api.shutdown(); } @@ -173,4 +202,149 @@ void doesNotInspectDetailsAfterDebugIsDisabled() { verifyNoInteractions(details); assertTrue(appender.list.isEmpty()); } + + @ParameterizedTest + @MethodSource("rawValues") + void logsEveryValueTypeWithoutTruncation(Object value) { + FlagEvaluationDetails details = + FlagEvaluationDetails.builder().flagKey("raw").value(value).build(); + DebugLoggingHook.createIfEnabled().finallyAfter(null, details, emptyMap()); + String message = appender.list.get(0).getFormattedMessage(); + String expected = value instanceof Value ? "tail-" + "x".repeat(4096) : value.toString(); + assertTrue(message.contains(expected), message); + } + + static Stream rawValues() { + return Stream.of( + true, + 42, + 1.25, + "untruncated-" + "x".repeat(4096), + new Value( + new ImmutableStructure( + singletonMap( + "nested", new Value(singletonList(new Value("tail-" + "x".repeat(4096))))))), + new Value( + singletonList( + new Value( + new ImmutableStructure( + singletonMap("nested", new Value("tail-" + "x".repeat(4096)))))))); + } + + @Test + void logsProviderFallbackWithConfigurationIdentity() { + ServerConfiguration config = + new ServerConfiguration( + "2026-10-21T00:00:00Z", "ufc/v1", false, new Environment("staging"), emptyMap()); + DDEvaluator evaluator = new DDEvaluator(() -> {}); + evaluator.accept(config); + ProviderEvaluation result = + evaluator.evaluate(String.class, "missing", "default", new MutableContext("user-123")); + assertEquals("default", result.getValue()); + String message = appender.list.get(appender.list.size() - 1).getFormattedMessage(); + assertTrue(message.contains("provider resolution:")); + assertTrue(message.contains("errorCode=FLAG_NOT_FOUND")); + assertTrue(message.contains("resolvedValue=default")); + assertTrue(message.contains("configurationEnv=staging")); + assertTrue(message.contains("configurationCreatedAt=" + config.createdAt)); + } + + @Test + void rawErrorLoggingDoesNotChangeReturnedMetadata() { + ServerConfiguration config = new ServerConfiguration(null, "ufc/v1", false, null, emptyMap()); + config.invalidFlags = singletonMap("broken", "parse_error"); + DDEvaluator evaluator = new DDEvaluator(() -> {}); + evaluator.accept(config); + ProviderEvaluation result = + evaluator.evaluate(Boolean.class, "broken", false, new MutableContext()); + assertEquals(ErrorCode.PARSE_ERROR, result.getErrorCode()); + assertNull(result.getErrorMessage()); + assertTrue( + appender.list.stream() + .anyMatch( + event -> + event + .getFormattedMessage() + .contains("errorMessage=invalid configuration for flag broken"))); + } + + @Test + void reportsFormattingFailureWithoutChangingEvaluation() { + Object broken = + new Object() { + @Override + public String toString() { + throw new AssertionError("broken formatting"); + } + }; + FlagEvaluationDetails details = + FlagEvaluationDetails.builder().flagKey("broken").value(broken).build(); + assertDoesNotThrow( + () -> DebugLoggingHook.createIfEnabled().finallyAfter(null, details, emptyMap())); + assertTrue( + appender + .list + .get(0) + .getFormattedMessage() + .contains("formatting failed; raw detail unavailable")); + } + + @Test + void disabledResolutionDoesNotInspectContextResultOrValues() { + logger.setLevel(Level.INFO); + EvaluationContext context = mock(EvaluationContext.class); + ProviderEvaluation result = mock(ProviderEvaluation.class); + Object value = mock(Object.class); + DebugLoggingHook.resolution("flag", value, context, result, null); + verifyNoInteractions(context, result, value); + assertTrue(appender.list.isEmpty()); + } + + @TableTest({ + "Scenario | Fail level check", + "backend throws | false ", + "level check throws | true " + }) + void loggerFailureDoesNotInterruptLifecycle(String scenario, boolean failLevelCheck) + throws Exception { + TurboFilter failure = + new TurboFilter() { + @Override + public FilterReply decide( + Marker marker, + Logger target, + Level level, + String format, + Object[] params, + Throwable throwable) { + if (target.getName().startsWith("datadog.trace.api.openfeature") + && (failLevelCheck || format != null)) { + throw new AssertionError("broken logger"); + } + return FilterReply.NEUTRAL; + } + }; + failure.start(); + logger.getLoggerContext().addTurboFilter(failure); + OpenFeatureAPI api = OpenFeatureAPI.getInstance(); + FeatureFlaggingGateway.dispatch((ServerConfiguration) null); + try { + Provider provider = new Provider(new Provider.Options().initTimeout(1, MILLISECONDS)); + assertThrows(ProviderNotReadyError.class, () -> api.setProviderAndWait(provider)); + Client client = api.getClient(); + CompletableFuture recovered = new CompletableFuture<>(); + client.on(ProviderEvent.PROVIDER_READY, recovered::complete); + ServerConfiguration config = new ServerConfiguration(null, "ufc/v1", false, null, emptyMap()); + FeatureFlaggingGateway.dispatch(config); + recovered.get(5, TimeUnit.SECONDS); + assertEquals(ProviderState.READY, client.getProviderState()); + assertEquals("fallback", client.getStringValue("missing", "fallback")); + assertDoesNotThrow(api::shutdown); + } finally { + logger.getLoggerContext().getTurboFilterList().remove(failure); + failure.stop(); + api.shutdown(); + FeatureFlaggingGateway.dispatch((ServerConfiguration) null); + } + } } diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java index efd42915b6d..410da22c7ec 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java @@ -68,7 +68,8 @@ protected Class loadClass(final String name, final boolean resolve) throw new ClassNotFoundException(name); } if (name.startsWith("datadog.trace.api.openfeature.ExposureHook") - || name.equals("datadog.trace.api.openfeature.SplitFeatureMetadata")) { + || name.equals("datadog.trace.api.openfeature.SplitFeatureMetadata") + || name.equals("datadog.trace.api.openfeature.DiagnosticLogger")) { Class loaded = findLoadedClass(name); if (loaded == null) { final byte[] bytes = classBytes(name); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java index d037d247433..1130d1fe4e3 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java @@ -33,11 +33,10 @@ import okhttp3.Request; import okhttp3.Response; import okhttp3.ResponseBody; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; final class AgentlessConfigurationSource implements ConfigurationSourceService { - private static final Logger LOGGER = LoggerFactory.getLogger(AgentlessConfigurationSource.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(AgentlessConfigurationSource.class); private static final String DATADOG_UFC_RULES_BASED_SERVER_PATH = "/api/v2/feature-flagging/config/rules-based/server"; @@ -81,7 +80,7 @@ private AgentlessConfigurationSource(final Config config, final HttpUrl endpoint () -> ThreadLocalRandom.current().nextDouble(1 - RETRY_JITTER, 1 + RETRY_JITTER)), Executors.newSingleThreadScheduledExecutor( new AgentThreadFactory(FEATURE_FLAG_CONFIGURATION_POLLER)), - new RatelimitedLogger(LOGGER, MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); + new RatelimitedLogger(LOGGER.backend(), MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); } AgentlessConfigurationSource( @@ -96,7 +95,7 @@ private AgentlessConfigurationSource(final Config config, final HttpUrl endpoint pollIntervalMillis, client, executor, - new RatelimitedLogger(LOGGER, MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); + new RatelimitedLogger(LOGGER.backend(), MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); } AgentlessConfigurationSource( @@ -125,13 +124,17 @@ public void init() { if (LOGGER.isDebugEnabled()) { LOGGER.debug( - "Feature Flagging starting agentless configuration source at {}://{}:{}; pollIntervalMs={}, requestTimeoutSeconds={}, env={}", + "Feature Flagging starting agentless configuration source at {}://{}:{}; pollIntervalMs={}, requestTimeoutSeconds={}, env={}, requestedEnv={}, endpointMode={}", endpoint.scheme(), endpoint.host(), endpoint.port(), pollIntervalMillis, config.getFeatureFlaggingConfigurationSourceRequestTimeoutSeconds(), - config.getEnv()); + config.getEnv(), + endpoint.queryParameter("dd_env"), + config.getFeatureFlaggingConfigurationSourceAgentlessBaseUrl() == null + ? "managed" + : "custom (DD_ENV is not appended)"); } if (config.getFeatureFlaggingConfigurationSourceAgentlessBaseUrl() == null && isBlank(config.getApiKey())) { @@ -211,10 +214,14 @@ private boolean fetchAndApply() { return false; } if (isRetryableStatus(response.status)) { - ratelimitedLogger.warn( - "Feature Flagging agentless endpoint failed after {} attempts with HTTP {}", - MAX_ATTEMPTS, - response.status); + try { + ratelimitedLogger.warn( + "Feature Flagging agentless endpoint failed after {} attempts with HTTP {}; retaining current configuration; retry on next poll", + MAX_ATTEMPTS, + response.status); + } catch (Throwable ignored) { + // Logging must not interrupt polling or recovery. + } return false; } synchronized (lifecycleLock) { @@ -222,12 +229,16 @@ private boolean fetchAndApply() { } } catch (final IOException e) { if (!closed) { - ratelimitedLogger.warn( - "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}", - MAX_ATTEMPTS, - e.getClass().getSimpleName(), - e.getMessage(), - e); + try { + ratelimitedLogger.warn( + "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}; retaining current configuration; retry on next poll", + MAX_ATTEMPTS, + e.getClass().getSimpleName(), + e.getMessage(), + e); + } catch (Throwable ignored) { + // Logging must not interrupt polling or recovery. + } } return false; } @@ -241,9 +252,13 @@ private boolean apply(final UfcHttpResponse response) { } if (response.status == HttpURLConnection.HTTP_UNAUTHORIZED || response.status == HttpURLConnection.HTTP_FORBIDDEN) { - ratelimitedLogger.warn( - "Feature Flagging agentless endpoint returned HTTP {}; verify endpoint authentication", - response.status); + try { + ratelimitedLogger.warn( + "Feature Flagging agentless endpoint returned HTTP {}; verify endpoint authentication", + response.status); + } catch (Throwable ignored) { + // Logging must not interrupt polling or recovery. + } return false; } if (response.status != HttpURLConnection.HTTP_OK) { @@ -276,11 +291,13 @@ private boolean apply(final UfcHttpResponse response) { updateEtag(response.etag); if (LOGGER.isDebugEnabled()) { LOGGER.debug( - "Feature Flagging agentless configuration applied: flags={}, env={}, configurationEnv={}, createdAt={}", + "Feature Flagging agentless configuration applied: flags={}, env={}, configurationEnv={}, createdAt={}, invalidFlags={}, etag={}", configuration.flags.size(), config.getEnv(), configuration.environment == null ? null : configuration.environment.name, - configuration.createdAt); + configuration.createdAt, + configuration.invalidFlags == null ? 0 : configuration.invalidFlags.size(), + etag); } return true; } diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java index 59919840ffe..60ebf9651cd 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java @@ -11,14 +11,12 @@ import java.util.function.Supplier; import javax.annotation.Nullable; import okhttp3.RequestBody; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** Sends Feature Flag events through the process-wide Agentless EVP route selector. */ final class AgentlessFeatureFlagBackendApi implements BackendApi { - private static final Logger LOGGER = - LoggerFactory.getLogger(AgentlessFeatureFlagBackendApi.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(AgentlessFeatureFlagBackendApi.class); private final FeatureFlagRouteSelector routeSelector; private final Supplier proxyEndpointSupplier; diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java new file mode 100644 index 00000000000..82b37b4e34d --- /dev/null +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java @@ -0,0 +1,117 @@ +package com.datadog.featureflag; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.Marker; + +/** Isolates diagnostic backend failures from feature flag behavior. */ +public final class DiagnosticLogger { + private final Logger delegate; + + private DiagnosticLogger(Logger delegate) { + this.delegate = delegate; + } + + public static DiagnosticLogger getLogger(Class type) { + Logger logger; + try { + logger = LoggerFactory.getLogger(type); + } catch (Throwable ignored) { + logger = null; + } + return new DiagnosticLogger(logger); + } + + /** The rate limiter's calls are guarded by its caller, including its own level checks. */ + Logger backend() { + return delegate == null ? org.slf4j.helpers.NOPLogger.NOP_LOGGER : delegate; + } + + public boolean isDebugEnabled() { + try { + return delegate != null && delegate.isDebugEnabled(); + } catch (Throwable ignored) { + return false; + } + } + + public void debug(String message) { + try { + if (delegate != null) { + delegate.debug(message); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void debug(String message, Object argument) { + try { + if (delegate != null) { + delegate.debug(message, argument); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void debug(String message, Object first, Object second) { + try { + if (delegate != null) { + delegate.debug(message, first, second); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void debug(String message, Object... arguments) { + try { + if (delegate != null) { + delegate.debug(message, arguments); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void warn(String message) { + try { + if (delegate != null) { + delegate.warn(message); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void warn(String message, Object... arguments) { + try { + if (delegate != null) { + delegate.warn(message, arguments); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } + + public void error(String message, Throwable error) { + try { + if (delegate != null) { + delegate.error(message, error); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt teardown. + } + } + + public void error(Marker marker, String message, Throwable error) { + try { + if (delegate != null) { + delegate.error(marker, message, error); + } + } catch (Throwable ignored) { + // A diagnostic must never interrupt evaluation, readiness notification, or teardown. + } + } +} diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java index 8aaa498d334..623dc11705c 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java @@ -22,12 +22,11 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Supplier; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; public class ExposureWriterImpl implements ExposureWriter, FeatureFlagEventWriter { - private static final Logger LOGGER = LoggerFactory.getLogger(ExposureWriterImpl.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(ExposureWriterImpl.class); private static final int DEFAULT_CAPACITY = 1 << 16; // 65536 elements private static final int DEFAULT_FLUSH_INTERVAL_IN_SECONDS = 1; private static final int FLUSH_THRESHOLD = 100; @@ -145,6 +144,12 @@ public void requestShutdown() { } // Stop accepting new dispatches without waiting for producers already inside accept(). FeatureFlaggingGateway.removeExposureListener(this); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging exposure shutdown requested: queued={}, inFlight={}; pending exposures will not be flushed; processor completion is reported separately", + queue.size(), + serializer.inFlight); + } // Polling wakes within 100 ms. An interrupt can race with, or abort, the final POST. serializer.requestShutdown(); } @@ -190,6 +195,7 @@ private static class ExposureSerializingHandler implements Runnable { private final List buffer = new ArrayList<>(); private final Runnable errorCallback; private final AtomicBoolean shutdownRequested = new AtomicBoolean(false); + private volatile boolean inFlight; ExposureSerializingHandler( final Supplier backendApiSupplier, @@ -238,7 +244,9 @@ public void run() { } } LOGGER.debug( - "Feature Flagging exposure processor stopped; pending exposures are not flushed on shutdown"); + "Feature Flagging exposure processor stopped; pending exposures are not flushed on shutdown; queued={}, buffered={}, inFlight=false", + queue.size(), + buffer.size()); } private void runDutyCycle() throws InterruptedException { @@ -298,6 +306,7 @@ private void flush() { } try { LOGGER.debug("Feature Flagging exposure flush starting: count={}", this.buffer.size()); + inFlight = true; evpPublisher.post(EXPOSURES_ROUTE, payload); LOGGER.debug("Feature Flagging exposure flush delivered: count={}", this.buffer.size()); } catch (AgentlessFeatureFlagBackendApi.UnavailableRouteException ignored) { @@ -315,6 +324,7 @@ private void flush() { e); } } finally { + inFlight = false; // Best-effort delivery must not retry an ambiguously accepted batch. A later definitive // proxy rejection could otherwise replay the same exposures through direct intake. this.buffer.clear(); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java index d4f3c8c499a..8401c445d55 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java @@ -20,13 +20,12 @@ import java.util.Map; import javax.annotation.Nullable; import okhttp3.Response; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** Selects the transport for Feature Flagging events. */ final class FeatureFlagBackendApiFactory { - private static final Logger LOGGER = LoggerFactory.getLogger(FeatureFlagBackendApiFactory.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(FeatureFlagBackendApiFactory.class); private static final Map REQUEST_HEADERS = requestHeaders(); /** Retries connection refusal only; automatic retries and redirects remain disabled. */ diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java index c2a6231076c..f5c76c812bd 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java @@ -24,8 +24,6 @@ import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicLong; import java.util.function.Supplier; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * EVP flagevaluation writer for Java. @@ -54,7 +52,8 @@ */ public class FlagEvaluationWriterImpl implements FlagEvaluationWriter, FeatureFlagEventWriter { - private static final Logger LOGGER = LoggerFactory.getLogger(FlagEvaluationWriterImpl.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(FlagEvaluationWriterImpl.class); static final int DEFAULT_CAPACITY = 1 << 12; // 4096 elements, per cross-SDK RFC static final int FLUSH_INTERVAL_SECONDS = 10; diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java index 09b4718f35b..d059c981f08 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java @@ -10,13 +10,12 @@ import datadog.trace.api.featureflag.FeatureFlaggingGateway; import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; import javax.annotation.Nullable; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; public class RemoteConfigServiceImpl implements ConfigurationSourceService, ConfigurationChangesTypedListener { - private static final Logger LOGGER = LoggerFactory.getLogger(RemoteConfigServiceImpl.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(RemoteConfigServiceImpl.class); private final ConfigurationPoller configurationPoller; @@ -51,11 +50,12 @@ public void accept( LOGGER.debug("Feature Flagging remote_config configuration removed"); } else if (LOGGER.isDebugEnabled()) { LOGGER.debug( - "Feature Flagging remote_config configuration applied: key={}, flags={}, env={}, createdAt={}", + "Feature Flagging remote_config configuration applied: key={}, flags={}, configurationEnv={}, createdAt={}, invalidFlags={}", configKey, configuration.flags == null ? 0 : configuration.flags.size(), configuration.environment == null ? null : configuration.environment.name, - configuration.createdAt); + configuration.createdAt, + configuration.invalidFlags == null ? 0 : configuration.invalidFlags.size()); } } } diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java index a82e194e248..9098ce17fa6 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java @@ -5,8 +5,6 @@ import datadog.trace.bootstrap.instrumentation.api.AgentSpan; import java.util.Collection; import java.util.Map; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * {@link TraceInterceptor} that writes the accumulated {@code ffe_*} tags onto the local root span @@ -46,7 +44,8 @@ */ final class SpanEnrichmentInterceptor implements TraceInterceptor { - private static final Logger log = LoggerFactory.getLogger(SpanEnrichmentInterceptor.class); + private static final DiagnosticLogger log = + DiagnosticLogger.getLogger(SpanEnrichmentInterceptor.class); /** * Unique priority in the "trace data enrichment" band, after {@code GIT_METADATA} (3) and before diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java index f97259d9368..4fafe68404d 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java @@ -6,8 +6,6 @@ import datadog.trace.bootstrap.instrumentation.api.AgentSpan; import datadog.trace.bootstrap.instrumentation.api.AgentTracer; import java.util.concurrent.atomic.AtomicBoolean; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * Agent-side owner of APM feature-flag span enrichment. This is the WRITE tier of the @@ -35,7 +33,8 @@ public final class SpanEnrichmentWriter implements FeatureFlaggingGateway.SpanEnrichmentListener, AutoCloseable { - private static final Logger log = LoggerFactory.getLogger(SpanEnrichmentWriter.class); + private static final DiagnosticLogger log = + DiagnosticLogger.getLogger(SpanEnrichmentWriter.class); public static SpanEnrichmentWriter getInstance() { return SingletonHolder.INSTANCE; diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java index 073f8e2212c..48037467b97 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java @@ -33,12 +33,11 @@ import javax.annotation.Nullable; import okio.BufferedSource; import okio.Okio; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; final class UniversalFlagConfigParser implements ConfigurationDeserializer { - private static final Logger LOGGER = LoggerFactory.getLogger(UniversalFlagConfigParser.class); + private static final DiagnosticLogger LOGGER = + DiagnosticLogger.getLogger(UniversalFlagConfigParser.class); static final String INVALID_FLAG = "invalid_flag"; static final String INVALID_SEMVER_COMPARAND = "invalid_semver_comparand"; @@ -95,6 +94,15 @@ ServerConfiguration parse(final JsonReader reader) throws IOException { } } INVALID_FLAGS_HOLDER.get().clear(); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging configuration received: usableFlags={}, invalidFlags={}, configurationPresent={}", + configuration == null || configuration.flags == null ? 0 : configuration.flags.size(), + configuration == null || configuration.invalidFlags == null + ? 0 + : configuration.invalidFlags.size(), + configuration != null && configuration.flags != null); + } return configuration; } @@ -369,17 +377,26 @@ public Map fromJson(@Nonnull final JsonReader reader) throws IOExc return reader.nextNull(); } final Map flags = new HashMap<>(); + int receivedFlags = 0; + int rejectedFlags = 0; reader.beginObject(); while (reader.hasNext()) { final String flagKey = reader.nextName(); + receivedFlags++; final Object rawFlag = reader.readJsonValue(); try { final Flag flag = flagAdapter.fromJsonValue(rawFlag); if (flag != null) { validateFlag(flagKey, flag); flags.put(flagKey, flag); + } else { + rejectedFlags++; + LOGGER.debug( + "Feature Flagging rejected flag {} during configuration parsing: null flag", + flagKey); } } catch (JsonDataException | IllegalArgumentException error) { + rejectedFlags++; final String reason = error instanceof InvalidSemverComparandException ? INVALID_SEMVER_COMPARAND @@ -392,6 +409,13 @@ public Map fromJson(@Nonnull final JsonReader reader) throws IOExc } } reader.endObject(); + if (LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging configuration flags parsed: receivedFlags={}, usableFlags={}, rejectedFlags={}", + receivedFlags, + flags.size(), + rejectedFlags); + } return flags; } diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java index 1b5dc7cc030..3cb0fc7a8f4 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/AgentlessConfigurationSourceTest.java @@ -65,6 +65,7 @@ import org.mockito.Mock; import org.mockito.junit.jupiter.MockitoExtension; import org.slf4j.LoggerFactory; +import org.tabletest.junit.TableTest; @ExtendWith(MockitoExtension.class) class AgentlessConfigurationSourceTest { @@ -765,7 +766,9 @@ void warnsRateLimitedAfterRetryableFailuresAreExhausted() throws Exception { assertEquals(3, requests.size()); verify(ratelimitedLogger) .warn( - "Feature Flagging agentless endpoint failed after {} attempts with HTTP {}", 3, 503); + "Feature Flagging agentless endpoint failed after {} attempts with HTTP {}; retaining current configuration; retry on next poll", + 3, + 503); verifyNoInteractions(listener); } finally { service.close(); @@ -803,7 +806,7 @@ void warnsRateLimitedAfterIoFailuresAreExhausted() throws Exception { assertEquals(3, requests.size()); verify(ratelimitedLogger) .warn( - "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}", + "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}; retaining current configuration; retry on next poll", 3, "SocketTimeoutException", finalFailure.getMessage(), @@ -1238,13 +1241,45 @@ void restoreLogging() { logger.setLevel(previousLevel); } + @TableTest({ + "Scenario | Env | Custom URL | Requested ", + "managed environment | production | | production", + "custom no environment | production | 'https://flags.example.com/config' | ", + "custom scoped URL | production | 'https://flags.example.com/?dd_env=qa' | qa ", + "managed unset | | | " + }) + void distinguishesSdkAndRequestedEnvironment(String env, String customUrl, String requested) + throws Exception { + Config config = config("datadoghq.com", env); + when(config.getFeatureFlaggingConfigurationSourceAgentlessBaseUrl()).thenReturn(customUrl); + AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + when(client.fetch(any(), any(), any())).thenReturn(response(304, null, null)); + try (AgentlessConfigurationSource source = + new AgentlessConfigurationSource( + AgentlessConfigurationSource.endpoint(config), + config, + 30000, + client, + mock(ScheduledExecutorService.class))) { + source.init(); + assertLogged( + "env=" + + env + + ", requestedEnv=" + + requested + + ", endpointMode=" + + (customUrl == null ? "managed" : "custom (DD_ENV is not appended)")); + } + } + @Test void reportsAppliedUnchangedAndRejectedConfigurationWithParseFailure() throws Exception { final AgentlessConfigurationSource.UfcHttpClient client = mock(AgentlessConfigurationSource.UfcHttpClient.class); when(client.fetch(any(), any(), any())) .thenReturn( - response(200, "secret-etag", emptyConfig()), + response(200, "configuration-v1", emptyConfig()), response(304, null, null), response(200, null, "{\"secret-payload\":")); final ScheduledExecutorService executor = Executors.newSingleThreadScheduledExecutor(); @@ -1260,6 +1295,7 @@ void reportsAppliedUnchangedAndRejectedConfigurationWithParseFailure() throws Ex assertTrue(service.pollOnce()); assertFalse(service.pollOnce()); assertLogged("configuration applied: flags=0, env=production, configurationEnv=Staging"); + assertLogged("etag=configuration-v1"); assertLogged("configuration unchanged (HTTP 304)"); assertNotNull( assertLogged("configuration rejected: malformed UFC payload").getThrowableProxy()); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java new file mode 100644 index 00000000000..0f75b50ca2b --- /dev/null +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java @@ -0,0 +1,136 @@ +package com.datadog.featureflag; + +import static java.nio.charset.StandardCharsets.UTF_8; +import static java.util.Collections.emptyMap; +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.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 static org.mockito.Mockito.when; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.turbo.TurboFilter; +import ch.qos.logback.core.spi.FilterReply; +import datadog.communication.BackendApi; +import datadog.communication.BackendApiFactory; +import datadog.communication.ddagent.SharedCommunicationObjects; +import datadog.remoteconfig.ConfigurationPoller; +import datadog.remoteconfig.Product; +import datadog.trace.api.Config; +import datadog.trace.api.featureflag.FeatureFlaggingGateway; +import datadog.trace.api.featureflag.exposure.Allocation; +import datadog.trace.api.featureflag.exposure.ExposureEvent; +import datadog.trace.api.featureflag.exposure.Flag; +import datadog.trace.api.featureflag.exposure.Subject; +import datadog.trace.api.featureflag.exposure.Variant; +import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; +import datadog.trace.api.intake.Intake; +import datadog.trace.test.util.PollingConditions; +import java.util.concurrent.ScheduledExecutorService; +import okhttp3.HttpUrl; +import org.slf4j.LoggerFactory; +import org.slf4j.Marker; +import org.tabletest.junit.TableTest; + +class DiagnosticIsolationTest { + @TableTest({ + "Scenario | Fail level check", + "backend throws | false ", + "level check throws | true " + }) + void preservesConfigurationAndDeliveryWhenLoggingFails(boolean failLevelCheck) throws Exception { + LoggerContext logging = (LoggerContext) LoggerFactory.getILoggerFactory(); + TurboFilter failure = + new TurboFilter() { + @Override + public FilterReply decide( + Marker marker, + Logger logger, + Level level, + String format, + Object[] params, + Throwable error) { + if (logger.getName().startsWith("com.datadog.featureflag") + && (failLevelCheck || format != null)) { + throw new AssertionError("broken logger"); + } + return FilterReply.NEUTRAL; + } + }; + failure.start(); + logging.addTurboFilter(failure); + FeatureFlaggingGateway.ConfigListener listener = + mock(FeatureFlaggingGateway.ConfigListener.class); + FeatureFlaggingGateway.addConfigListener(listener); + try { + Config config = mock(Config.class); + SharedCommunicationObjects sco = mock(SharedCommunicationObjects.class); + ConfigurationPoller poller = mock(ConfigurationPoller.class); + when(sco.configurationPoller(config)).thenReturn(poller); + try (RemoteConfigServiceImpl service = new RemoteConfigServiceImpl(sco, config)) { + service.init(); + ServerConfiguration parsed = + UniversalFlagConfigParser.INSTANCE.deserialize( + "{\"flags\":{\"bad\":42}}".getBytes(UTF_8)); + assertEquals(1, parsed.invalidFlags.size()); + service.accept("config", parsed, null); + verify(listener).accept(parsed); + } + verify(poller).removeListeners(Product.FFE_FLAGS); + verify(poller).stop(); + + AgentlessConfigurationSource.UfcHttpClient client = + mock(AgentlessConfigurationSource.UfcHttpClient.class); + ScheduledExecutorService executor = mock(ScheduledExecutorService.class); + HttpUrl endpoint = HttpUrl.get("http://localhost/config"); + when(client.fetch(eq(endpoint), eq(config), any())) + .thenReturn(new AgentlessConfigurationSource.UfcHttpResponse(503, null, null)) + .thenReturn( + new AgentlessConfigurationSource.UfcHttpResponse( + 200, + "v1", + "{\"data\":{\"type\":\"universal-flag-configuration\",\"attributes\":{\"flags\":{}}}}" + .getBytes(UTF_8))); + try (AgentlessConfigurationSource source = + new AgentlessConfigurationSource(endpoint, config, 1000, client, executor)) { + source.init(); + assertTrue(source.pollOnce()); + } + verify(client).cancel(); + verify(executor).shutdownNow(); + + BackendApi backend = mock(BackendApi.class); + BackendApiFactory backendFactory = mock(BackendApiFactory.class); + when(backendFactory.createEvpProxyApi(Intake.EVENT_PLATFORM, true)).thenReturn(backend); + FeatureFlagBackendApiFactory factory = + new FeatureFlagBackendApiFactory(config, backendFactory, FeatureFlagEventType.EXPOSURE); + ExposureWriterImpl writer = new ExposureWriterImpl(16, 1, MILLISECONDS, factory, config); + PollingConditions poll = new PollingConditions(5); + try { + writer.init(); + writer.accept( + new ExposureEvent( + 1, + new Allocation("allocation"), + new Flag("flag"), + new Variant("variant"), + new Subject("user", emptyMap()))); + poll.eventually(() -> verify(backend).post(any(), any(), any(), any(), eq(false))); + } finally { + writer.close(); + } + poll.eventually(() -> assertFalse(writer.isSerializerThreadAlive())); + } finally { + FeatureFlaggingGateway.removeConfigListener(listener); + FeatureFlaggingGateway.dispatch((ServerConfiguration) null); + logging.getTurboFilterList().remove(failure); + failure.stop(); + } + } +} diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java index f29ea8e17e8..c0c8abae850 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java @@ -237,6 +237,73 @@ void distinguishesQueuedFromDeliveredExposures(boolean fails, Integer status, St } } + @TableTest({ + "Scenario | Fails | Outcome ", + "in-flight delivered | false | 'flush delivered' ", + "in-flight timed out | true | 'flush failed: SocketTimeoutException; dropping batch'" + }) + void reportsShutdownWithPendingAndInFlightExposures(boolean fails, String outcome) + throws Exception { + Logger logger = (Logger) LoggerFactory.getLogger(ExposureWriterImpl.class); + Level previous = logger.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.list = new CopyOnWriteArrayList<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.DEBUG); + CountDownLatch inFlight = new CountDownLatch(1); + BackendApi backend = mock(BackendApi.class); + when(backend.post(any(), any(), any(), any(), eq(false))) + .thenAnswer( + invocation -> { + inFlight.countDown(); + try { + new CountDownLatch(1).await(); + } catch (InterruptedException interrupted) { + Thread.currentThread().interrupt(); + } + if (fails) { + throw new SocketTimeoutException("destination timed out during shutdown"); + } + return null; + }); + Config config = mockConfig("shutdown"); + BackendApiFactory backendFactory = mock(BackendApiFactory.class); + when(backendFactory.createEvpProxyApi(Intake.EVENT_PLATFORM, true)).thenReturn(backend); + ExposureWriterImpl writer = + new ExposureWriterImpl( + 16, + 1, + MILLISECONDS, + new FeatureFlagBackendApiFactory(config, backendFactory, FeatureFlagEventType.EXPOSURE), + config); + try { + writer.init(); + writer.accept(buildExposure()); + assertTrue(inFlight.await(5000, MILLISECONDS)); + writer.accept(buildExposure()); + writer.close(); + poll.eventually(() -> assertFalse(writer.isSerializerThreadAlive())); + assertTrue( + appender.list.stream() + .anyMatch( + e -> + e.getFormattedMessage() + .contains("shutdown requested: queued=1, inFlight=true"))); + assertTrue(appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(outcome))); + assertTrue( + appender.list.stream() + .anyMatch( + e -> e.getFormattedMessage().contains("queued=1, buffered=0, inFlight=false"))); + verify(backend).post(any(), any(), any(), any(), eq(false)); + } finally { + writer.close(); + logger.detachAppender(appender); + logger.setLevel(previous); + appender.stop(); + } + } + @Test void testExposureRequestsCarrySdkIdentity() throws Exception { // Exercise the production writer and factory on the fixed Remote Config EVP v2 route. diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java index e233e0672bb..775d304b689 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/JsonApiUfcResponseParserTest.java @@ -29,6 +29,36 @@ class JsonApiUfcResponseParserTest { + @Test + void countsNullAndMalformedFlagsWithoutChangingTheirEvaluationSemantics() throws Exception { + Logger logger = (Logger) LoggerFactory.getLogger(UniversalFlagConfigParser.class); + Level previous = logger.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.DEBUG); + try { + ServerConfiguration config = parse(wrap("{\"flags\":{\"null-flag\":null,\"bad\":42}}")); + assertTrue(config.flags.isEmpty()); + assertEquals(1, config.invalidFlags.size()); + assertFalse(config.invalidFlags.containsKey("null-flag")); + assertTrue( + appender.list.stream() + .anyMatch( + event -> + event + .getFormattedMessage() + .contains("receivedFlags=2, usableFlags=0, rejectedFlags=2"))); + assertTrue( + appender.list.stream() + .anyMatch(event -> event.getFormattedMessage().contains("null flag"))); + } finally { + logger.detachAppender(appender); + logger.setLevel(previous); + appender.stop(); + } + } + @Test void rejectedFlagWarningsRetainStructuralReasonsWithoutSemverComparands() throws Exception { final Logger logger = (Logger) LoggerFactory.getLogger(UniversalFlagConfigParser.class); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java index 17ea30bbad3..48be3b98b35 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java @@ -132,7 +132,7 @@ void reportsAppliedConfiguration() throws Exception { verify(listener).accept(config); assertLogged( - "configuration applied: key=datadog/2/FFE_FLAGS/config/config, flags=0, env=Test, createdAt=2024-04-17T19:40:53.716Z"); + "configuration applied: key=datadog/2/FFE_FLAGS/config/config, flags=0, configurationEnv=Test, createdAt=2024-04-17T19:40:53.716Z"); } @Test @@ -142,7 +142,8 @@ void reportsAppliedConfigurationWithoutFlagsOrEnvironment() { service.accept("config", config, mock(PollingRateHinter.class)); verify(listener).accept(config); - assertLogged("configuration applied: key=config, flags=0, env=null, createdAt=null"); + assertLogged( + "configuration applied: key=config, flags=0, configurationEnv=null, createdAt=null"); } @Test From 19562a9ca390db07f45b941c9450dc965cdc8e0e Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Wed, 21 Oct 2026 15:32:08 +0000 Subject: [PATCH 5/9] Gate provider debug logging on DD_TRACE_DEBUG --- .../feature-flagging-api/README.md | 15 ++- .../api/openfeature/DiagnosticLogger.java | 22 +++- .../DebugLoggingDisabledForkedTest.java | 71 ++++++++++++ ...t.java => DebugLoggingHookForkedTest.java} | 6 +- .../api/openfeature/DiagnosticLoggerTest.java | 106 ++++++++++++++++++ .../ExposureHookWithoutAgentTest.java | 27 ++++- 6 files changed, 236 insertions(+), 11 deletions(-) create mode 100644 products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java rename products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/{DebugLoggingHookTest.java => DebugLoggingHookForkedTest.java} (99%) create mode 100644 products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index 74d14311112..e5c8e55a6ac 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -259,6 +259,9 @@ This setting stops exposures only. Flag evaluation events have their own setting Set `DD_TRACE_DEBUG=true` for the Java agent's configuration, writer, and transport logs. Also enable DEBUG for `datadog.trace.api.openfeature` in the application's SLF4J backend **before constructing `Provider`**. The provider and agent have separate logging backends; +provider debug logs require both `DD_TRACE_DEBUG=true` (or `-Ddd.trace.debug=true`) and an +application logger that permits DEBUG. The trace debug setting defaults to false and is cached +when provider loggers are initialized; changing it requires restarting the application. `DD_TRACE_DEBUG` does not change application logger levels. No additional flag evaluation data setting is required for raw debug logs, including when `observe_full_evaluation_data` is false. That metadata setting continues to govern evaluation telemetry independently. @@ -340,8 +343,11 @@ Look for these diagnostic boundaries: flight. Pending exposures are **not flushed**. The processor reports completion separately, after any in-flight delivery outcome, with the counts left in its queue and buffer. -To disable these diagnostics, turn off `DD_TRACE_DEBUG`, restore the application category to INFO, -and recreate the provider. When DEBUG is off, raw values and context are not traversed or formatted. +To disable these debug diagnostics, set `DD_TRACE_DEBUG=false` and restart the application +(without a conflicting `-Ddd.trace.debug=true` override). Provider debug logs are suppressed even +if the application logger remains at DEBUG. Lowering the application category to INFO also +suppresses provider debug logs immediately. When either gate is off, raw values and context are +not traversed or formatted. WARN, INFO, and ERROR messages retain their normal logging behavior. Logger and diagnostic formatting failures are isolated from provider and delivery behavior. ### Java scenario coverage @@ -356,18 +362,19 @@ not certification that every acceptance scenario has passed against a deployed A | C. Usable configuration + identity | Present | Parser summaries, `RemoteConfigServiceImplTest`, agentless apply/retain/ETag logs | | D. Environment mismatch | Present | Separate SDK, URL-requested and delivered environment fields | | E. Readiness/recovery | Present | `ProviderTest`, initial subscription availability and recovery logs | -| F. Raw evaluation details | Present | `DebugLoggingHookTest`: raw values, nested objects, defaults, context, errors, hook failure, configuration identity | +| F. Raw evaluation details | Present | `DebugLoggingHookForkedTest`: raw values, nested objects, defaults, context, errors, hook failure, configuration identity | | G. Exposure lifecycle | Present | `ExposureWriterTests`, provider suppression and listener dispatch logs | | H. Shutdown outcome | Present | Source stop, provider detach, exposure shutdown request and worker completion/delivery logs | | I. Enable/find logs | Present | Exact startup switches, SLF4J configuration, categories and destinations above | | J. Debug-off overhead | Present | Hook registration gate and tests that forbid context/result inspection with DEBUG off | -| K. Logger-failure isolation | Present | `DebugLoggingHookTest` and `DiagnosticIsolationTest`: throwing backends and level checks across lifecycle and delivery | +| K. Logger-failure isolation | Present | `DebugLoggingHookForkedTest` and `DiagnosticIsolationTest`: throwing backends and level checks across lifecycle and delivery | Run the focused suites with: ```shell git submodule update --init -- dd-smoke-tests/openfeature/src/test/resources/ffe-system-test-data ./gradlew :products:feature-flagging:feature-flagging-api:test \ + :products:feature-flagging:feature-flagging-api:forkedTest \ :products:feature-flagging:feature-flagging-lib:test \ :products:feature-flagging:feature-flagging-agent:test -PtestJvm=11 ``` diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java index 67442f007aa..1a8c3a063c1 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java @@ -1,5 +1,6 @@ package datadog.trace.api.openfeature; +import datadog.trace.bootstrap.config.provider.ConfigProvider; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -10,9 +11,11 @@ */ final class DiagnosticLogger { private final Logger delegate; + private final boolean traceDebugEnabled; private DiagnosticLogger(Logger delegate) { this.delegate = delegate; + this.traceDebugEnabled = readTraceDebugEnabled(); } public static DiagnosticLogger getLogger(Class type) { @@ -25,9 +28,18 @@ public static DiagnosticLogger getLogger(Class type) { return new DiagnosticLogger(logger); } + private static boolean readTraceDebugEnabled() { + try { + return ConfigProvider.getInstance().getBoolean("trace.debug", false); + } catch (Throwable ignored) { + // Configuration may be unavailable without an agent or with an older agent. + return false; + } + } + public boolean isDebugEnabled() { try { - return delegate != null && delegate.isDebugEnabled(); + return traceDebugEnabled && delegate != null && delegate.isDebugEnabled(); } catch (Throwable ignored) { return false; } @@ -35,7 +47,7 @@ public boolean isDebugEnabled() { public void debug(String message) { try { - if (delegate != null) { + if (traceDebugEnabled && delegate != null) { delegate.debug(message); } } catch (Throwable ignored) { @@ -45,7 +57,7 @@ public void debug(String message) { public void debug(String message, Object argument) { try { - if (delegate != null) { + if (traceDebugEnabled && delegate != null) { delegate.debug(message, argument); } } catch (Throwable ignored) { @@ -55,7 +67,7 @@ public void debug(String message, Object argument) { public void debug(String message, Object first, Object second) { try { - if (delegate != null) { + if (traceDebugEnabled && delegate != null) { delegate.debug(message, first, second); } } catch (Throwable ignored) { @@ -65,7 +77,7 @@ public void debug(String message, Object first, Object second) { public void debug(String message, Object... arguments) { try { - if (delegate != null) { + if (traceDebugEnabled && delegate != null) { delegate.debug(message, arguments); } } catch (Throwable ignored) { diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java new file mode 100644 index 00000000000..ea12f7de45f --- /dev/null +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java @@ -0,0 +1,71 @@ +package datadog.trace.api.openfeature; + +import static java.util.Collections.emptyMap; +import static java.util.concurrent.TimeUnit.MILLISECONDS; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verifyNoInteractions; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import dev.openfeature.sdk.EvaluationContext; +import dev.openfeature.sdk.FlagEvaluationDetails; +import dev.openfeature.sdk.FlagValueType; +import dev.openfeature.sdk.HookContext; +import dev.openfeature.sdk.ProviderEvaluation; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; + +/** Exercises the cached debug gate in a fresh JVM with the application logger at DEBUG. */ +class DebugLoggingDisabledForkedTest { + static { + System.setProperty("dd.trace.debug", "false"); + } + + @Test + void skipsHookRegistrationAndRawInspection() { + Logger backend = (Logger) LoggerFactory.getLogger("datadog.trace.api.openfeature"); + Level previousLevel = backend.getLevel(); + ListAppender appender = new ListAppender<>(); + appender.start(); + backend.setLevel(Level.DEBUG); + backend.addAppender(appender); + try { + Provider provider = + new Provider(new Provider.Options().initTimeout(1, MILLISECONDS), mock(Evaluator.class)); + try { + assertFalse( + provider.getProviderHooks().stream().anyMatch(DebugLoggingHook.class::isInstance)); + assertNull(DebugLoggingHook.createIfEnabled()); + EvaluationContext context = mock(EvaluationContext.class); + ProviderEvaluation result = mock(ProviderEvaluation.class); + FlagEvaluationDetails details = mock(FlagEvaluationDetails.class); + Object value = mock(Object.class); + HookContext hookContext = + HookContext.builder() + .flagKey("flag") + .type(FlagValueType.OBJECT) + .ctx(context) + .defaultValue(value) + .build(); + + DebugLoggingHook.resolution("flag", value, context, result, null); + DebugLoggingHook.resolutionError("flag", "ERROR", "raw error"); + new DebugLoggingHook().finallyAfter(hookContext, details, emptyMap()); + + verifyNoInteractions(context, result, details, value); + } finally { + provider.shutdown(); + } + assertTrue(appender.list.stream().noneMatch(event -> event.getLevel() == Level.DEBUG)); + } finally { + backend.detachAppender(appender); + appender.stop(); + backend.setLevel(previousLevel); + } + } +} diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java similarity index 99% rename from products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java rename to products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java index 8a95ade2d90..0ca8144eabd 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java @@ -56,7 +56,11 @@ import org.slf4j.Marker; import org.tabletest.junit.TableTest; -class DebugLoggingHookTest { +class DebugLoggingHookForkedTest { + static { + System.setProperty("dd.trace.debug", "true"); + } + private final Logger logger = (Logger) LoggerFactory.getLogger(DebugLoggingHook.class); private final ListAppender appender = new ListAppender<>(); private Level previousLevel; diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java new file mode 100644 index 00000000000..86f85e5cc6a --- /dev/null +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java @@ -0,0 +1,106 @@ +package datadog.trace.api.openfeature; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; +import org.tabletest.junit.TableTest; + +class DiagnosticLoggerTest { + private final Logger backend = (Logger) LoggerFactory.getLogger(DiagnosticLoggerTest.class); + private final ListAppender appender = new ListAppender<>(); + private String previousTraceDebug; + private Level previousLevel; + + @BeforeEach + void setup() { + previousTraceDebug = System.getProperty("dd.trace.debug"); + previousLevel = backend.getLevel(); + backend.setLevel(Level.DEBUG); + appender.start(); + backend.addAppender(appender); + } + + @AfterEach + void cleanup() { + setTraceDebug(previousTraceDebug); + backend.detachAppender(appender); + appender.stop(); + backend.setLevel(previousLevel); + } + + @TableTest({ + "Scenario | Trace debug | Level | Enabled", + "Both enabled | true | DEBUG | true ", + "Trace debug disabled | false | DEBUG | false ", + "Trace debug unset | | DEBUG | false ", + "Application filtered | true | INFO | false ", + "Both disabled | false | INFO | false " + }) + void requiresTraceDebugAndApplicationDebug( + String scenario, String traceDebug, String level, boolean enabled) { + setTraceDebug(traceDebug); + backend.setLevel(Level.toLevel(level)); + DiagnosticLogger logger = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); + + assertEquals(enabled, logger.isDebugEnabled()); + logDebugOverloads(logger); + + assertEquals(enabled ? 4 : 0, appender.list.size()); + } + + @Test + void cachesTraceDebugAtLoggerCreation() { + setTraceDebug("false"); + DiagnosticLogger disabled = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); + setTraceDebug("true"); + DiagnosticLogger enabled = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); + setTraceDebug("false"); + + assertFalse(disabled.isDebugEnabled()); + assertTrue(enabled.isDebugEnabled()); + disabled.debug("disabled"); + enabled.debug("enabled"); + assertEquals(1, appender.list.size()); + assertEquals("enabled", appender.list.get(0).getFormattedMessage()); + } + + @Test + void keepsOtherLevelsWhenTraceDebugIsDisabled() { + setTraceDebug("false"); + DiagnosticLogger logger = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); + logger.info("information {}", "value"); + logger.warn("warning"); + logger.warn("warning {}", "value"); + logger.error("error", new IllegalStateException("failure")); + + assertEquals(4, appender.list.size()); + assertEquals(Level.INFO, appender.list.get(0).getLevel()); + assertEquals(Level.WARN, appender.list.get(1).getLevel()); + assertEquals(Level.WARN, appender.list.get(2).getLevel()); + assertEquals(Level.ERROR, appender.list.get(3).getLevel()); + } + + private static void logDebugOverloads(DiagnosticLogger logger) { + logger.debug("message"); + logger.debug("one {}", "first"); + logger.debug("two {} {}", "first", "second"); + logger.debug("three {} {} {}", "first", "second", "third"); + } + + private static void setTraceDebug(String value) { + if (value == null) { + System.clearProperty("dd.trace.debug"); + } else { + System.setProperty("dd.trace.debug", value); + } + } +} diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java index 410da22c7ec..8ada6bd8335 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java @@ -2,6 +2,7 @@ import static java.util.Collections.singletonMap; import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertTrue; import dev.openfeature.sdk.EvaluationContext; @@ -12,6 +13,7 @@ import java.io.IOException; import java.io.InputStream; import java.lang.reflect.Constructor; +import java.lang.reflect.Method; import org.junit.jupiter.api.Test; /** @@ -54,6 +56,28 @@ void exposureHookWorksWithoutTheAgentClasses() throws Exception { evaluationClass.getMethod("getFeatures").invoke(evaluation)); } + @Test + void debugLoggingIsDisabledWithoutAgentConfiguration() throws Exception { + String previousDebug = System.getProperty("dd.trace.debug"); + System.setProperty("dd.trace.debug", "true"); + try { + ClassLoader loader = new AgentlessClassLoader(getClass().getClassLoader()); + Class loggerClass = Class.forName(DiagnosticLogger.class.getName(), true, loader); + Method getLogger = loggerClass.getMethod("getLogger", Class.class); + getLogger.setAccessible(true); + Object logger = getLogger.invoke(null, getClass()); + Method isDebugEnabled = loggerClass.getMethod("isDebugEnabled"); + isDebugEnabled.setAccessible(true); + assertFalse((Boolean) isDebugEnabled.invoke(logger)); + } finally { + if (previousDebug == null) { + System.clearProperty("dd.trace.debug"); + } else { + System.setProperty("dd.trace.debug", previousDebug); + } + } + } + private static final class AgentlessClassLoader extends ClassLoader { AgentlessClassLoader(final ClassLoader parent) { super(parent); @@ -63,7 +87,8 @@ private static final class AgentlessClassLoader extends ClassLoader { protected Class loadClass(final String name, final boolean resolve) throws ClassNotFoundException { synchronized (getClassLoadingLock(name)) { - if (name.startsWith("datadog.trace.api.featureflag.") + if (name.startsWith("datadog.trace.bootstrap.config.") + || name.startsWith("datadog.trace.api.featureflag.") || name.startsWith("datadog.trace.api.openfeature.DDEvaluator")) { throw new ClassNotFoundException(name); } From 0cae04f904232db63a72dc785d12f703fe448131 Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Wed, 21 Oct 2026 17:04:37 +0000 Subject: [PATCH 6/9] Cover unavailable and failing feature flag loggers --- .../featureflag/DiagnosticLoggerTest.java | 88 +++++++++++++++++++ 1 file changed, 88 insertions(+) create mode 100644 products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java new file mode 100644 index 00000000000..47ef63e32a7 --- /dev/null +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java @@ -0,0 +1,88 @@ +package com.datadog.featureflag; + +import static org.junit.jupiter.api.Assertions.assertDoesNotThrow; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import java.lang.reflect.Constructor; +import org.junit.jupiter.api.Test; +import org.slf4j.Logger; +import org.slf4j.Marker; +import org.slf4j.helpers.NOPLogger; + +class DiagnosticLoggerTest { + private final Marker marker = mock(Marker.class); + private final Throwable error = new IllegalStateException("diagnostic failure"); + + @Test + void forwardsMessagesAndArgumentsToTheBackend() throws Exception { + Logger backend = mock(Logger.class); + when(backend.isDebugEnabled()).thenReturn(true); + DiagnosticLogger logger = loggerWithBackend(backend); + + assertTrue(logger.isDebugEnabled()); + assertSame(backend, logger.backend()); + logAllLevels(logger); + + verify(backend).debug("message"); + verify(backend).debug("one {}", "first"); + verify(backend).debug("two {} {}", "first", "second"); + verify(backend).debug("three {} {} {}", "first", "second", "third"); + verify(backend).warn("warning"); + verify(backend).warn("warning {}", new Object[] {"argument"}); + verify(backend).error("error", error); + verify(backend).error(marker, "marked error", error); + } + + @Test + void respectsTheBackendDebugLevel() throws Exception { + Logger backend = mock(Logger.class); + assertFalse(loggerWithBackend(backend).isDebugEnabled()); + verify(backend).isDebugEnabled(); + } + + @Test + void toleratesAnUnavailableBackend() throws Exception { + DiagnosticLogger logger = loggerWithBackend(null); + + assertFalse(logger.isDebugEnabled()); + assertSame(NOPLogger.NOP_LOGGER, logger.backend()); + assertDoesNotThrow(() -> logAllLevels(logger)); + } + + @Test + void containsFailuresFromEveryLoggingOverloadAndLevelCheck() throws Exception { + Logger backend = + mock( + Logger.class, + invocation -> { + throw new AssertionError("broken backend"); + }); + DiagnosticLogger logger = loggerWithBackend(backend); + + assertFalse(logger.isDebugEnabled()); + assertDoesNotThrow(() -> logAllLevels(logger)); + } + + private void logAllLevels(DiagnosticLogger logger) { + logger.debug("message"); + logger.debug("one {}", "first"); + logger.debug("two {} {}", "first", "second"); + logger.debug("three {} {} {}", "first", "second", "third"); + logger.warn("warning"); + logger.warn("warning {}", "argument"); + logger.error("error", error); + logger.error(marker, "marked error", error); + } + + private static DiagnosticLogger loggerWithBackend(Logger backend) throws Exception { + Constructor constructor = + DiagnosticLogger.class.getDeclaredConstructor(Logger.class); + constructor.setAccessible(true); + return constructor.newInstance(backend); + } +} From e518e5a4f119e2c6e5e323d144d19e31b3b82c5a Mon Sep 17 00:00:00 2001 From: ethan-romero-dg Date: Thu, 22 Oct 2026 10:22:21 -0400 Subject: [PATCH 7/9] Simplify feature flag diagnostic logging Replace the DiagnosticLogger wrappers with plain SLF4J loggers. Agent-side code logs through the tracer's internal logger, so it needs no isolation wrapper. The provider keeps isolation where an application logging backend is involved: debug diagnostics go through debugQuietly and DebugLoggingHook, which cache DD_TRACE_DEBUG and swallow logging and formatting failures. - Warn at provider construction when DD_TRACE_DEBUG is enabled but the application logger blocks DEBUG for datadog.trace.api.openfeature. - Report flags=missing for Remote Config payloads without a flags member, separately from an empty configuration. - Drop the racy inFlight shutdown field and the duplicate parser summary. - Update the README to match. Environment: Datadog workspace Co-Authored-By: Claude Sonnet 5.5 --- .../featureflag/FeatureFlaggingSystem.java | 5 +- .../feature-flagging-api/README.md | 48 +++---- .../trace/api/openfeature/DDEvaluator.java | 8 +- .../api/openfeature/DebugLoggingHook.java | 56 ++++++-- .../api/openfeature/DiagnosticLogger.java | 127 ---------------- .../trace/api/openfeature/ExposureHook.java | 4 +- .../api/openfeature/ExposureLoggingHook.java | 22 ++- .../api/openfeature/FlagEvalLoggingHook.java | 4 +- .../api/openfeature/FlagEvalMetrics.java | 8 +- .../trace/api/openfeature/Provider.java | 86 ++++++++--- .../api/openfeature/SpanEnrichmentHook.java | 4 +- .../DebugLoggingDisabledForkedTest.java | 7 + .../DebugLoggingHookForkedTest.java | 49 ++++++- .../api/openfeature/DiagnosticLoggerTest.java | 106 -------------- .../ExposureHookWithoutAgentTest.java | 17 +-- .../AgentlessConfigurationSource.java | 47 +++--- .../AgentlessFeatureFlagBackendApi.java | 6 +- .../datadog/featureflag/DiagnosticLogger.java | 117 --------------- .../featureflag/ExposureWriterImpl.java | 15 +- .../FeatureFlagBackendApiFactory.java | 5 +- .../featureflag/FlagEvaluationWriterImpl.java | 5 +- .../featureflag/RemoteConfigServiceImpl.java | 8 +- .../SpanEnrichmentInterceptor.java | 5 +- .../featureflag/SpanEnrichmentWriter.java | 5 +- .../UniversalFlagConfigParser.java | 23 +-- .../featureflag/DiagnosticIsolationTest.java | 136 ------------------ .../featureflag/DiagnosticLoggerTest.java | 88 ------------ .../featureflag/ExposureWriterTests.java | 8 +- .../RemoteConfigServiceImplTest.java | 2 +- 29 files changed, 284 insertions(+), 737 deletions(-) delete mode 100644 products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java delete mode 100644 products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java delete mode 100644 products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java delete mode 100644 products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java delete mode 100644 products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java diff --git a/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java b/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java index f73fa5f94c3..fb8561f3518 100644 --- a/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java +++ b/products/feature-flagging/feature-flagging-agent/src/main/java/com/datadog/featureflag/FeatureFlaggingSystem.java @@ -11,6 +11,8 @@ import datadog.trace.api.featureflag.config.FeatureFlaggingConfig; import datadog.trace.api.featureflag.flagevaluation.FlagEvaluationWriter; import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class FeatureFlaggingSystem { @@ -19,8 +21,7 @@ interface SystemInitializer { void initialize(SharedCommunicationObjects sco, Config config); } - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(FeatureFlaggingSystem.class); + private static final Logger LOGGER = LoggerFactory.getLogger(FeatureFlaggingSystem.class); private static volatile ConfigurationSourceService CONFIG_SERVICE; private static volatile ExposureWriter EXPOSURE_WRITER; diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index e5c8e55a6ac..fd2489991bc 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -258,11 +258,14 @@ This setting stops exposures only. Flag evaluation events have their own setting Set `DD_TRACE_DEBUG=true` for the Java agent's configuration, writer, and transport logs. Also enable DEBUG for `datadog.trace.api.openfeature` in the application's SLF4J backend **before -constructing `Provider`**. The provider and agent have separate logging backends; -provider debug logs require both `DD_TRACE_DEBUG=true` (or `-Ddd.trace.debug=true`) and an -application logger that permits DEBUG. The trace debug setting defaults to false and is cached -when provider loggers are initialized; changing it requires restarting the application. -`DD_TRACE_DEBUG` does not change application logger levels. No additional flag evaluation data +constructing `Provider`**. The provider and agent have separate logging backends; provider +debug logs (lifecycle, exposure, and raw evaluation values, defaults, and targeting context) +require both `DD_TRACE_DEBUG=true` (or `-Ddd.trace.debug=true`) and an application logger that +permits DEBUG. The trace debug setting defaults to false and is read once, when the provider is +first constructed; changing it requires restarting the application. +`DD_TRACE_DEBUG` does not change application logger levels. If `DD_TRACE_DEBUG` is enabled but +that category does not permit DEBUG when the provider is constructed, the provider logs a WARN +that names the missing logger setting. No additional flag evaluation data setting is required for raw debug logs, including when `observe_full_evaluation_data` is false. That metadata setting continues to govern evaluation telemetry independently. @@ -320,8 +323,9 @@ Look for these diagnostic boundaries: `DD_ENV`, even if the supplied URL already contains a `dd_env` query parameter. - Parsing reports usable and rejected flag counts. Application reports include the configuration's creation time, agentless ETag or Remote Config key where available. `flags=0` on an applied - configuration means an available empty configuration; a missing configuration is reported - separately. Failed refreshes report retention of the previous configuration. HTTP attempts, + configuration means an available empty configuration. `flags=missing` means the Remote Config + payload had no `flags` member; evaluations against it return a `GENERAL` error. Removal or + absence of the whole configuration is reported separately. Failed refreshes report retention of the previous configuration. HTTP attempts, retry delays, exhaustion, unchanged responses, and subsequent application are logged. - Provider initialization reports its timeout budget, initial availability, terminal outcome, and unavailable/recovered transitions. @@ -339,35 +343,17 @@ Look for these diagnostic boundaries: - Exposures report suppression reasons, queueing, overflow, flush counts, delivery, and failed batches that are dropped. Dispatch to listeners and queueing do not confirm delivery. - Provider shutdown detaches its configuration listener; the Java agent owns the configuration - source and exposure writer. Exposure shutdown reports queued work and whether a request is in - flight. Pending exposures are **not flushed**. The processor reports completion separately, + source and exposure writer. Exposure shutdown reports queued work. Pending exposures are + **not flushed**. The processor reports completion separately, after any in-flight delivery outcome, with the counts left in its queue and buffer. To disable these debug diagnostics, set `DD_TRACE_DEBUG=false` and restart the application (without a conflicting `-Ddd.trace.debug=true` override). Provider debug logs are suppressed even if the application logger remains at DEBUG. Lowering the application category to INFO also -suppresses provider debug logs immediately. When either gate is off, raw values and context are -not traversed or formatted. WARN, INFO, and ERROR messages retain their normal logging behavior. -Logger and diagnostic formatting failures are isolated from provider and delivery behavior. - -### Java scenario coverage - -The implementation assessment below follows the shared A–K matrix. **Present means source coverage, -not certification that every acceptance scenario has passed against a deployed Agent or endpoint.** - -| Scenario | Assessment | Implementation / focused test evidence | -|---|---|---| -| A. Setup/settings | Present | `FeatureFlaggingSystem`, source startup and credential diagnostics | -| B. Fetch/failure/retry | Present | `AgentlessConfigurationSourceTest`, shared Remote Config/transport logs | -| C. Usable configuration + identity | Present | Parser summaries, `RemoteConfigServiceImplTest`, agentless apply/retain/ETag logs | -| D. Environment mismatch | Present | Separate SDK, URL-requested and delivered environment fields | -| E. Readiness/recovery | Present | `ProviderTest`, initial subscription availability and recovery logs | -| F. Raw evaluation details | Present | `DebugLoggingHookForkedTest`: raw values, nested objects, defaults, context, errors, hook failure, configuration identity | -| G. Exposure lifecycle | Present | `ExposureWriterTests`, provider suppression and listener dispatch logs | -| H. Shutdown outcome | Present | Source stop, provider detach, exposure shutdown request and worker completion/delivery logs | -| I. Enable/find logs | Present | Exact startup switches, SLF4J configuration, categories and destinations above | -| J. Debug-off overhead | Present | Hook registration gate and tests that forbid context/result inspection with DEBUG off | -| K. Logger-failure isolation | Present | `DebugLoggingHookForkedTest` and `DiagnosticIsolationTest`: throwing backends and level checks across lifecycle and delivery | +suppresses provider debug logs immediately. When either gate is off, raw values and context are not traversed or formatted. +WARN, INFO, and ERROR messages retain their normal logging behavior. Logging and formatting +failures in provider diagnostics are isolated from construction, initialization, readiness +events, evaluation, and shutdown. Run the focused suites with: diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java index a13c59d788d..2e28a5a5449 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DDEvaluator.java @@ -1,5 +1,6 @@ package datadog.trace.api.openfeature; +import static datadog.trace.api.openfeature.Provider.debugQuietly; import static java.util.Arrays.asList; import datadog.trace.api.featureflag.FeatureFlaggingGateway; @@ -49,10 +50,12 @@ import java.util.concurrent.atomic.AtomicReference; import java.util.regex.Pattern; import java.util.regex.PatternSyntaxException; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; class DDEvaluator implements Evaluator, FeatureFlaggingGateway.ConfigListener { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(DDEvaluator.class); + private static final Logger log = LoggerFactory.getLogger(DDEvaluator.class); private static final Set> SUPPORTED_RESOLUTION_TYPES = new HashSet<>(asList(String.class, Boolean.class, Integer.class, Double.class, Value.class)); @@ -223,7 +226,8 @@ public boolean initialize( final long timeout, final TimeUnit unit, final EvaluationContext context) throws Exception { FeatureFlaggingGateway.activate(); FeatureFlaggingGateway.addConfigListener(this); - log.debug( + debugQuietly( + log, "Feature Flagging provider configuration available at subscription: {}", hasConfiguration()); return initializationLatch.await(timeout, unit) || hasConfiguration(); diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java index 94a9e5c1b48..7ee11175757 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DebugLoggingHook.java @@ -1,6 +1,7 @@ package datadog.trace.api.openfeature; import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; +import datadog.trace.bootstrap.config.provider.ConfigProvider; import dev.openfeature.sdk.EvaluationContext; import dev.openfeature.sdk.FlagEvaluationDetails; import dev.openfeature.sdk.Hook; @@ -10,14 +11,25 @@ import dev.openfeature.sdk.Structure; import dev.openfeature.sdk.Value; import java.util.Map; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; -/** Logs raw evaluation diagnostics at the provider and OpenFeature hook boundaries. */ +/** + * Logs raw evaluation diagnostics at the provider and OpenFeature hook boundaries. + * + *

Raw values and context are logged only when both {@code DD_TRACE_DEBUG} and the application + * logger allow DEBUG. Logging and formatting failures never reach the evaluation. + */ final class DebugLoggingHook implements Hook { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(DebugLoggingHook.class); + private static final Logger log = LoggerFactory.getLogger(DebugLoggingHook.class); + + /** Cached {@code DD_TRACE_DEBUG}; it also gates the provider's other debug diagnostics. */ + static final boolean TRACE_DEBUG = readTraceDebug(); + private static final Structure VALUE_CONVERTER = new ImmutableStructure(); static DebugLoggingHook createIfEnabled() { - return log.isDebugEnabled() ? new DebugLoggingHook() : null; + return isEnabled() ? new DebugLoggingHook() : null; } static void resolution( @@ -26,7 +38,7 @@ static void resolution( EvaluationContext context, ProviderEvaluation result, ServerConfiguration config) { - if (!log.isDebugEnabled()) { + if (!isEnabled()) { return; } try { @@ -52,12 +64,17 @@ static void resolution( } static void resolutionError(String key, Object code, String message) { - if (log.isDebugEnabled()) { + if (!isEnabled()) { + return; + } + try { log.debug( "Feature Flagging provider resolution error: flag={}, errorCode={}, errorMessage={}", key, code, message); + } catch (Throwable ignored) { + // Diagnostics must never interrupt evaluation. } } @@ -66,7 +83,7 @@ public void finallyAfter( final HookContext context, final FlagEvaluationDetails details, final Map hints) { - if (!log.isDebugEnabled() || details == null) { + if (details == null || !isEnabled()) { return; } try { @@ -89,6 +106,14 @@ public void finallyAfter( } } + private static boolean isEnabled() { + try { + return TRACE_DEBUG && log.isDebugEnabled(); + } catch (Throwable ignored) { + return false; + } + } + /** * Materialize inside the diagnostic boundary, including user supplied structure implementations. */ @@ -102,8 +127,21 @@ private static String raw(Object value) { } private static void formattingFailed(Throwable failure) { - log.debug( - "Feature Flagging evaluation diagnostic formatting failed; raw detail unavailable", - failure); + try { + log.debug( + "Feature Flagging evaluation diagnostic formatting failed; raw detail unavailable", + failure); + } catch (Throwable ignored) { + // Diagnostics must never interrupt evaluation. + } + } + + private static boolean readTraceDebug() { + try { + return ConfigProvider.getInstance().getBoolean("trace.debug", false); + } catch (Throwable ignored) { + // Configuration is unavailable without the agent or with an older agent. + return false; + } } } diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java deleted file mode 100644 index 1a8c3a063c1..00000000000 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/DiagnosticLogger.java +++ /dev/null @@ -1,127 +0,0 @@ -package datadog.trace.api.openfeature; - -import datadog.trace.bootstrap.config.provider.ConfigProvider; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -/** - * Isolates diagnostic backend failures from feature flag behavior. - * - *

The provider owns this helper so it also works without agent classes or with an older agent. - */ -final class DiagnosticLogger { - private final Logger delegate; - private final boolean traceDebugEnabled; - - private DiagnosticLogger(Logger delegate) { - this.delegate = delegate; - this.traceDebugEnabled = readTraceDebugEnabled(); - } - - public static DiagnosticLogger getLogger(Class type) { - Logger logger; - try { - logger = LoggerFactory.getLogger(type); - } catch (Throwable ignored) { - logger = null; - } - return new DiagnosticLogger(logger); - } - - private static boolean readTraceDebugEnabled() { - try { - return ConfigProvider.getInstance().getBoolean("trace.debug", false); - } catch (Throwable ignored) { - // Configuration may be unavailable without an agent or with an older agent. - return false; - } - } - - public boolean isDebugEnabled() { - try { - return traceDebugEnabled && delegate != null && delegate.isDebugEnabled(); - } catch (Throwable ignored) { - return false; - } - } - - public void debug(String message) { - try { - if (traceDebugEnabled && delegate != null) { - delegate.debug(message); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void debug(String message, Object argument) { - try { - if (traceDebugEnabled && delegate != null) { - delegate.debug(message, argument); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void debug(String message, Object first, Object second) { - try { - if (traceDebugEnabled && delegate != null) { - delegate.debug(message, first, second); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void debug(String message, Object... arguments) { - try { - if (traceDebugEnabled && delegate != null) { - delegate.debug(message, arguments); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void warn(String message) { - try { - if (delegate != null) { - delegate.warn(message); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void warn(String message, Object... arguments) { - try { - if (delegate != null) { - delegate.warn(message, arguments); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void info(String message, Object argument) { - try { - if (delegate != null) { - delegate.info(message, argument); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void error(String message, Throwable error) { - try { - if (delegate != null) { - delegate.error(message, error); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } -} diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java index 26592e40296..01f8a479c53 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureHook.java @@ -11,6 +11,8 @@ import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Consumer; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * An OpenFeature hook that hands each completed flag evaluation to a callback, with the Datadog @@ -39,7 +41,7 @@ */ public final class ExposureHook implements Hook { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(ExposureHook.class); + private static final Logger log = LoggerFactory.getLogger(ExposureHook.class); private final Consumer callback; private final AtomicBoolean warned = new AtomicBoolean(); diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java index f2052c8dbae..f48ab528969 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/ExposureLoggingHook.java @@ -1,5 +1,7 @@ package datadog.trace.api.openfeature; +import static datadog.trace.api.openfeature.Provider.debugQuietly; + import datadog.trace.api.featureflag.FeatureFlaggingGateway; import dev.openfeature.sdk.EvaluationContext; import dev.openfeature.sdk.FlagEvaluationDetails; @@ -8,6 +10,8 @@ import dev.openfeature.sdk.ImmutableMetadata; import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Sends the exposure for a logged allocation to the agent once the evaluation has succeeded. @@ -19,7 +23,7 @@ */ class ExposureLoggingHook implements Hook { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(ExposureLoggingHook.class); + private static final Logger log = LoggerFactory.getLogger(ExposureLoggingHook.class); private static final AtomicBoolean WARNED = new AtomicBoolean(); static final ExposureLoggingHook INSTANCE = @@ -43,19 +47,21 @@ public void finallyAfter( final Map hints) { try { if (details == null || details.getErrorCode() != null) { - log.debug("Feature Flagging exposure suppressed: evaluation failed or details unavailable"); + debugQuietly( + log, "Feature Flagging exposure suppressed: evaluation failed or details unavailable"); return; } final ImmutableMetadata metadata = details.getFlagMetadata(); if (metadata == null) { - log.debug("Feature Flagging exposure suppressed: metadata unavailable"); + debugQuietly(log, "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(DDEvaluator.METADATA_DO_LOG)) || !Boolean.FALSE.equals(values.get(DDEvaluator.METADATA_EXPOSURE_CACHE_HIT))) { - log.debug( + debugQuietly( + log, "Feature Flagging exposure suppressed: allocation logging disabled or exposure already recorded"); return; } @@ -66,7 +72,8 @@ public void finallyAfter( final String variantKey = details.getVariant(); final EvaluationContext context = ctx == null ? null : ctx.getCtx(); if (allocationKey == null || variantKey == null || context == null) { - log.debug( + debugQuietly( + log, "Feature Flagging exposure suppressed: allocation, variant, or context unavailable"); return; } @@ -85,9 +92,10 @@ public void finallyAfter( serialId, SplitFeatureMetadata.featuresWithPrefix( metadata, DDEvaluator.METADATA_EXPOSURE_FEATURE_PREFIX))); - log.debug("Feature Flagging exposure dispatched to agent listeners"); + debugQuietly(log, "Feature Flagging exposure dispatched to agent listeners"); } else { - log.debug("Feature Flagging exposure suppressed: Datadog exposure logging disabled"); + debugQuietly( + log, "Feature Flagging exposure suppressed: Datadog exposure logging disabled"); } } catch (LinkageError e) { // Never let exposure reporting break flag evaluation. diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java index e2416bfd36d..41426fd3683 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalLoggingHook.java @@ -11,6 +11,8 @@ import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Supplier; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * OpenFeature Hook that captures flag evaluation events for EVP flagevaluation emission. @@ -34,7 +36,7 @@ */ class FlagEvalLoggingHook implements Hook { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(FlagEvalLoggingHook.class); + private static final Logger log = LoggerFactory.getLogger(FlagEvalLoggingHook.class); static final AtomicBoolean FEATURES_SUPPORTED = new AtomicBoolean(featuresSupported(FlagEvalEvent.class)); diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java index dae3f10b31e..2f28500f8c4 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/FlagEvalMetrics.java @@ -1,5 +1,7 @@ package datadog.trace.api.openfeature; +import static datadog.trace.api.openfeature.Provider.debugQuietly; + import dev.openfeature.sdk.ErrorCode; import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.common.AttributeKey; @@ -8,10 +10,12 @@ import io.opentelemetry.api.metrics.LongCounter; import io.opentelemetry.api.metrics.Meter; import java.io.Closeable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; class FlagEvalMetrics implements Closeable { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(FlagEvalMetrics.class); + private static final Logger log = LoggerFactory.getLogger(FlagEvalMetrics.class); private static final String METER_NAME = "ddtrace.openfeature"; private static final String METRIC_NAME = "feature_flag.evaluations"; @@ -40,7 +44,7 @@ class FlagEvalMetrics implements Closeable { .setDescription(METRIC_DESC) .build(); - log.debug("Flag evaluation metrics initialized"); + debugQuietly(log, "Flag evaluation metrics initialized"); } catch (NoClassDefFoundError e) { log.error( "OpenTelemetry API is not on the classpath — evaluation metrics disabled. Add" diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java index d3a0d01b793..39910f60975 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java @@ -23,10 +23,12 @@ import java.util.List; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class Provider extends EventProvider implements Metadata { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(Provider.class); + private static final Logger log = LoggerFactory.getLogger(Provider.class); static final String METADATA = "datadog-openfeature-provider"; private static final String EVALUATOR_IMPL = "datadog.trace.api.openfeature.DDEvaluator"; @@ -118,22 +120,37 @@ public Provider(final Options options) { final DebugLoggingHook debugLoggingHook = DebugLoggingHook.createIfEnabled(); if (debugLoggingHook != null) { hooks.add(debugLoggingHook); + } else if (DebugLoggingHook.TRACE_DEBUG) { + // DD_TRACE_DEBUG cannot raise application logger levels, so name the missing second gate. + try { + log.warn( + "DD_TRACE_DEBUG is enabled, but DEBUG is disabled for datadog.trace.api.openfeature in" + + " the application's logging configuration; provider debug diagnostics are off." + + " Enable DEBUG for that category before constructing the Provider."); + } catch (Throwable ignored) { + // A failing logging backend must not prevent provider construction. + } } this.providerHooks = hooks.isEmpty() ? Collections.emptyList() : Collections.unmodifiableList(hooks); // Announce the span-enrichment state at startup (matches the reference implementation). // "enabled" only when the gate is on (the capture hook was constructed), otherwise "disabled". - if (spanEnrichmentHook != null) { - log.info("{} span enrichment enabled", METADATA); - } else { - log.info("{} span enrichment disabled", METADATA); + try { + if (spanEnrichmentHook != null) { + log.info("{} span enrichment enabled", METADATA); + } else { + log.info("{} span enrichment disabled", METADATA); + } + } catch (Throwable ignored) { + // A failing logging backend must not prevent provider construction. } } @Override public void initialize(final EvaluationContext context) throws Exception { - log.debug( + debugQuietly( + log, "Feature Flagging provider initializing; timeout={} {}", options.getTimeout(), options.getUnit()); @@ -142,29 +159,35 @@ public void initialize(final EvaluationContext context) throws Exception { evaluator = buildEvaluator(); if (!evaluator.initialize(options.getTimeout(), options.getUnit(), context)) { if (markInitialConfigReceivedReady()) { - log.debug("Feature Flagging provider initialized successfully"); + debugQuietly(log, "Feature Flagging provider initialized successfully"); return; } markInitializationError(); - log.debug( + debugQuietly( + log, "Feature Flagging provider initialization timed out waiting for usable configuration"); throw new ProviderNotReadyError( "Provider timed-out while waiting for initial configuration"); } if (!evaluator.hasConfiguration() || !markSuccessfulInitializationReady()) { markInitializationError(); - log.debug("Feature Flagging provider initialization failed: configuration unavailable"); + debugQuietly( + log, "Feature Flagging provider initialization failed: configuration unavailable"); throw new ProviderNotReadyError( "Provider timed-out while waiting for initial configuration"); } - log.debug("Feature Flagging provider initialized successfully"); + debugQuietly(log, "Feature Flagging provider initialized successfully"); } catch (final OpenFeatureError e) { - log.debug( - "Feature Flagging provider initialization failed: errorCode={}", e.getErrorCode(), e); + debugQuietly( + log, + "Feature Flagging provider initialization failed: errorCode={}", + e.getErrorCode(), + e); markInitializationError(); throw e; } catch (final Throwable e) { - log.debug( + debugQuietly( + log, "Feature Flagging provider initialization failed: {}; verify the Java agent and feature flag configuration", e.getClass().getSimpleName(), e); @@ -191,7 +214,7 @@ void onConfigurationChange() { if (state == InitializationState.ERROR && initializationState.compareAndSet( InitializationState.ERROR, InitializationState.READY)) { - log.debug("Feature Flagging provider ready after configuration recovery"); + debugQuietly(log, "Feature Flagging provider ready after configuration recovery"); emit( ProviderEvent.PROVIDER_READY, ProviderEventDetails.builder().message("Provider ready").build()); @@ -200,7 +223,7 @@ void onConfigurationChange() { if (initializationState.get() != InitializationState.READY) { return; } - log.debug("Feature Flagging provider configuration changed"); + debugQuietly(log, "Feature Flagging provider configuration changed"); emit( ProviderEvent.PROVIDER_CONFIGURATION_CHANGED, ProviderEventDetails.builder().message("New configuration received").build()); @@ -214,7 +237,7 @@ private void onConfigurationUnavailable() { if (!initializationState.compareAndSet(InitializationState.READY, InitializationState.ERROR)) { return; } - log.debug("Feature Flagging provider configuration unavailable"); + debugQuietly(log, "Feature Flagging provider configuration unavailable"); emit( ProviderEvent.PROVIDER_ERROR, ProviderEventDetails.builder() @@ -269,7 +292,7 @@ Hook buildExposureLoggingHook() { @Override public void shutdown() { - log.debug("Feature Flagging provider shutting down"); + debugQuietly(log, "Feature Flagging provider shutting down"); if (flagEvalMetrics != null) { flagEvalMetrics.shutdown(); } @@ -279,10 +302,37 @@ public void shutdown() { if (evaluator != null) { evaluator.shutdown(); } - log.debug( + debugQuietly( + log, "Feature Flagging provider shutdown complete; configuration listener detached; agent owns exposure delivery and shutdown"); } + /** + * Logs a provider diagnostic only when {@code DD_TRACE_DEBUG} is enabled; a failing logging + * backend never changes provider behavior. + */ + static void debugQuietly(final Logger log, final String message) { + if (!DebugLoggingHook.TRACE_DEBUG) { + return; + } + try { + log.debug(message); + } catch (Throwable ignored) { + // Diagnostics must never interrupt construction, initialization, evaluation, or shutdown. + } + } + + static void debugQuietly(final Logger log, final String format, final Object... arguments) { + if (!DebugLoggingHook.TRACE_DEBUG) { + return; + } + try { + log.debug(format, arguments); + } catch (Throwable ignored) { + // Diagnostics must never interrupt construction, initialization, evaluation, or shutdown. + } + } + // Visible for tests: expose whether span enrichment is wired (gate-on) without leaking the impl. SpanEnrichmentHook spanEnrichmentHook() { return spanEnrichmentHook; diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java index 00201c2a10d..40e998a6546 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/SpanEnrichmentHook.java @@ -14,6 +14,8 @@ import java.util.LinkedHashMap; import java.util.List; import java.util.Map; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * OpenFeature {@code finally} hook that captures feature-flag evaluation metadata for APM span @@ -35,7 +37,7 @@ */ class SpanEnrichmentHook implements Hook { - private static final DiagnosticLogger log = DiagnosticLogger.getLogger(SpanEnrichmentHook.class); + private static final Logger log = LoggerFactory.getLogger(SpanEnrichmentHook.class); // The metadata keys the DDEvaluator attaches for span enrichment (single source of truth there). static final String METADATA_SERIAL_ID = DDEvaluator.METADATA_SPLIT_SERIAL_ID; diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java index ea12f7de45f..dd5a1b6d33b 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingDisabledForkedTest.java @@ -4,6 +4,7 @@ import static java.util.concurrent.TimeUnit.MILLISECONDS; 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.Mockito.mock; import static org.mockito.Mockito.verifyNoInteractions; @@ -17,6 +18,7 @@ import dev.openfeature.sdk.FlagValueType; import dev.openfeature.sdk.HookContext; import dev.openfeature.sdk.ProviderEvaluation; +import dev.openfeature.sdk.exceptions.ProviderNotReadyError; import org.junit.jupiter.api.Test; import org.slf4j.LoggerFactory; @@ -58,10 +60,15 @@ void skipsHookRegistrationAndRawInspection() { new DebugLoggingHook().finallyAfter(hookContext, details, emptyMap()); verifyNoInteractions(context, result, details, value); + assertThrows(ProviderNotReadyError.class, () -> provider.initialize(null)); + ExposureLoggingHook.INSTANCE.finallyAfter(null, null, emptyMap()); } finally { provider.shutdown(); } assertTrue(appender.list.stream().noneMatch(event -> event.getLevel() == Level.DEBUG)); + assertTrue( + appender.list.stream() + .noneMatch(event -> event.getFormattedMessage().startsWith("DD_TRACE_DEBUG"))); } finally { backend.detachAppender(appender); appender.stop(); diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java index 0ca8144eabd..4786e778a17 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DebugLoggingHookForkedTest.java @@ -81,21 +81,35 @@ void cleanup() { } @TableTest({ - "Scenario | Level | Registered", - "Debug enabled | DEBUG | true ", - "Debug filtered | INFO | false ", - "Errors only | ERROR | false " + "Scenario | Level | Registered | Warned", + "Debug enabled | DEBUG | true | false ", + "Debug filtered | INFO | false | true ", + "Errors only | ERROR | false | true " }) - void registersOnlyWhenDebugIsActive(String scenario, String level, boolean registered) { + void registersOnlyWhenDebugIsActiveAndWarnsOtherwise( + String scenario, String level, boolean registered, boolean warned) { logger.setLevel(Level.toLevel(level)); + Logger providerLogger = (Logger) LoggerFactory.getLogger(Provider.class); + ListAppender providerEvents = new ListAppender<>(); + providerEvents.start(); + providerLogger.addAppender(providerEvents); Provider provider = new Provider(new Provider.Options().initTimeout(1, MILLISECONDS), mock(Evaluator.class)); try { assertEquals( registered, provider.getProviderHooks().stream().anyMatch(DebugLoggingHook.class::isInstance)); + assertEquals( + warned, + providerEvents.list.stream() + .anyMatch( + event -> + event.getLevel() == Level.WARN + && event.getFormattedMessage().startsWith("DD_TRACE_DEBUG is enabled"))); } finally { provider.shutdown(); + providerLogger.detachAppender(providerEvents); + providerEvents.stop(); } } @@ -304,6 +318,31 @@ void disabledResolutionDoesNotInspectContextResultOrValues() { assertTrue(appender.list.isEmpty()); } + @Test + void enabledTraceDebugLogsProviderLifecycle() { + Logger providerLogger = (Logger) LoggerFactory.getLogger(Provider.class); + Level previousLevel = providerLogger.getLevel(); + ListAppender lifecycle = new ListAppender<>(); + lifecycle.start(); + providerLogger.setLevel(Level.DEBUG); + providerLogger.addAppender(lifecycle); + try { + new Provider(new Provider.Options(), mock(Evaluator.class)).shutdown(); + assertTrue( + lifecycle.list.stream() + .anyMatch( + event -> + event.getLevel() == Level.DEBUG + && event + .getFormattedMessage() + .equals("Feature Flagging provider shutting down"))); + } finally { + providerLogger.detachAppender(lifecycle); + lifecycle.stop(); + providerLogger.setLevel(previousLevel); + } + } + @TableTest({ "Scenario | Fail level check", "backend throws | false ", diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java deleted file mode 100644 index 86f85e5cc6a..00000000000 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/DiagnosticLoggerTest.java +++ /dev/null @@ -1,106 +0,0 @@ -package datadog.trace.api.openfeature; - -import static org.junit.jupiter.api.Assertions.assertEquals; -import static org.junit.jupiter.api.Assertions.assertFalse; -import static org.junit.jupiter.api.Assertions.assertTrue; - -import ch.qos.logback.classic.Level; -import ch.qos.logback.classic.Logger; -import ch.qos.logback.classic.spi.ILoggingEvent; -import ch.qos.logback.core.read.ListAppender; -import org.junit.jupiter.api.AfterEach; -import org.junit.jupiter.api.BeforeEach; -import org.junit.jupiter.api.Test; -import org.slf4j.LoggerFactory; -import org.tabletest.junit.TableTest; - -class DiagnosticLoggerTest { - private final Logger backend = (Logger) LoggerFactory.getLogger(DiagnosticLoggerTest.class); - private final ListAppender appender = new ListAppender<>(); - private String previousTraceDebug; - private Level previousLevel; - - @BeforeEach - void setup() { - previousTraceDebug = System.getProperty("dd.trace.debug"); - previousLevel = backend.getLevel(); - backend.setLevel(Level.DEBUG); - appender.start(); - backend.addAppender(appender); - } - - @AfterEach - void cleanup() { - setTraceDebug(previousTraceDebug); - backend.detachAppender(appender); - appender.stop(); - backend.setLevel(previousLevel); - } - - @TableTest({ - "Scenario | Trace debug | Level | Enabled", - "Both enabled | true | DEBUG | true ", - "Trace debug disabled | false | DEBUG | false ", - "Trace debug unset | | DEBUG | false ", - "Application filtered | true | INFO | false ", - "Both disabled | false | INFO | false " - }) - void requiresTraceDebugAndApplicationDebug( - String scenario, String traceDebug, String level, boolean enabled) { - setTraceDebug(traceDebug); - backend.setLevel(Level.toLevel(level)); - DiagnosticLogger logger = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); - - assertEquals(enabled, logger.isDebugEnabled()); - logDebugOverloads(logger); - - assertEquals(enabled ? 4 : 0, appender.list.size()); - } - - @Test - void cachesTraceDebugAtLoggerCreation() { - setTraceDebug("false"); - DiagnosticLogger disabled = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); - setTraceDebug("true"); - DiagnosticLogger enabled = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); - setTraceDebug("false"); - - assertFalse(disabled.isDebugEnabled()); - assertTrue(enabled.isDebugEnabled()); - disabled.debug("disabled"); - enabled.debug("enabled"); - assertEquals(1, appender.list.size()); - assertEquals("enabled", appender.list.get(0).getFormattedMessage()); - } - - @Test - void keepsOtherLevelsWhenTraceDebugIsDisabled() { - setTraceDebug("false"); - DiagnosticLogger logger = DiagnosticLogger.getLogger(DiagnosticLoggerTest.class); - logger.info("information {}", "value"); - logger.warn("warning"); - logger.warn("warning {}", "value"); - logger.error("error", new IllegalStateException("failure")); - - assertEquals(4, appender.list.size()); - assertEquals(Level.INFO, appender.list.get(0).getLevel()); - assertEquals(Level.WARN, appender.list.get(1).getLevel()); - assertEquals(Level.WARN, appender.list.get(2).getLevel()); - assertEquals(Level.ERROR, appender.list.get(3).getLevel()); - } - - private static void logDebugOverloads(DiagnosticLogger logger) { - logger.debug("message"); - logger.debug("one {}", "first"); - logger.debug("two {} {}", "first", "second"); - logger.debug("three {} {} {}", "first", "second", "third"); - } - - private static void setTraceDebug(String value) { - if (value == null) { - System.clearProperty("dd.trace.debug"); - } else { - System.setProperty("dd.trace.debug", value); - } - } -} diff --git a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java index 8ada6bd8335..9a9b34a4cef 100644 --- a/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java +++ b/products/feature-flagging/feature-flagging-api/src/test/java/datadog/trace/api/openfeature/ExposureHookWithoutAgentTest.java @@ -13,7 +13,7 @@ import java.io.IOException; import java.io.InputStream; import java.lang.reflect.Constructor; -import java.lang.reflect.Method; +import java.lang.reflect.Field; import org.junit.jupiter.api.Test; /** @@ -57,18 +57,15 @@ void exposureHookWorksWithoutTheAgentClasses() throws Exception { } @Test - void debugLoggingIsDisabledWithoutAgentConfiguration() throws Exception { + void rawDebugLoggingIsDisabledWithoutAgentConfiguration() throws Exception { String previousDebug = System.getProperty("dd.trace.debug"); System.setProperty("dd.trace.debug", "true"); try { ClassLoader loader = new AgentlessClassLoader(getClass().getClassLoader()); - Class loggerClass = Class.forName(DiagnosticLogger.class.getName(), true, loader); - Method getLogger = loggerClass.getMethod("getLogger", Class.class); - getLogger.setAccessible(true); - Object logger = getLogger.invoke(null, getClass()); - Method isDebugEnabled = loggerClass.getMethod("isDebugEnabled"); - isDebugEnabled.setAccessible(true); - assertFalse((Boolean) isDebugEnabled.invoke(logger)); + Class hookClass = Class.forName(DebugLoggingHook.class.getName(), true, loader); + Field traceDebug = hookClass.getDeclaredField("TRACE_DEBUG"); + traceDebug.setAccessible(true); + assertFalse(traceDebug.getBoolean(null)); } finally { if (previousDebug == null) { System.clearProperty("dd.trace.debug"); @@ -94,7 +91,7 @@ protected Class loadClass(final String name, final boolean resolve) } if (name.startsWith("datadog.trace.api.openfeature.ExposureHook") || name.equals("datadog.trace.api.openfeature.SplitFeatureMetadata") - || name.equals("datadog.trace.api.openfeature.DiagnosticLogger")) { + || name.equals("datadog.trace.api.openfeature.DebugLoggingHook")) { Class loaded = findLoadedClass(name); if (loaded == null) { final byte[] bytes = classBytes(name); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java index 1130d1fe4e3..ba4b393a460 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessConfigurationSource.java @@ -33,10 +33,11 @@ import okhttp3.Request; import okhttp3.Response; import okhttp3.ResponseBody; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; final class AgentlessConfigurationSource implements ConfigurationSourceService { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(AgentlessConfigurationSource.class); + private static final Logger LOGGER = LoggerFactory.getLogger(AgentlessConfigurationSource.class); private static final String DATADOG_UFC_RULES_BASED_SERVER_PATH = "/api/v2/feature-flagging/config/rules-based/server"; @@ -80,7 +81,7 @@ private AgentlessConfigurationSource(final Config config, final HttpUrl endpoint () -> ThreadLocalRandom.current().nextDouble(1 - RETRY_JITTER, 1 + RETRY_JITTER)), Executors.newSingleThreadScheduledExecutor( new AgentThreadFactory(FEATURE_FLAG_CONFIGURATION_POLLER)), - new RatelimitedLogger(LOGGER.backend(), MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); + new RatelimitedLogger(LOGGER, MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); } AgentlessConfigurationSource( @@ -95,7 +96,7 @@ private AgentlessConfigurationSource(final Config config, final HttpUrl endpoint pollIntervalMillis, client, executor, - new RatelimitedLogger(LOGGER.backend(), MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); + new RatelimitedLogger(LOGGER, MINUTES_BETWEEN_WARNINGS, TimeUnit.MINUTES)); } AgentlessConfigurationSource( @@ -214,14 +215,10 @@ private boolean fetchAndApply() { return false; } if (isRetryableStatus(response.status)) { - try { - ratelimitedLogger.warn( - "Feature Flagging agentless endpoint failed after {} attempts with HTTP {}; retaining current configuration; retry on next poll", - MAX_ATTEMPTS, - response.status); - } catch (Throwable ignored) { - // Logging must not interrupt polling or recovery. - } + ratelimitedLogger.warn( + "Feature Flagging agentless endpoint failed after {} attempts with HTTP {}; retaining current configuration; retry on next poll", + MAX_ATTEMPTS, + response.status); return false; } synchronized (lifecycleLock) { @@ -229,16 +226,12 @@ private boolean fetchAndApply() { } } catch (final IOException e) { if (!closed) { - try { - ratelimitedLogger.warn( - "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}; retaining current configuration; retry on next poll", - MAX_ATTEMPTS, - e.getClass().getSimpleName(), - e.getMessage(), - e); - } catch (Throwable ignored) { - // Logging must not interrupt polling or recovery. - } + ratelimitedLogger.warn( + "Feature Flagging agentless endpoint request failed after {} attempts: {}: {}; retaining current configuration; retry on next poll", + MAX_ATTEMPTS, + e.getClass().getSimpleName(), + e.getMessage(), + e); } return false; } @@ -252,13 +245,9 @@ private boolean apply(final UfcHttpResponse response) { } if (response.status == HttpURLConnection.HTTP_UNAUTHORIZED || response.status == HttpURLConnection.HTTP_FORBIDDEN) { - try { - ratelimitedLogger.warn( - "Feature Flagging agentless endpoint returned HTTP {}; verify endpoint authentication", - response.status); - } catch (Throwable ignored) { - // Logging must not interrupt polling or recovery. - } + ratelimitedLogger.warn( + "Feature Flagging agentless endpoint returned HTTP {}; verify endpoint authentication", + response.status); return false; } if (response.status != HttpURLConnection.HTTP_OK) { diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java index 60ebf9651cd..59919840ffe 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/AgentlessFeatureFlagBackendApi.java @@ -11,12 +11,14 @@ import java.util.function.Supplier; import javax.annotation.Nullable; import okhttp3.RequestBody; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** Sends Feature Flag events through the process-wide Agentless EVP route selector. */ final class AgentlessFeatureFlagBackendApi implements BackendApi { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(AgentlessFeatureFlagBackendApi.class); + private static final Logger LOGGER = + LoggerFactory.getLogger(AgentlessFeatureFlagBackendApi.class); private final FeatureFlagRouteSelector routeSelector; private final Supplier proxyEndpointSupplier; diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java deleted file mode 100644 index 82b37b4e34d..00000000000 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/DiagnosticLogger.java +++ /dev/null @@ -1,117 +0,0 @@ -package com.datadog.featureflag; - -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; -import org.slf4j.Marker; - -/** Isolates diagnostic backend failures from feature flag behavior. */ -public final class DiagnosticLogger { - private final Logger delegate; - - private DiagnosticLogger(Logger delegate) { - this.delegate = delegate; - } - - public static DiagnosticLogger getLogger(Class type) { - Logger logger; - try { - logger = LoggerFactory.getLogger(type); - } catch (Throwable ignored) { - logger = null; - } - return new DiagnosticLogger(logger); - } - - /** The rate limiter's calls are guarded by its caller, including its own level checks. */ - Logger backend() { - return delegate == null ? org.slf4j.helpers.NOPLogger.NOP_LOGGER : delegate; - } - - public boolean isDebugEnabled() { - try { - return delegate != null && delegate.isDebugEnabled(); - } catch (Throwable ignored) { - return false; - } - } - - public void debug(String message) { - try { - if (delegate != null) { - delegate.debug(message); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void debug(String message, Object argument) { - try { - if (delegate != null) { - delegate.debug(message, argument); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void debug(String message, Object first, Object second) { - try { - if (delegate != null) { - delegate.debug(message, first, second); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void debug(String message, Object... arguments) { - try { - if (delegate != null) { - delegate.debug(message, arguments); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void warn(String message) { - try { - if (delegate != null) { - delegate.warn(message); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void warn(String message, Object... arguments) { - try { - if (delegate != null) { - delegate.warn(message, arguments); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } - - public void error(String message, Throwable error) { - try { - if (delegate != null) { - delegate.error(message, error); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt teardown. - } - } - - public void error(Marker marker, String message, Throwable error) { - try { - if (delegate != null) { - delegate.error(marker, message, error); - } - } catch (Throwable ignored) { - // A diagnostic must never interrupt evaluation, readiness notification, or teardown. - } - } -} diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java index 623dc11705c..998e8306f09 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java @@ -22,11 +22,12 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Supplier; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class ExposureWriterImpl implements ExposureWriter, FeatureFlagEventWriter { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(ExposureWriterImpl.class); + private static final Logger LOGGER = LoggerFactory.getLogger(ExposureWriterImpl.class); private static final int DEFAULT_CAPACITY = 1 << 16; // 65536 elements private static final int DEFAULT_FLUSH_INTERVAL_IN_SECONDS = 1; private static final int FLUSH_THRESHOLD = 100; @@ -146,9 +147,8 @@ public void requestShutdown() { FeatureFlaggingGateway.removeExposureListener(this); if (LOGGER.isDebugEnabled()) { LOGGER.debug( - "Feature Flagging exposure shutdown requested: queued={}, inFlight={}; pending exposures will not be flushed; processor completion is reported separately", - queue.size(), - serializer.inFlight); + "Feature Flagging exposure shutdown requested: queued={}; pending exposures will not be flushed; processor completion is reported separately", + queue.size()); } // Polling wakes within 100 ms. An interrupt can race with, or abort, the final POST. serializer.requestShutdown(); @@ -195,7 +195,6 @@ private static class ExposureSerializingHandler implements Runnable { private final List buffer = new ArrayList<>(); private final Runnable errorCallback; private final AtomicBoolean shutdownRequested = new AtomicBoolean(false); - private volatile boolean inFlight; ExposureSerializingHandler( final Supplier backendApiSupplier, @@ -244,7 +243,7 @@ public void run() { } } LOGGER.debug( - "Feature Flagging exposure processor stopped; pending exposures are not flushed on shutdown; queued={}, buffered={}, inFlight=false", + "Feature Flagging exposure processor stopped; pending exposures are not flushed on shutdown; queued={}, buffered={}", queue.size(), buffer.size()); } @@ -306,7 +305,6 @@ private void flush() { } try { LOGGER.debug("Feature Flagging exposure flush starting: count={}", this.buffer.size()); - inFlight = true; evpPublisher.post(EXPOSURES_ROUTE, payload); LOGGER.debug("Feature Flagging exposure flush delivered: count={}", this.buffer.size()); } catch (AgentlessFeatureFlagBackendApi.UnavailableRouteException ignored) { @@ -324,7 +322,6 @@ private void flush() { e); } } finally { - inFlight = false; // Best-effort delivery must not retry an ambiguously accepted batch. A later definitive // proxy rejection could otherwise replay the same exposures through direct intake. this.buffer.clear(); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java index 8401c445d55..d4f3c8c499a 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FeatureFlagBackendApiFactory.java @@ -20,12 +20,13 @@ import java.util.Map; import javax.annotation.Nullable; import okhttp3.Response; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** Selects the transport for Feature Flagging events. */ final class FeatureFlagBackendApiFactory { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(FeatureFlagBackendApiFactory.class); + private static final Logger LOGGER = LoggerFactory.getLogger(FeatureFlagBackendApiFactory.class); private static final Map REQUEST_HEADERS = requestHeaders(); /** Retries connection refusal only; automatic retries and redirects remain disabled. */ diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java index f5c76c812bd..c2a6231076c 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/FlagEvaluationWriterImpl.java @@ -24,6 +24,8 @@ import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicLong; import java.util.function.Supplier; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * EVP flagevaluation writer for Java. @@ -52,8 +54,7 @@ */ public class FlagEvaluationWriterImpl implements FlagEvaluationWriter, FeatureFlagEventWriter { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(FlagEvaluationWriterImpl.class); + private static final Logger LOGGER = LoggerFactory.getLogger(FlagEvaluationWriterImpl.class); static final int DEFAULT_CAPACITY = 1 << 12; // 4096 elements, per cross-SDK RFC static final int FLUSH_INTERVAL_SECONDS = 10; diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java index d059c981f08..8e8106bad6d 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/RemoteConfigServiceImpl.java @@ -10,12 +10,13 @@ import datadog.trace.api.featureflag.FeatureFlaggingGateway; import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; import javax.annotation.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class RemoteConfigServiceImpl implements ConfigurationSourceService, ConfigurationChangesTypedListener { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(RemoteConfigServiceImpl.class); + private static final Logger LOGGER = LoggerFactory.getLogger(RemoteConfigServiceImpl.class); private final ConfigurationPoller configurationPoller; @@ -52,7 +53,8 @@ public void accept( LOGGER.debug( "Feature Flagging remote_config configuration applied: key={}, flags={}, configurationEnv={}, createdAt={}, invalidFlags={}", configKey, - configuration.flags == null ? 0 : configuration.flags.size(), + // A payload without a flags member is not an empty configuration. + configuration.flags == null ? "missing" : configuration.flags.size(), configuration.environment == null ? null : configuration.environment.name, configuration.createdAt, configuration.invalidFlags == null ? 0 : configuration.invalidFlags.size()); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java index 9098ce17fa6..a82e194e248 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentInterceptor.java @@ -5,6 +5,8 @@ import datadog.trace.bootstrap.instrumentation.api.AgentSpan; import java.util.Collection; import java.util.Map; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * {@link TraceInterceptor} that writes the accumulated {@code ffe_*} tags onto the local root span @@ -44,8 +46,7 @@ */ final class SpanEnrichmentInterceptor implements TraceInterceptor { - private static final DiagnosticLogger log = - DiagnosticLogger.getLogger(SpanEnrichmentInterceptor.class); + private static final Logger log = LoggerFactory.getLogger(SpanEnrichmentInterceptor.class); /** * Unique priority in the "trace data enrichment" band, after {@code GIT_METADATA} (3) and before diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java index 4fafe68404d..f97259d9368 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/SpanEnrichmentWriter.java @@ -6,6 +6,8 @@ import datadog.trace.bootstrap.instrumentation.api.AgentSpan; import datadog.trace.bootstrap.instrumentation.api.AgentTracer; import java.util.concurrent.atomic.AtomicBoolean; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Agent-side owner of APM feature-flag span enrichment. This is the WRITE tier of the @@ -33,8 +35,7 @@ public final class SpanEnrichmentWriter implements FeatureFlaggingGateway.SpanEnrichmentListener, AutoCloseable { - private static final DiagnosticLogger log = - DiagnosticLogger.getLogger(SpanEnrichmentWriter.class); + private static final Logger log = LoggerFactory.getLogger(SpanEnrichmentWriter.class); public static SpanEnrichmentWriter getInstance() { return SingletonHolder.INSTANCE; diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java index 48037467b97..39bfdf1bef3 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/UniversalFlagConfigParser.java @@ -33,11 +33,12 @@ import javax.annotation.Nullable; import okio.BufferedSource; import okio.Okio; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; final class UniversalFlagConfigParser implements ConfigurationDeserializer { - private static final DiagnosticLogger LOGGER = - DiagnosticLogger.getLogger(UniversalFlagConfigParser.class); + private static final Logger LOGGER = LoggerFactory.getLogger(UniversalFlagConfigParser.class); static final String INVALID_FLAG = "invalid_flag"; static final String INVALID_SEMVER_COMPARAND = "invalid_semver_comparand"; @@ -94,15 +95,6 @@ ServerConfiguration parse(final JsonReader reader) throws IOException { } } INVALID_FLAGS_HOLDER.get().clear(); - if (LOGGER.isDebugEnabled()) { - LOGGER.debug( - "Feature Flagging configuration received: usableFlags={}, invalidFlags={}, configurationPresent={}", - configuration == null || configuration.flags == null ? 0 : configuration.flags.size(), - configuration == null || configuration.invalidFlags == null - ? 0 - : configuration.invalidFlags.size(), - configuration != null && configuration.flags != null); - } return configuration; } @@ -397,11 +389,10 @@ public Map fromJson(@Nonnull final JsonReader reader) throws IOExc } } catch (JsonDataException | IllegalArgumentException error) { rejectedFlags++; - final String reason = - error instanceof InvalidSemverComparandException - ? INVALID_SEMVER_COMPARAND - : INVALID_FLAG; - INVALID_FLAGS_HOLDER.get().put(flagKey, reason); + INVALID_FLAGS_HOLDER.get().put(flagKey, INVALID_FLAG); + if (error instanceof InvalidSemverComparandException) { + INVALID_FLAGS_HOLDER.get().put(flagKey, INVALID_SEMVER_COMPARAND); + } LOGGER.warn( "Feature Flagging rejected flag {} during configuration parsing: {}", flagKey, diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java deleted file mode 100644 index 0f75b50ca2b..00000000000 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticIsolationTest.java +++ /dev/null @@ -1,136 +0,0 @@ -package com.datadog.featureflag; - -import static java.nio.charset.StandardCharsets.UTF_8; -import static java.util.Collections.emptyMap; -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.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 static org.mockito.Mockito.when; - -import ch.qos.logback.classic.Level; -import ch.qos.logback.classic.Logger; -import ch.qos.logback.classic.LoggerContext; -import ch.qos.logback.classic.turbo.TurboFilter; -import ch.qos.logback.core.spi.FilterReply; -import datadog.communication.BackendApi; -import datadog.communication.BackendApiFactory; -import datadog.communication.ddagent.SharedCommunicationObjects; -import datadog.remoteconfig.ConfigurationPoller; -import datadog.remoteconfig.Product; -import datadog.trace.api.Config; -import datadog.trace.api.featureflag.FeatureFlaggingGateway; -import datadog.trace.api.featureflag.exposure.Allocation; -import datadog.trace.api.featureflag.exposure.ExposureEvent; -import datadog.trace.api.featureflag.exposure.Flag; -import datadog.trace.api.featureflag.exposure.Subject; -import datadog.trace.api.featureflag.exposure.Variant; -import datadog.trace.api.featureflag.ufc.v1.ServerConfiguration; -import datadog.trace.api.intake.Intake; -import datadog.trace.test.util.PollingConditions; -import java.util.concurrent.ScheduledExecutorService; -import okhttp3.HttpUrl; -import org.slf4j.LoggerFactory; -import org.slf4j.Marker; -import org.tabletest.junit.TableTest; - -class DiagnosticIsolationTest { - @TableTest({ - "Scenario | Fail level check", - "backend throws | false ", - "level check throws | true " - }) - void preservesConfigurationAndDeliveryWhenLoggingFails(boolean failLevelCheck) throws Exception { - LoggerContext logging = (LoggerContext) LoggerFactory.getILoggerFactory(); - TurboFilter failure = - new TurboFilter() { - @Override - public FilterReply decide( - Marker marker, - Logger logger, - Level level, - String format, - Object[] params, - Throwable error) { - if (logger.getName().startsWith("com.datadog.featureflag") - && (failLevelCheck || format != null)) { - throw new AssertionError("broken logger"); - } - return FilterReply.NEUTRAL; - } - }; - failure.start(); - logging.addTurboFilter(failure); - FeatureFlaggingGateway.ConfigListener listener = - mock(FeatureFlaggingGateway.ConfigListener.class); - FeatureFlaggingGateway.addConfigListener(listener); - try { - Config config = mock(Config.class); - SharedCommunicationObjects sco = mock(SharedCommunicationObjects.class); - ConfigurationPoller poller = mock(ConfigurationPoller.class); - when(sco.configurationPoller(config)).thenReturn(poller); - try (RemoteConfigServiceImpl service = new RemoteConfigServiceImpl(sco, config)) { - service.init(); - ServerConfiguration parsed = - UniversalFlagConfigParser.INSTANCE.deserialize( - "{\"flags\":{\"bad\":42}}".getBytes(UTF_8)); - assertEquals(1, parsed.invalidFlags.size()); - service.accept("config", parsed, null); - verify(listener).accept(parsed); - } - verify(poller).removeListeners(Product.FFE_FLAGS); - verify(poller).stop(); - - AgentlessConfigurationSource.UfcHttpClient client = - mock(AgentlessConfigurationSource.UfcHttpClient.class); - ScheduledExecutorService executor = mock(ScheduledExecutorService.class); - HttpUrl endpoint = HttpUrl.get("http://localhost/config"); - when(client.fetch(eq(endpoint), eq(config), any())) - .thenReturn(new AgentlessConfigurationSource.UfcHttpResponse(503, null, null)) - .thenReturn( - new AgentlessConfigurationSource.UfcHttpResponse( - 200, - "v1", - "{\"data\":{\"type\":\"universal-flag-configuration\",\"attributes\":{\"flags\":{}}}}" - .getBytes(UTF_8))); - try (AgentlessConfigurationSource source = - new AgentlessConfigurationSource(endpoint, config, 1000, client, executor)) { - source.init(); - assertTrue(source.pollOnce()); - } - verify(client).cancel(); - verify(executor).shutdownNow(); - - BackendApi backend = mock(BackendApi.class); - BackendApiFactory backendFactory = mock(BackendApiFactory.class); - when(backendFactory.createEvpProxyApi(Intake.EVENT_PLATFORM, true)).thenReturn(backend); - FeatureFlagBackendApiFactory factory = - new FeatureFlagBackendApiFactory(config, backendFactory, FeatureFlagEventType.EXPOSURE); - ExposureWriterImpl writer = new ExposureWriterImpl(16, 1, MILLISECONDS, factory, config); - PollingConditions poll = new PollingConditions(5); - try { - writer.init(); - writer.accept( - new ExposureEvent( - 1, - new Allocation("allocation"), - new Flag("flag"), - new Variant("variant"), - new Subject("user", emptyMap()))); - poll.eventually(() -> verify(backend).post(any(), any(), any(), any(), eq(false))); - } finally { - writer.close(); - } - poll.eventually(() -> assertFalse(writer.isSerializerThreadAlive())); - } finally { - FeatureFlaggingGateway.removeConfigListener(listener); - FeatureFlaggingGateway.dispatch((ServerConfiguration) null); - logging.getTurboFilterList().remove(failure); - failure.stop(); - } - } -} diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java deleted file mode 100644 index 47ef63e32a7..00000000000 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/DiagnosticLoggerTest.java +++ /dev/null @@ -1,88 +0,0 @@ -package com.datadog.featureflag; - -import static org.junit.jupiter.api.Assertions.assertDoesNotThrow; -import static org.junit.jupiter.api.Assertions.assertFalse; -import static org.junit.jupiter.api.Assertions.assertSame; -import static org.junit.jupiter.api.Assertions.assertTrue; -import static org.mockito.Mockito.mock; -import static org.mockito.Mockito.verify; -import static org.mockito.Mockito.when; - -import java.lang.reflect.Constructor; -import org.junit.jupiter.api.Test; -import org.slf4j.Logger; -import org.slf4j.Marker; -import org.slf4j.helpers.NOPLogger; - -class DiagnosticLoggerTest { - private final Marker marker = mock(Marker.class); - private final Throwable error = new IllegalStateException("diagnostic failure"); - - @Test - void forwardsMessagesAndArgumentsToTheBackend() throws Exception { - Logger backend = mock(Logger.class); - when(backend.isDebugEnabled()).thenReturn(true); - DiagnosticLogger logger = loggerWithBackend(backend); - - assertTrue(logger.isDebugEnabled()); - assertSame(backend, logger.backend()); - logAllLevels(logger); - - verify(backend).debug("message"); - verify(backend).debug("one {}", "first"); - verify(backend).debug("two {} {}", "first", "second"); - verify(backend).debug("three {} {} {}", "first", "second", "third"); - verify(backend).warn("warning"); - verify(backend).warn("warning {}", new Object[] {"argument"}); - verify(backend).error("error", error); - verify(backend).error(marker, "marked error", error); - } - - @Test - void respectsTheBackendDebugLevel() throws Exception { - Logger backend = mock(Logger.class); - assertFalse(loggerWithBackend(backend).isDebugEnabled()); - verify(backend).isDebugEnabled(); - } - - @Test - void toleratesAnUnavailableBackend() throws Exception { - DiagnosticLogger logger = loggerWithBackend(null); - - assertFalse(logger.isDebugEnabled()); - assertSame(NOPLogger.NOP_LOGGER, logger.backend()); - assertDoesNotThrow(() -> logAllLevels(logger)); - } - - @Test - void containsFailuresFromEveryLoggingOverloadAndLevelCheck() throws Exception { - Logger backend = - mock( - Logger.class, - invocation -> { - throw new AssertionError("broken backend"); - }); - DiagnosticLogger logger = loggerWithBackend(backend); - - assertFalse(logger.isDebugEnabled()); - assertDoesNotThrow(() -> logAllLevels(logger)); - } - - private void logAllLevels(DiagnosticLogger logger) { - logger.debug("message"); - logger.debug("one {}", "first"); - logger.debug("two {} {}", "first", "second"); - logger.debug("three {} {} {}", "first", "second", "third"); - logger.warn("warning"); - logger.warn("warning {}", "argument"); - logger.error("error", error); - logger.error(marker, "marked error", error); - } - - private static DiagnosticLogger loggerWithBackend(Logger backend) throws Exception { - Constructor constructor = - DiagnosticLogger.class.getDeclaredConstructor(Logger.class); - constructor.setAccessible(true); - return constructor.newInstance(backend); - } -} diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java index c0c8abae850..6c21e51e08d 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java @@ -286,15 +286,11 @@ void reportsShutdownWithPendingAndInFlightExposures(boolean fails, String outcom poll.eventually(() -> assertFalse(writer.isSerializerThreadAlive())); assertTrue( appender.list.stream() - .anyMatch( - e -> - e.getFormattedMessage() - .contains("shutdown requested: queued=1, inFlight=true"))); + .anyMatch(e -> e.getFormattedMessage().contains("shutdown requested: queued=1;"))); assertTrue(appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(outcome))); assertTrue( appender.list.stream() - .anyMatch( - e -> e.getFormattedMessage().contains("queued=1, buffered=0, inFlight=false"))); + .anyMatch(e -> e.getFormattedMessage().contains("queued=1, buffered=0"))); verify(backend).post(any(), any(), any(), any(), eq(false)); } finally { writer.close(); diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java index 48be3b98b35..ac334aa46e7 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/RemoteConfigServiceImplTest.java @@ -143,7 +143,7 @@ void reportsAppliedConfigurationWithoutFlagsOrEnvironment() { verify(listener).accept(config); assertLogged( - "configuration applied: key=config, flags=0, configurationEnv=null, createdAt=null"); + "configuration applied: key=config, flags=missing, configurationEnv=null, createdAt=null"); } @Test From 6554ed252fb6355f208df0204f43c795de04db48 Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Thu, 22 Oct 2026 14:25:41 +0000 Subject: [PATCH 8/9] Clarify which provider debug logs DD_TRACE_DEBUG gates DD_TRACE_DEBUG gates the lifecycle, evaluation, and exposure diagnostics, but a few existing debug messages for rare failures follow only the application logger level. Only debug diagnostics are isolated from logging failures; WARN and ERROR messages are not. Environment: Datadog workspace Co-Authored-By: Claude Opus 5.5 --- .../feature-flagging-api/README.md | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index fd2489991bc..e49fe1244b2 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -348,12 +348,15 @@ Look for these diagnostic boundaries: after any in-flight delivery outcome, with the counts left in its queue and buffer. To disable these debug diagnostics, set `DD_TRACE_DEBUG=false` and restart the application -(without a conflicting `-Ddd.trace.debug=true` override). Provider debug logs are suppressed even -if the application logger remains at DEBUG. Lowering the application category to INFO also -suppresses provider debug logs immediately. When either gate is off, raw values and context are not traversed or formatted. -WARN, INFO, and ERROR messages retain their normal logging behavior. Logging and formatting -failures in provider diagnostics are isolated from construction, initialization, readiness -events, evaluation, and shutdown. +(without a conflicting `-Ddd.trace.debug=true` override). Provider lifecycle, evaluation, and +exposure debug diagnostics are then suppressed even if the application logger remains at DEBUG. +A few debug messages for rare failures (an exposure callback, span enrichment, or metric recording +failure, or an older agent missing a feature) follow only the application logger level. Lowering +the application category to INFO suppresses all provider debug logs immediately. When either gate +is off, raw values and context are not traversed or formatted. WARN, INFO, and ERROR messages +retain their normal logging behavior. Logging and formatting failures in provider debug +diagnostics are isolated from construction, initialization, readiness events, evaluation, and +shutdown; WARN and ERROR messages are not isolated from a logging backend that throws. Run the focused suites with: From 92567d114008b8d7383cedf2d4628e0425e6165c Mon Sep 17 00:00:00 2001 From: "ethan.romero" Date: Thu, 22 Oct 2026 14:44:20 +0000 Subject: [PATCH 9/9] Align exposure shutdown diagnostics with the final flush Master now drains pending exposures and makes one final best-effort flush on shutdown instead of interrupting the processor. Update the shutdown messages and README to match, and log exposures dropped after shutdown starts and a shutdown wait that expires before the final delivery returns. Rework the affected tests to inject the backend directly, since route selection moved into the backend factory. Note in Provider that evaluation telemetry opt-out does not apply to local debug diagnostics. Environment: Datadog workspace Co-Authored-By: Claude Opus 5.5 --- .../feature-flagging-api/README.md | 9 ++- .../trace/api/openfeature/Provider.java | 1 + .../featureflag/ExposureWriterImpl.java | 13 +++- .../featureflag/ExposureWriterTests.java | 63 +++++++++++-------- 4 files changed, 54 insertions(+), 32 deletions(-) diff --git a/products/feature-flagging/feature-flagging-api/README.md b/products/feature-flagging/feature-flagging-api/README.md index e49fe1244b2..f525ee9c159 100644 --- a/products/feature-flagging/feature-flagging-api/README.md +++ b/products/feature-flagging/feature-flagging-api/README.md @@ -343,9 +343,12 @@ Look for these diagnostic boundaries: - Exposures report suppression reasons, queueing, overflow, flush counts, delivery, and failed batches that are dropped. Dispatch to listeners and queueing do not confirm delivery. - Provider shutdown detaches its configuration listener; the Java agent owns the configuration - source and exposure writer. Exposure shutdown reports queued work. Pending exposures are - **not flushed**. The processor reports completion separately, - after any in-flight delivery outcome, with the counts left in its queue and buffer. + source and exposure writer. Exposure shutdown reports queued work, then the processor finishes + any in-flight delivery, drains the queue, and makes one final best-effort flush whose outcome is + logged like any other flush. Exposures dispatched after shutdown starts are dropped and logged. + If the final delivery outlives the shutdown wait, a message says it continues in the + background. The processor reports completion separately, with the counts left in its queue and + buffer. To disable these debug diagnostics, set `DD_TRACE_DEBUG=false` and restart the application (without a conflicting `-Ddd.trace.debug=true` override). Provider lifecycle, evaluation, and diff --git a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java index 39910f60975..1c2a1ad6d2a 100644 --- a/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java +++ b/products/feature-flagging/feature-flagging-api/src/main/java/datadog/trace/api/openfeature/Provider.java @@ -117,6 +117,7 @@ public Provider(final Options options) { } catch (LinkageError e) { log.warn("Feature flag exposure reporting is unavailable with the installed agent", e); } + // Local debug diagnostics are not telemetry, so evaluation telemetry opt-out does not apply. final DebugLoggingHook debugLoggingHook = DebugLoggingHook.createIfEnabled(); if (debugLoggingHook != null) { hooks.add(debugLoggingHook); diff --git a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java index 998e8306f09..35b5eabd203 100644 --- a/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java +++ b/products/feature-flagging/feature-flagging-lib/src/main/java/com/datadog/featureflag/ExposureWriterImpl.java @@ -147,7 +147,7 @@ public void requestShutdown() { FeatureFlaggingGateway.removeExposureListener(this); if (LOGGER.isDebugEnabled()) { LOGGER.debug( - "Feature Flagging exposure shutdown requested: queued={}; pending exposures will not be flushed; processor completion is reported separately", + "Feature Flagging exposure shutdown requested: queued={}; pending exposures get one final best-effort flush; processor completion is reported separately", queue.size()); } // Polling wakes within 100 ms. An interrupt can race with, or abort, the final POST. @@ -158,6 +158,13 @@ public void requestShutdown() { @Override public void awaitTermination(final long deadlineNanos) { FeatureFlagEventWriter.awaitThread(serializerThread, deadlineNanos); + // The final POST is not interrupted, so it can outlive the shutdown budget. + if (serializerThread.isAlive() + && serializerThread != Thread.currentThread() + && LOGGER.isDebugEnabled()) { + LOGGER.debug( + "Feature Flagging exposure shutdown wait expired; final delivery continues in the background"); + } } @Override @@ -170,6 +177,8 @@ public void accept(final ExposureEvent event) { if (LOGGER.isDebugEnabled()) { LOGGER.debug("Feature Flagging exposure {}", queued ? "queued" : "dropped: queue full"); } + } else if (LOGGER.isDebugEnabled()) { + LOGGER.debug("Feature Flagging exposure dropped: writer shutting down"); } } @@ -243,7 +252,7 @@ public void run() { } } LOGGER.debug( - "Feature Flagging exposure processor stopped; pending exposures are not flushed on shutdown; queued={}, buffered={}", + "Feature Flagging exposure processor stopped after final flush; queued={}, buffered={}", queue.size(), buffer.size()); } diff --git a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java index 6c21e51e08d..874e107c1c7 100644 --- a/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java +++ b/products/feature-flagging/feature-flagging-lib/src/test/java/com/datadog/featureflag/ExposureWriterTests.java @@ -201,12 +201,14 @@ void distinguishesQueuedFromDeliveredExposures(boolean fails, Integer status, St if (fails) { when(backend.post(any(), any(), any(), any(), eq(false))).thenThrow(failure); } - Config config = mockConfig("test-service"); - BackendApiFactory backendApiFactory = mock(BackendApiFactory.class); - when(backendApiFactory.createEvpProxyApi(Intake.EVENT_PLATFORM, true)).thenReturn(backend); - FeatureFlagBackendApiFactory factory = - new FeatureFlagBackendApiFactory(config, backendApiFactory, FeatureFlagEventType.EXPOSURE); - ExposureWriterImpl writer = new ExposureWriterImpl(16, 1, MILLISECONDS, factory, config); + ExposureWriterImpl writer = + new ExposureWriterImpl( + 16, + 1, + MILLISECONDS, + () -> backend, + mockConfig("test-service"), + ExposureWriterImpl.SHUTDOWN_TIMEOUT_MILLIS); try { writer.init(); writer.accept(buildExposures(1).get(0)); @@ -252,47 +254,54 @@ void reportsShutdownWithPendingAndInFlightExposures(boolean fails, String outcom logger.addAppender(appender); logger.setLevel(Level.DEBUG); CountDownLatch inFlight = new CountDownLatch(1); + CountDownLatch release = new CountDownLatch(1); + AtomicLong posts = new AtomicLong(); BackendApi backend = mock(BackendApi.class); when(backend.post(any(), any(), any(), any(), eq(false))) .thenAnswer( invocation -> { - inFlight.countDown(); - try { - new CountDownLatch(1).await(); - } catch (InterruptedException interrupted) { - Thread.currentThread().interrupt(); - } - if (fails) { - throw new SocketTimeoutException("destination timed out during shutdown"); + // Only the first delivery blocks; the final flush after it returns immediately. + if (posts.incrementAndGet() == 1) { + inFlight.countDown(); + release.await(); + if (fails) { + throw new SocketTimeoutException("destination timed out during shutdown"); + } } return null; }); - Config config = mockConfig("shutdown"); - BackendApiFactory backendFactory = mock(BackendApiFactory.class); - when(backendFactory.createEvpProxyApi(Intake.EVENT_PLATFORM, true)).thenReturn(backend); + List exposures = buildExposures(3); ExposureWriterImpl writer = - new ExposureWriterImpl( - 16, - 1, - MILLISECONDS, - new FeatureFlagBackendApiFactory(config, backendFactory, FeatureFlagEventType.EXPOSURE), - config); + new ExposureWriterImpl(16, 1, MILLISECONDS, () -> backend, mockConfig("shutdown"), 100); try { writer.init(); - writer.accept(buildExposure()); + writer.accept(exposures.get(0)); assertTrue(inFlight.await(5000, MILLISECONDS)); - writer.accept(buildExposure()); + writer.accept(exposures.get(1)); writer.close(); + writer.accept(exposures.get(2)); + assertTrue(writer.isSerializerThreadAlive()); + release.countDown(); poll.eventually(() -> assertFalse(writer.isSerializerThreadAlive())); assertTrue( appender.list.stream() .anyMatch(e -> e.getFormattedMessage().contains("shutdown requested: queued=1;"))); + assertTrue( + appender.list.stream() + .anyMatch(e -> e.getFormattedMessage().contains("shutdown wait expired"))); + assertTrue( + appender.list.stream() + .anyMatch(e -> e.getFormattedMessage().contains("dropped: writer shutting down"))); assertTrue(appender.list.stream().anyMatch(e -> e.getFormattedMessage().contains(outcome))); assertTrue( appender.list.stream() - .anyMatch(e -> e.getFormattedMessage().contains("queued=1, buffered=0"))); - verify(backend).post(any(), any(), any(), any(), eq(false)); + .anyMatch( + e -> + e.getFormattedMessage() + .contains("stopped after final flush; queued=0, buffered=0"))); + verify(backend, times(2)).post(any(), any(), any(), any(), eq(false)); } finally { + release.countDown(); writer.close(); logger.detachAppender(appender); logger.setLevel(previous);