Skip to content

Commit da378c3

Browse files
tanderson-ldtanderson-ld
authored
chore: improves FDv2 DataSource logging (#156)
**Requirements** - [x] I have added test coverage for new or changed functionality - [x] I have followed the repository's [pull request submission guidelines](../blob/main/CONTRIBUTING.md#submitting-pull-requests) - [ ] I have validated my changes against all supported platform versions Updates implementation to meet orchestration logging spec to be more consistent with other implementations. <!-- CURSOR_SUMMARY --> --- > [!NOTE] > **Low Risk** > Low risk: changes are primarily log-level/message adjustments plus optional `name()` methods with defaults; core data acquisition behavior is unchanged aside from additional status dedupe state. > > **Overview** > **Orchestration logging is standardized and made more actionable for FDv2 initializers/synchronizers.** `Initializer` and `Synchronizer` now expose a default `name()` for diagnostics, with key implementations (polling/streaming/file/testdata and the FDv1 adapter) overriding it for consistent labels. > > `FDv2DataSource` now logs initializer/synchronizer start, success, fallback/recovery transitions, permanent failures, and exhaustion of synchronizers with clearer severity and error detail (including root-cause summaries). It also deduplicates repeated synchronizer status logs until a data update occurs. > > Adds targeted tests validating the new orchestration log messages and introduces small test helpers/mocks to supply custom source names. > > <sup>Reviewed by [Cursor Bugbot](https://cursor.com/bugbot) for commit d5b5f04. Bugbot is set up for automated code reviews on this repo. Configure [here](https://www.cursor.com/dashboard/bugbot).</sup> <!-- /CURSOR_SUMMARY --> BEGIN_COMMIT_OVERRIDE chore: improves FDv2 DataSource logging END_COMMIT_OVERRIDE
1 parent f4719ec commit da378c3

11 files changed

Lines changed: 399 additions & 16 deletions

File tree

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/DataSourceSynchronizerAdapter.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,11 @@ public DataSourceSynchronizerAdapter(DataSourceFactory dataSourceFactory) {
6161
this.dataSource = dataSourceFactory.create(convertingSink);
6262
}
6363

64+
@Override
65+
public String name() {
66+
return "AdaptedSynchronizer(V1->V2)";
67+
}
68+
6469
@Override
6570
public CompletableFuture<FDv2SourceResult> next() {
6671
synchronized (startLock) {

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/FDv2DataSource.java‎

Lines changed: 93 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,8 @@
22

33
import com.google.common.collect.ImmutableList;
44
import com.launchdarkly.logging.LDLogger;
5+
import com.launchdarkly.logging.LogValues;
6+
import com.launchdarkly.sdk.fdv2.SourceSignal;
57
import com.launchdarkly.sdk.server.datasources.FDv2SourceResult;
68
import com.launchdarkly.sdk.server.datasources.Initializer;
79
import com.launchdarkly.sdk.server.datasources.Synchronizer;
@@ -48,6 +50,13 @@ class FDv2DataSource implements DataSource {
4850

4951
private volatile boolean closed = false;
5052

53+
/**
54+
* Avoid duplicate orchestration logs for the same synchronizer and {@link SourceSignal}.
55+
*/
56+
private String lastLoggedSynchronizerDedupeName;
57+
58+
private SourceSignal lastLoggedSynchronizerDedupeStatus;
59+
5160
public interface DataSourceFactory<T> {
5261
T build();
5362
}
@@ -73,7 +82,6 @@ public FDv2DataSource(
7382
);
7483
}
7584

76-
7785
public FDv2DataSource(
7886
ImmutableList<DataSourceFactory<Initializer>> initializers,
7987
ImmutableList<DataSourceFactory<Synchronizer>> synchronizers,
@@ -117,7 +125,9 @@ private void run() {
117125
if (!sourceManager.hasAvailableSources()) {
118126
// There are not any initializer or synchronizers, so we are at the best state that
119127
// can be achieved.
120-
logger.info("LaunchDarkly client will not connect to Launchdarkly for feature flag data due to no initializers or synchronizers");
128+
logger.warn(
129+
"LaunchDarkly client will not connect to LaunchDarkly for feature flag data due to no initializers or synchronizers configured."
130+
);
121131
dataSourceUpdates.updateStatus(DataSourceStatusProvider.State.VALID, null);
122132
startFuture.complete(true);
123133
return;
@@ -157,13 +167,16 @@ private void run() {
157167
private void runInitializers() {
158168
boolean anyDataReceived = false;
159169
Initializer initializer = sourceManager.getNextInitializerAndSetActive();
160-
while(initializer != null) {
170+
while (initializer != null) {
171+
String initializerName = initializer.name();
172+
logger.info("Initializer '{}' is starting.", initializerName);
161173
try {
162-
try(FDv2SourceResult result = initializer.run().get()) {
174+
try (FDv2SourceResult result = initializer.run().get()) {
163175
switch (result.getResultType()) {
164176
case CHANGE_SET:
165177
dataSourceUpdates.apply(result.getChangeSet());
166178
anyDataReceived = true;
179+
logger.info("Initialized via '{}'.", initializerName);
167180
if (!result.getChangeSet().getSelector().isEmpty()) {
168181
// We received data with a selector, so we end the initialization process.
169182
dataSourceUpdates.updateStatus(DataSourceStatusProvider.State.VALID, null);
@@ -176,6 +189,9 @@ private void runInitializers() {
176189
switch (status.getState()) {
177190
case INTERRUPTED:
178191
case TERMINAL_ERROR:
192+
logger.warn("Initializer '{}' failed: {}",
193+
initializerName,
194+
detailForError(status.getErrorInfo()));
179195
// The data source updates handler will filter the state during initializing, but this
180196
// will make the error information available.
181197
dataSourceUpdates.updateStatus(
@@ -194,8 +210,6 @@ private void runInitializers() {
194210
}
195211
}
196212
} catch (ExecutionException | InterruptedException | CancellationException e) {
197-
// We don't expect these conditions to happen in practice.
198-
199213
// The data source updates handler will filter the state during initializing, but this
200214
// will make the error information available.
201215
dataSourceUpdates.updateStatus(
@@ -204,9 +218,12 @@ private void runInitializers() {
204218
0,
205219
e.toString(),
206220
new Date().toInstant()));
207-
logger.warn("Error running initializer: {}", e.toString());
221+
Throwable root = e instanceof ExecutionException && e.getCause() != null ? e.getCause() : e;
222+
logger.error("Error running initializer '{}': {}",
223+
initializerName,
224+
root.getMessage() != null ? root.getMessage() : LogValues.exceptionSummary(root));
208225
}
209-
initializer = sourceManager.getNextInitializerAndSetActive();
226+
initializer = sourceManager.getNextInitializerAndSetActive();
210227
}
211228
// We received data without a selector, and we have exhausted initializers, so we are going to
212229
// consider ourselves initialized.
@@ -249,6 +266,9 @@ private void runSynchronizers() {
249266

250267
// We want to continue running synchronizers for as long as any are available.
251268
while (synchronizer != null) {
269+
String synchronizerName = synchronizer.name();
270+
logger.info("Synchronizer '{}' is starting.", synchronizerName);
271+
resetSynchronizerStatusDedupe();
252272
try {
253273
boolean running = true;
254274

@@ -264,16 +284,19 @@ private void runSynchronizers() {
264284
Condition c = (Condition) res;
265285
switch (c.getType()) {
266286
case FALLBACK:
267-
// For fallback, we will move to the next available synchronizer, which may loop.
268-
// This is the default behavior of exiting the run loop, so we don't need to take
269-
// any action.
270-
logger.debug("A synchronizer has experienced an interruption and we are falling back.");
287+
logger.info(
288+
"Fallback condition met, falling back from synchronizer '{}'.",
289+
synchronizer.name()
290+
);
271291
break;
272292
case RECOVERY:
273293
// For recovery, we will start at the first available synchronizer.
274294
// So we reset the source index, and finding the source will start at the beginning.
275295
sourceManager.resetSourceIndex();
276-
logger.debug("The data source is attempting to recover to a higher priority synchronizer.");
296+
logger.info(
297+
"Recovery condition met, moving from synchronizer '{}' to primary synchronizer.",
298+
synchronizer.name()
299+
);
277300
break;
278301
}
279302
// A running synchronizer will only have fallback and recovery conditions that it can act on.
@@ -292,6 +315,8 @@ private void runSynchronizers() {
292315

293316
switch (result.getResultType()) {
294317
case CHANGE_SET:
318+
// A data update breaks the "in a row" streak for status deduplication.
319+
resetSynchronizerStatusDedupe();
295320
dataSourceUpdates.apply(result.getChangeSet());
296321
dataSourceUpdates.updateStatus(DataSourceStatusProvider.State.VALID, null);
297322
// This could have been completed by any data source. But if it has not been completed before
@@ -302,17 +327,33 @@ private void runSynchronizers() {
302327
FDv2SourceResult.Status status = result.getStatus();
303328
switch (status.getState()) {
304329
case INTERRUPTED:
330+
maybeLogSynchronizerStatusChange(
331+
synchronizer.name(),
332+
status.getState()
333+
);
305334
// Handled by conditions.
306335
dataSourceUpdates.updateStatus(
307336
DataSourceStatusProvider.State.INTERRUPTED,
308337
status.getErrorInfo());
309338
break;
310339
case SHUTDOWN:
340+
maybeLogSynchronizerStatusChange(
341+
synchronizer.name(),
342+
status.getState()
343+
);
311344
// We should be overall shutting down.
312345
logger.debug("Synchronizer shutdown.");
313346
return;
314347
case TERMINAL_ERROR:
348+
maybeLogSynchronizerStatusChange(
349+
synchronizer.name(),
350+
status.getState()
351+
);
315352
sourceManager.blockCurrentSynchronizer();
353+
logger.warn(
354+
"Synchronizer '{}' permanently failed and will not be used again until application restart.",
355+
synchronizer.name()
356+
);
316357
running = false;
317358
dataSourceUpdates.updateStatus(
318359
DataSourceStatusProvider.State.INTERRUPTED,
@@ -335,6 +376,7 @@ private void runSynchronizers() {
335376
!sourceManager.isCurrentSynchronizerFDv1Fallback()
336377
) {
337378
sourceManager.fdv1Fallback();
379+
logger.info("Falling back to an FDv1 fallback synchronizer.");
338380
running = false;
339381
}
340382
}
@@ -348,20 +390,55 @@ private void runSynchronizers() {
348390
e.toString(),
349391
new Date().toInstant()
350392
));
351-
logger.warn("Error running synchronizer: {}, will try next synchronizer, or retry.", e.toString());
393+
Throwable root = e instanceof ExecutionException && e.getCause() != null ? e.getCause() : e;
394+
logger.error("Error running synchronizer '{}': {}",
395+
synchronizer.name(),
396+
root.getMessage() != null ? root.getMessage() : LogValues.exceptionSummary(root));
352397
// Move to the next synchronizer.
353398
}
354399
// Get the next available synchronizer and set it active
355400
synchronizer = sourceManager.getNextAvailableSynchronizerAndSetActive();
356401
}
357-
} catch(Exception e) {
402+
if (!closed) {
403+
logger.warn("No more synchronizers available.");
404+
}
405+
} catch (Exception e) {
358406
// We are not expecting to encounter this situation, but if we do, then we should log it.
359407
logger.error("Unexpected error in data source: {}", e.toString());
360-
}finally {
408+
} finally {
361409
sourceManager.close();
362410
}
363411
}
364412

413+
private static String detailForError(DataSourceStatusProvider.ErrorInfo errorInfo) {
414+
if (errorInfo == null) {
415+
return "unknown error";
416+
}
417+
if (errorInfo.getMessage() != null && !errorInfo.getMessage().isEmpty()) {
418+
return errorInfo.getMessage();
419+
}
420+
return errorInfo.toString();
421+
}
422+
423+
private void resetSynchronizerStatusDedupe() {
424+
lastLoggedSynchronizerDedupeName = null;
425+
lastLoggedSynchronizerDedupeStatus = null;
426+
}
427+
428+
private void maybeLogSynchronizerStatusChange(String sourceName, SourceSignal state) {
429+
if (state == SourceSignal.GOODBYE) {
430+
return;
431+
}
432+
if (sourceName != null
433+
&& sourceName.equals(lastLoggedSynchronizerDedupeName)
434+
&& state == lastLoggedSynchronizerDedupeStatus) {
435+
return;
436+
}
437+
lastLoggedSynchronizerDedupeName = sourceName;
438+
lastLoggedSynchronizerDedupeStatus = state;
439+
logger.info("Synchronizer '{}' reported status: {}.", sourceName, state.name());
440+
}
441+
365442
@Override
366443
public Future<Void> start() {
367444
if (!started.getAndSet(true)) {

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/PollingInitializerImpl.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,11 @@ public PollingInitializerImpl(FDv2Requestor requestor, LDLogger logger, Selector
1616
this.selectorSource = selectorSource;
1717
}
1818

19+
@Override
20+
public String name() {
21+
return "PollingInitializer(V2)";
22+
}
23+
1924
@Override
2025
public CompletableFuture<FDv2SourceResult> run() {
2126
CompletableFuture<FDv2SourceResult> pollResult = poll(selectorSource.getSelector(), true);

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/PollingSynchronizerImpl.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,11 @@ public PollingSynchronizerImpl(
3636
}
3737
}
3838

39+
@Override
40+
public String name() {
41+
return "PollingSynchronizer(V2)";
42+
}
43+
3944
private void doPoll() {
4045
try {
4146
FDv2SourceResult res = poll(selectorSource.getSelector(), false).get();

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/StreamingSynchronizerImpl.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,11 @@ public StreamingSynchronizerImpl(
9494
// The stream will lazily start when `next` is called.
9595
}
9696

97+
@Override
98+
public String name() {
99+
return "StreamingSynchronizer(V2)";
100+
}
101+
97102
private void startStream() {
98103
Headers headers = httpProperties.toHeadersBuilder()
99104
.add("Accept", "text/event-stream")

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/datasources/Initializer.java‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -51,4 +51,16 @@ public interface Initializer extends Closeable {
5151
* @return The result of the initializer.
5252
*/
5353
CompletableFuture<FDv2SourceResult> run();
54+
55+
/**
56+
* Human-readable name for logging and diagnostics. Do not use this for influencing code behavior.
57+
* <p>
58+
* Implementations may override; the default uses the runtime class simple name.
59+
*
60+
* @return the name
61+
*/
62+
default String name() {
63+
String simple = getClass().getSimpleName();
64+
return simple.isEmpty() ? getClass().getName() : simple;
65+
}
5466
}

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/datasources/Synchronizer.java‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -57,4 +57,16 @@ public interface Synchronizer extends Closeable {
5757
* @return a future that will complete when the next result is available
5858
*/
5959
CompletableFuture<FDv2SourceResult> next();
60+
61+
/**
62+
* Human-readable name for logging and diagnostics. Do not use this for influencing code behavior.
63+
* <p>
64+
* Implementations may override; the default uses the runtime class simple name.
65+
*
66+
* @return the name
67+
*/
68+
default String name() {
69+
String simple = getClass().getSimpleName();
70+
return simple.isEmpty() ? getClass().getName() : simple;
71+
}
6072
}

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/integrations/FileInitializer.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,11 @@ final class FileInitializer implements Initializer {
3333
this.synchronizer = new FileSynchronizer(sources, false, duplicateKeysHandling, logger, persist);
3434
}
3535

36+
@Override
37+
public String name() {
38+
return "FileInitializer(V2)";
39+
}
40+
3641
@Override
3742
public CompletableFuture<FDv2SourceResult> run() {
3843
return synchronizer.next().thenApply(result -> {

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/integrations/FileSynchronizer.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,11 @@ final class FileSynchronizer extends FileDataSourceBase implements Synchronizer
6161
this.fileWatcher = fw;
6262
}
6363

64+
@Override
65+
public String name() {
66+
return "FileSynchronizer(V2)";
67+
}
68+
6469
@Override
6570
public CompletableFuture<FDv2SourceResult> next() {
6671
if (!started.getAndSet(true)) {

‎lib/sdk/server/src/main/java/com/launchdarkly/sdk/server/integrations/TestDataV2.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -295,6 +295,11 @@ private final class TestDataV2SynchronizerImpl implements Synchronizer {
295295

296296
private final AtomicBoolean initialSent = new AtomicBoolean(false);
297297

298+
@Override
299+
public String name() {
300+
return "TestData(V2)";
301+
}
302+
298303
void put(FDv2SourceResult result, CompletableFuture<Void> completion) {
299304
resultQueue.put(result);
300305
try {

0 commit comments

Comments
 (0)