From 921c27f832b3a8269a2943a01e2d41992acdab1e Mon Sep 17 00:00:00 2001 From: jsonbailey Date: Fri, 16 Oct 2026 00:18:51 -0500 Subject: [PATCH] fix: Keep polling after an unexpected HTTP error response --- .../bin/contract_test_service.dart | 14 +- .../lib/src/config/data_source_config.dart | 26 +- .../lib/src/data_sources/data_source.dart | 7 +- .../src/data_sources/data_source_status.dart | 20 +- .../fdv2/fdv1_fallback_synchronizer.dart | 3 +- .../src/data_sources/polling_data_source.dart | 113 ++++--- .../lib/src/data_sources/requestor.dart | 15 +- .../test/config/data_source_config_test.dart | 41 +++ .../data_source_manager_test.dart | 11 + .../polling_data_source_manager_test.dart | 208 +++++++++++++ .../polling_data_source_retry_test.dart | 293 ++++++++++++++++++ .../polling_data_source_test.dart | 7 +- 12 files changed, 684 insertions(+), 74 deletions(-) create mode 100644 packages/common_client/test/data_sources/polling_data_source_manager_test.dart create mode 100644 packages/common_client/test/data_sources/polling_data_source_retry_test.dart diff --git a/apps/flutter_client_contract_test_service/bin/contract_test_service.dart b/apps/flutter_client_contract_test_service/bin/contract_test_service.dart index 474ca3d9..973fb0ab 100644 --- a/apps/flutter_client_contract_test_service/bin/contract_test_service.dart +++ b/apps/flutter_client_contract_test_service/bin/contract_test_service.dart @@ -6,6 +6,8 @@ import 'package:flutter/widgets.dart' as widgets; import 'package:connectivity_plus_platform_interface/connectivity_plus_platform_interface.dart'; import 'package:launchdarkly_dart_common/launchdarkly_dart_common.dart' as common; +import 'package:launchdarkly_common_client/src/config/data_source_config.dart' + show PollingDataSourceConfig; import 'package:launchdarkly_flutter_client_sdk/launchdarkly_flutter_client_sdk.dart'; import 'package:openapi_base/openapi_base.dart'; import 'package:shared_preferences/shared_preferences.dart'; @@ -32,6 +34,7 @@ class TestApiImpl extends SdkTestApi { 'client-event-source-http-errors', 'fdv1-fallback', 'client-use-post', + 'retry-conformance-fdv1-polling', ]; static const clientUrlPrefix = '/client/'; @@ -57,6 +60,7 @@ class TestApiImpl extends SdkTestApi { final mappedDataSystem = _mapDataSystem( body.configuration?.dataSystem?.toJson(), usePost: body.configuration?.clientSide?.usePost ?? false); + final pollIntervalMs = body.configuration?.polling?.pollIntervalMs; final config = LDConfig( body.configuration?.credential ?? '', AutoEnvAttributes.disabled, @@ -76,7 +80,12 @@ class TestApiImpl extends SdkTestApi { ? ConnectionMode.streaming : ConnectionMode.polling), evaluationReasons: body.configuration?.clientSide?.evaluationReasons, - useReport: body.configuration?.clientSide?.useReport), + useReport: body.configuration?.clientSide?.useReport, + polling: pollIntervalMs != null + ? PollingConfig( + pollingInterval: + Duration(milliseconds: pollIntervalMs.toInt())) + : null), events: EventsConfig( eventCapacity: body.configuration?.events?.capacity?.toInt(), disabled: body.configuration?.events == null, @@ -616,6 +625,9 @@ final class _WifiConnected extends ConnectivityPlatform { void main() async { test(timeout: Timeout.none, 'Run contract tests', () async { ConnectivityPlatform.instance = _WifiConnected(); + // Tests set short polling intervals and expect the SDK to use them. + // ignore: invalid_use_of_visible_for_testing_member + PollingDataSourceConfig.ignorePollingMinimum = true; widgets.WidgetsFlutterBinding.ensureInitialized(); // needed before mocking // ignore: invalid_use_of_visible_for_testing_member SharedPreferences.setMockInitialValues({}); // required to mock persistence diff --git a/packages/common_client/lib/src/config/data_source_config.dart b/packages/common_client/lib/src/config/data_source_config.dart index 9a85af32..9e7ed883 100644 --- a/packages/common_client/lib/src/config/data_source_config.dart +++ b/packages/common_client/lib/src/config/data_source_config.dart @@ -1,4 +1,5 @@ import 'package:launchdarkly_dart_common/launchdarkly_dart_common.dart'; +import 'package:meta/meta.dart'; import 'defaults/default_config.dart'; @@ -28,17 +29,34 @@ final class PollingDataSourceConfig extends DataSourceConfigBase { /// The current polling interval, if less than min, then the min will be used. final Duration pollingInterval; + /// When true, the polling interval has no minimum. Only the contract test + /// service sets this, so that tests can poll every few seconds. It has an + /// effect only when asserts are enabled, as in debug builds and tests. A + /// release build always applies the minimum. + @visibleForTesting + static bool ignorePollingMinimum = false; + PollingDataSourceConfig( {Duration? pollingInterval, bool? withReasons, bool? useReport}) - : pollingInterval = durationWithMin( - DefaultConfig.pollingConfig.defaultPollingInterval, - pollingInterval, - DefaultConfig.pollingConfig.minPollingInterval), + : pollingInterval = _resolvePollingInterval(pollingInterval), super( withReasons: withReasons ?? DefaultConfig.dataSourceConfig.defaultWithReasons, useReport: useReport ?? DefaultConfig.dataSourceConfig.defaultUseReport); + + static Duration _resolvePollingInterval(Duration? requested) { + var ignoreMinimum = false; + assert(() { + ignoreMinimum = ignorePollingMinimum; + return true; + }()); + return ignoreMinimum + ? durationGreaterThanZeroWithDefault( + requested, DefaultConfig.pollingConfig.defaultPollingInterval) + : durationWithMin(DefaultConfig.pollingConfig.defaultPollingInterval, + requested, DefaultConfig.pollingConfig.minPollingInterval); + } } final class StreamingDataSourceConfig extends DataSourceConfigBase { diff --git a/packages/common_client/lib/src/data_sources/data_source.dart b/packages/common_client/lib/src/data_sources/data_source.dart index 6d9e8d0c..39b690b2 100644 --- a/packages/common_client/lib/src/data_sources/data_source.dart +++ b/packages/common_client/lib/src/data_sources/data_source.dart @@ -11,9 +11,10 @@ final class DataEvent implements DataSourceEvent { DataEvent(this.type, this.data, {this.environmentId}); } -/// An FDv2 change set produced by the data source orchestrator. Carries -/// typed flag descriptors translated at acquisition time, not the FDv1 -/// JSON string forms. +/// A change set with typed flag descriptors, not the FDv1 JSON string forms. +/// The FDv2 orchestrator produces these for its payloads. The FDv1 data +/// sources produce one of type none when a poll confirms that the data is +/// current. final class PayloadEvent implements DataSourceEvent { final ChangeSet changeSet; final String? environmentId; diff --git a/packages/common_client/lib/src/data_sources/data_source_status.dart b/packages/common_client/lib/src/data_sources/data_source_status.dart index f14ec32b..a021e4e8 100644 --- a/packages/common_client/lib/src/data_sources/data_source_status.dart +++ b/packages/common_client/lib/src/data_sources/data_source_status.dart @@ -3,8 +3,8 @@ enum DataSourceState { /// initialized. /// /// If it encounters an error that requires it to retry initialization, - /// the state will remain at kInitializing until it either succeeds and - /// becomes [valid], or permanently fails and becomes [shutdown]. + /// the state will remain at [initializing] until it succeeds and becomes + /// [valid]. initializing, /// Indicates that the data source is currently operational and has not @@ -22,19 +22,19 @@ enum DataSourceState { /// In streaming mode, this means that the stream connection failed, or /// had to be dropped due to some other error, and will be retried after /// a backoff delay. In polling mode, it means that the last poll request - /// failed, and a new poll request will be made after the configured - /// polling interval. + /// failed, and a new poll request will be made after a backoff delay that + /// is never shorter than the configured polling interval. interrupted, /// Indicates that the application has told the SDK to stay offline. setOffline, - /// Indicates that the data source has been permanently shut down. + /// Indicates that the data source has been shut down. /// - /// This could be because it encountered an unrecoverable error (for - /// instance, the LaunchDarkly service rejected the SDK key; an invalid - /// SDK key will never become valid), or because the SDK client was - /// explicitly shut down. + /// This could be because the SDK client was explicitly shut down, or + /// because the data source configuration cannot work. An HTTP error or a + /// network error does not cause this state, because the data source keeps + /// retrying after those errors. shutdown, /// Indicates that the SDK is aware of a lack of network connectivity. @@ -148,7 +148,7 @@ final class DataSourceStatus { /// [DataSourceState.valid]. /// /// - For [DataSourceState.shutdown], it is the time that the data source - /// encountered an unrecoverable error or that the SDK was explicitly shut down. + /// was shut down. /// /// - For [DataSourceState.networkUnavailable] or /// [DataSourceState.backgroundDisabled], it is the time that the SDK switched diff --git a/packages/common_client/lib/src/data_sources/fdv2/fdv1_fallback_synchronizer.dart b/packages/common_client/lib/src/data_sources/fdv2/fdv1_fallback_synchronizer.dart index 904164bf..e78b9c2b 100644 --- a/packages/common_client/lib/src/data_sources/fdv2/fdv1_fallback_synchronizer.dart +++ b/packages/common_client/lib/src/data_sources/fdv2/fdv1_fallback_synchronizer.dart @@ -109,8 +109,9 @@ FDv2SourceResult _translate(DataSourceEvent? event) { ); } case StatusEvent(): + final statusCode = event.statusCode; return StatusResult( - state: event.shutdown + state: statusCode != null && !isHttpGloballyRecoverable(statusCode) ? SourceState.terminalError : SourceState.interrupted, message: event.message, diff --git a/packages/common_client/lib/src/data_sources/polling_data_source.dart b/packages/common_client/lib/src/data_sources/polling_data_source.dart index f900a325..11b1b57e 100644 --- a/packages/common_client/lib/src/data_sources/polling_data_source.dart +++ b/packages/common_client/lib/src/data_sources/polling_data_source.dart @@ -1,11 +1,10 @@ import 'dart:async'; import 'dart:convert'; import 'package:launchdarkly_dart_common/launchdarkly_dart_common.dart'; -import 'dart:math'; import '../config/data_source_config.dart'; import 'data_source.dart'; -import 'data_source_status.dart'; +import 'fdv2/payload.dart'; import 'requestor.dart'; HttpClient _defaultHttpClientFactory(HttpProperties httpProperties) { @@ -16,13 +15,17 @@ HttpClient _defaultHttpClientFactory(HttpProperties httpProperties) { // because the etag may not correspond to the current payload the SDK has, // because streaming could have been used in the interim. +/// A data source that polls for flag updates. +/// +/// Each poll is scheduled when the previous poll completes. After a +/// successful poll, the next poll comes one polling interval later. After a +/// failed poll, the wait comes from the [RetryState]. A payload that the SDK +/// cannot apply is a failed poll. No failure stops the data source. final class PollingDataSource implements DataSource { final LDLogger _logger; Timer? _pollTimer; - final Stopwatch _pollStopwatch = Stopwatch(); - late final Duration _pollingInterval; late final String _contextString; @@ -35,12 +38,15 @@ final class PollingDataSource implements DataSource { late final Requestor _requestor; + late final RetryState _retryState; + + /// Set when the last poll returned a payload that the SDK has not yet + /// rejected. The SDK rejects a payload through [restart]. + bool _payloadPending = false; + @override Stream get events => _eventController.stream; - /// Used to track if there has been an unrecoverable error. - bool _permanentShutdown = false; - /// The [httpClientFactory] parameter is primarily intended for testing, but it also /// could be used for customized clients which support functionality /// our default client support does not. For instance domain sockets or @@ -60,6 +66,7 @@ final class PollingDataSource implements DataSource { : _logger = logger.subLogger('PollingDataSource'), _credential = credential { _pollingInterval = testingInterval ?? dataSourceConfig.pollingInterval; + _retryState = RetryState.polling(_pollingInterval); final method = dataSourceConfig.useReport ? RequestMethod.report : RequestMethod.get; @@ -84,9 +91,12 @@ final class PollingDataSource implements DataSource { } Future _doPoll() async { - _pollStopwatch.reset(); - _pollStopwatch.start(); - + if (_payloadPending) { + // The previous payload was applied, because it was not rejected + // before this poll. + _payloadPending = false; + _retryState.recordSuccess(); + } final event = await _requestor.requestAllFlags(); if (_stopped) { @@ -95,69 +105,76 @@ final class PollingDataSource implements DataSource { switch (event) { case null: - // No change (e.g. 304 Not Modified). Fall through to schedule - // the next poll -- returning here would leave the timer - // unset and silently stop polling after the first unchanged - // response. - break; + // No change (e.g. 304 Not Modified). This is a successful poll, and + // a change set of type none restores the valid status. + _retryState.recordSuccess(); + _eventController.sink.add(_unchanged()); + _schedulePoll(_pollingInterval); case DataEvent(): + _payloadPending = true; _eventController.sink.add(event); + _schedulePoll(_pollingInterval); case StatusEvent(): _eventController.sink.add(event); - final suffix = event.shutdown ? 'stopping polling' : 'will retry'; - final message = event.kind == ErrorKind.errorResponse - ? 'received unexpected status code when polling' - : 'encountered error with polling request'; - final argument = event.kind == ErrorKind.errorResponse - ? event.statusCode - : event.message; - _logger.error('$message: $argument, $suffix'); - if (event.shutdown) { - _permanentShutdown = true; - stop(); - } + _handleFailure(event); case PayloadEvent(): case InitializedEvent(): // The FDv1 requestor never produces FDv2 payload or lifecycle events. break; } + } - _schedulePoll(); + void _handleFailure(StatusEvent event) { + if (event.statusCode case final statusCode?) { + final kind = classifyHttpStatus(statusCode); + final delay = _retryState.recordFailure(kind); + switch (kind) { + case FailureKind.unexpected: + _logger.error('Received unexpected status code $statusCode when ' + 'polling.${credentialHint(statusCode)} Will retry in ' + '${delay.inMilliseconds} ms.'); + case FailureKind.normal: + _logger.warn('Received status code $statusCode when polling. Will ' + 'retry in ${delay.inMilliseconds} ms.'); + } + _schedulePoll(delay); + return; + } + final delay = _retryState.recordFailure(FailureKind.normal); + _logger.warn('Encountered error with polling request: ${event.message}. ' + 'Will retry in ${delay.inMilliseconds} ms.'); + _schedulePoll(delay); } - void _schedulePoll() { + void _schedulePoll(Duration delay) { if (_stopped) { return; } - _pollStopwatch.stop(); - final timeSincePoll = _pollStopwatch.elapsed; - // Calculate a delay based on the polling interval and the duration elapsed - // since the last poll. - - // Example: If the poll took 5 seconds, and the interval is 30 seconds, then - // we want to poll after 25 seconds. - final delay = Duration( - milliseconds: min( - _pollingInterval.inMilliseconds - timeSincePoll.inMilliseconds, - _pollingInterval.inMilliseconds)); - _pollTimer = Timer(delay, _doPoll); } @override void start() { - if (_permanentShutdown || _stopped) { + if (_stopped) { return; } - - _stopped = false; _doPoll(); } + /// Records that the SDK could not apply the last payload. The data source + /// fetches a full payload again after the retry delay. @override void restart() { - // For polling there is no persistent connection, so this function - // has no effect. + if (_stopped || !_payloadPending) { + return; + } + _payloadPending = false; + _requestor.clearEtag(); + _pollTimer?.cancel(); + final delay = _retryState.recordFailure(FailureKind.normal); + _logger.warn('Polling response contained invalid data. Will retry in ' + '${delay.inMilliseconds} ms.'); + _schedulePoll(delay); } @override @@ -168,3 +185,7 @@ final class PollingDataSource implements DataSource { _eventController.close(); } } + +/// A change set that confirms that the SDK data is current. +PayloadEvent _unchanged() => + PayloadEvent(const ChangeSet(type: PayloadType.none, updates: {})); diff --git a/packages/common_client/lib/src/data_sources/requestor.dart b/packages/common_client/lib/src/data_sources/requestor.dart index c893e912..9a14369d 100644 --- a/packages/common_client/lib/src/data_sources/requestor.dart +++ b/packages/common_client/lib/src/data_sources/requestor.dart @@ -55,6 +55,12 @@ final class Requestor { _uri = Uri.parse(completeUrl); } + /// Forgets the stored ETag, so that the next request fetches a full + /// payload. Call this when the last payload could not be used. + void clearEtag() { + _lastEtag = null; + } + Future requestAllFlags() async { try { _logger.debug( @@ -73,7 +79,7 @@ final class Requestor { // and the URL embeds the base64url-encoded context in GET mode. // Categorize into a fixed message and use that everywhere. final sanitized = _describeError(err); - _logger.warn('Polling request failed: $sanitized'); + _logger.debug('Polling request failed: $sanitized'); return StatusEvent(ErrorKind.networkError, null, sanitized); } } @@ -100,13 +106,8 @@ final class Requestor { return DataEvent('put', res.body, environmentId: environmentId); } - if (isHttpGloballyRecoverable(res.statusCode)) { - return StatusEvent(ErrorKind.errorResponse, res.statusCode, - 'Received unexpected status code: ${res.statusCode}'); - } return StatusEvent(ErrorKind.errorResponse, res.statusCode, - 'Received unexpected status code: ${res.statusCode}', - shutdown: true); + 'Received unexpected status code: ${res.statusCode}'); } String _describeError(Object err) { diff --git a/packages/common_client/test/config/data_source_config_test.dart b/packages/common_client/test/config/data_source_config_test.dart index f835ccd6..a4ff3ab5 100644 --- a/packages/common_client/test/config/data_source_config_test.dart +++ b/packages/common_client/test/config/data_source_config_test.dart @@ -29,4 +29,45 @@ void main() { }); } }); + + group('the polling interval minimum', () { + test('a public config uses the minimum for a shorter interval', () { + final config = + PollingDataSourceConfig(pollingInterval: const Duration(seconds: 1)); + expect(config.pollingInterval, const Duration(minutes: 5)); + }); + + test('the test hook removes the minimum when asserts are enabled', () { + var assertsEnabled = false; + assert(assertsEnabled = true); + expect(assertsEnabled, isTrue, + reason: 'the hook has an effect only when asserts are enabled'); + + PollingDataSourceConfig.ignorePollingMinimum = true; + addTearDown(() => PollingDataSourceConfig.ignorePollingMinimum = false); + + final config = + PollingDataSourceConfig(pollingInterval: const Duration(seconds: 1)); + expect(config.pollingInterval, const Duration(seconds: 1)); + }); + + for (final interval in [Duration.zero, const Duration(seconds: -1)]) { + test('the test hook uses the default for an interval of $interval', () { + PollingDataSourceConfig.ignorePollingMinimum = true; + addTearDown(() => PollingDataSourceConfig.ignorePollingMinimum = false); + + expect( + PollingDataSourceConfig(pollingInterval: interval).pollingInterval, + const Duration(minutes: 5)); + }); + } + + test('the test hook keeps the default when no interval is given', () { + PollingDataSourceConfig.ignorePollingMinimum = true; + addTearDown(() => PollingDataSourceConfig.ignorePollingMinimum = false); + + expect(PollingDataSourceConfig().pollingInterval, + const Duration(minutes: 5)); + }); + }); } diff --git a/packages/common_client/test/data_sources/data_source_manager_test.dart b/packages/common_client/test/data_sources/data_source_manager_test.dart index ac17f44c..35aa0eee 100644 --- a/packages/common_client/test/data_sources/data_source_manager_test.dart +++ b/packages/common_client/test/data_sources/data_source_manager_test.dart @@ -536,6 +536,17 @@ void main() { expect(identifyCompleter.isCompleted, isFalse); }); + test('an unchanged poll that arrives after stop does not set valid', + () async { + dataSource.controller.add( + PayloadEvent(const ChangeSet(type: PayloadType.none, updates: {}))); + manager.stop(); + await pumpEventQueue(); + + expect(statusManager.status.state, DataSourceState.initializing); + expect(identifyCompleter.isCompleted, isFalse); + }); + test('a failed FDv2 payload does not set an error', () async { await sendAndStop([ PayloadEvent(const ChangeSet( diff --git a/packages/common_client/test/data_sources/polling_data_source_manager_test.dart b/packages/common_client/test/data_sources/polling_data_source_manager_test.dart new file mode 100644 index 00000000..9bf7d6e9 --- /dev/null +++ b/packages/common_client/test/data_sources/polling_data_source_manager_test.dart @@ -0,0 +1,208 @@ +import 'dart:async'; + +import 'package:fake_async/fake_async.dart'; +import 'package:http/http.dart' as http; +import 'package:http/testing.dart'; +import 'package:launchdarkly_common_client/launchdarkly_common_client.dart'; +import 'package:launchdarkly_common_client/src/config/data_source_config.dart'; +import 'package:launchdarkly_common_client/src/data_sources/data_source_event_handler.dart'; +import 'package:launchdarkly_common_client/src/data_sources/data_source_manager.dart'; +import 'package:launchdarkly_common_client/src/data_sources/data_source_status_manager.dart'; +import 'package:launchdarkly_common_client/src/data_sources/polling_data_source.dart'; +import 'package:launchdarkly_common_client/src/flag_manager/flag_manager.dart'; +import 'package:launchdarkly_dart_common/launchdarkly_dart_common.dart' + as ld_common; +import 'package:test/test.dart'; + +const _interval = Duration(seconds: 30); + +const _flagPayload = + '{"flag":{"version":2,"value":true,"variation":0,"trackEvents":false}}'; + +/// A persistence whose writes always fail. +final class _FailingPersistence implements Persistence { + @override + Future read(String namespace, String key) async => null; + + @override + Future remove(String namespace, String key) async {} + + @override + Future set(String namespace, String key, String data) async => + throw StateError('write failed'); +} + +/// Runs a data source behind a real [DataSourceManager], so that payloads go +/// through the event handler and invalid payloads cause a restart. +final class _Harness { + final DataSourceStatusManager statusManager = + DataSourceStatusManager(stamper: () => DateTime(1)); + final List requests = []; + final List requestTimes = []; + late final FlagManager flagManager; + late final DataSourceManager manager; + final LDContext context = LDContextBuilder().kind('user', 'test').build(); + + _Harness(FakeAsync async, + FutureOr Function(int index, http.Request request) respond, + {required ConnectionMode mode, Persistence? persistence}) { + final logger = LDLogger(level: LDLogLevel.none); + flagManager = FlagManager( + sdkKey: 'dummy-key', + maxCachedContexts: 5, + logger: logger, + persistence: persistence); + manager = DataSourceManager( + startingMode: mode, + statusManager: statusManager, + dataSourceEventHandler: DataSourceEventHandler( + flagManager: flagManager, + statusManager: statusManager, + logger: logger), + logger: logger); + final client = MockClient((request) async { + final index = requests.length; + requests.add(request); + requestTimes.add(async.elapsed); + return await respond(index, request); + }); + ld_common.HttpClient httpClientFactory(HttpProperties properties) => + ld_common.HttpClient(client: client, httpProperties: properties); + manager.setFactories({ + const FDv2Polling(): (context) => PollingDataSource( + credential: 'dummy-key', + context: context, + endpoints: ServiceEndpoints(), + logger: logger, + dataSourceConfig: PollingDataSourceConfig(), + httpProperties: HttpProperties(), + testingInterval: _interval, + httpClientFactory: httpClientFactory), + }); + manager.identify(context, Completer()..future.ignore()); + } + + bool get flagValue => + flagManager.get('flag')?.flag?.detail.value.booleanValue() ?? false; + + /// The wait between request [index] and the request before it. + Duration waitBefore(int index) => + requestTimes[index] - requestTimes[index - 1]; +} + +http.Response _ok(String body, String etag) => + http.Response(body, 200, headers: {'etag': etag}); + +bool _hasEtag(http.BaseRequest request) => + request.headers.containsKey('if-none-match'); + +void main() { + group('polling', () { + test('a retry after an unusable payload fetches fresh data', () { + fakeAsync((async) { + final harness = + _Harness(async, mode: ConnectionMode.polling, (index, request) { + if (index == 0) { + return _ok('not a payload', '"e1"'); + } + return _hasEtag(request) + ? http.Response('', 304) + : _ok(_flagPayload, '"e2"'); + }); + async.elapse(const Duration(minutes: 2)); + + expect(harness.requests.length, greaterThanOrEqualTo(2)); + expect(_hasEtag(harness.requests[1]), isFalse); + expect(harness.flagValue, isTrue); + expect(harness.statusManager.status.state, DataSourceState.valid); + harness.manager.stop(); + }); + }); + + /// Responds to request `i` with `statuses[i]`. A status of 0 is a 200 + /// with a body that is not a flag payload. + http.Response Function(int, http.Request) bySequence(List statuses) => + (index, request) => switch (statuses[ + index < statuses.length ? index : statuses.length - 1]) { + 0 => _ok('not a payload', '"e$index"'), + 200 => _ok(_flagPayload, '"e$index"'), + final status => http.Response('', status), + }; + + test('an unusable payload counts as a failure', () { + fakeAsync((async) { + final harness = _Harness( + async, mode: ConnectionMode.polling, bySequence([401, 0, 200])); + async.elapse(const Duration(minutes: 30)); + + // The second extended attempt has a base delay of 10 minutes. + expect( + harness.waitBefore(2), + allOf(greaterThanOrEqualTo(const Duration(minutes: 5)), + lessThanOrEqualTo(const Duration(minutes: 10)))); + harness.manager.stop(); + }); + }); + + test('an unusable payload does not count toward the reset', () { + fakeAsync((async) { + final harness = _Harness( + async, + mode: ConnectionMode.polling, + bySequence([401, 200, 0, 200, 503, 200])); + async.elapse(const Duration(hours: 2)); + + // The third extended attempt has a base delay of 20 minutes. + expect( + harness.waitBefore(5), + allOf(greaterThanOrEqualTo(const Duration(minutes: 10)), + lessThanOrEqualTo(const Duration(minutes: 20)))); + harness.manager.stop(); + }); + }); + + test('a payload that cannot be stored counts as a failure', () { + fakeAsync((async) { + final harness = _Harness( + async, + mode: ConnectionMode.polling, + persistence: _FailingPersistence(), + (index, request) => index == 0 + ? http.Response('', 401) + : _ok(_flagPayload, '"e$index"')); + async.elapse(const Duration(minutes: 30)); + + // The second extended attempt has a base delay of 10 minutes. + expect( + harness.waitBefore(2), + allOf(greaterThanOrEqualTo(const Duration(minutes: 5)), + lessThanOrEqualTo(const Duration(minutes: 10)))); + harness.manager.stop(); + }); + }); + + test('a 304 after a failure restores the valid status', () { + fakeAsync((async) { + final harness = + _Harness(async, mode: ConnectionMode.polling, (index, request) { + return switch (index) { + 0 => _ok(_flagPayload, '"e1"'), + 1 => http.Response('', 503), + _ => http.Response('', 304), + }; + }); + async.flushMicrotasks(); + expect(harness.statusManager.status.state, DataSourceState.valid); + + async.elapse(_interval); + expect(harness.statusManager.status.state, DataSourceState.interrupted); + + async.elapse(_interval); + expect(harness.requests, hasLength(3)); + expect(harness.statusManager.status.state, DataSourceState.valid); + expect(harness.flagValue, isTrue); + harness.manager.stop(); + }); + }); + }); +} diff --git a/packages/common_client/test/data_sources/polling_data_source_retry_test.dart b/packages/common_client/test/data_sources/polling_data_source_retry_test.dart new file mode 100644 index 00000000..5e64cb6b --- /dev/null +++ b/packages/common_client/test/data_sources/polling_data_source_retry_test.dart @@ -0,0 +1,293 @@ +import 'dart:async'; + +import 'package:fake_async/fake_async.dart'; +import 'package:http/http.dart' as http; +import 'package:http/testing.dart'; +import 'package:launchdarkly_common_client/launchdarkly_common_client.dart'; +import 'package:launchdarkly_common_client/src/config/data_source_config.dart'; +import 'package:launchdarkly_common_client/src/data_sources/data_source.dart'; +import 'package:launchdarkly_common_client/src/data_sources/polling_data_source.dart'; +import 'package:launchdarkly_dart_common/launchdarkly_dart_common.dart' + as ld_common; +import 'package:mocktail/mocktail.dart'; +import 'package:test/test.dart'; + +class _MockLogAdapter extends Mock implements LDLogAdapter {} + +const _credentialHint = + 'Check that the SDK credential (mobile key or client-side ID) is correct.'; + +const _interval = Duration(seconds: 30); + +/// Holds a polling data source whose responses come from [statuses], in +/// order. The last status repeats. +final class _Harness { + final PollingDataSource dataSource; + final List events = []; + + /// The fake time of each request. + final List requestTimes = []; + + _Harness._(this.dataSource); + + factory _Harness(FakeAsync async, List statuses) { + late final _Harness harness; + final client = MockClient((request) async { + final index = harness.requestTimes.length; + harness.requestTimes.add(async.elapsed); + final status = + statuses[index < statuses.length ? index : -1 + statuses.length]; + return switch (status) { + 200 => http.Response('{}', 200), + _ => http.Response('', status), + }; + }); + harness = _Harness._(PollingDataSource( + credential: 'dummy-key', + context: LDContextBuilder().kind('user', 'test').build(), + endpoints: ServiceEndpoints(), + logger: LDLogger(level: LDLogLevel.none), + dataSourceConfig: PollingDataSourceConfig(), + httpProperties: HttpProperties(), + testingInterval: _interval, + httpClientFactory: (properties) => + ld_common.HttpClient(client: client, httpProperties: properties))); + harness.dataSource.events.listen(harness.events.add); + return harness; + } + + List get statuses => events.whereType().toList(); + + /// The wait between request [index] and the request before it. + Duration waitBefore(int index) => + requestTimes[index] - requestTimes[index - 1]; +} + +/// Matches a wait of one poll interval. +final _oneInterval = allOf(greaterThan(_interval - const Duration(seconds: 1)), + lessThanOrEqualTo(_interval)); + +void main() { + setUpAll(() { + registerFallbackValue(LDLogRecord( + level: LDLogLevel.debug, + message: '', + time: DateTime.now(), + logTag: '')); + }); + + test('a network error logs one warning', () { + final adapter = _MockLogAdapter(); + fakeAsync((async) { + final dataSource = PollingDataSource( + credential: 'dummy-key', + context: LDContextBuilder().kind('user', 'test').build(), + endpoints: ServiceEndpoints(), + logger: LDLogger(adapter: adapter, level: LDLogLevel.debug), + dataSourceConfig: PollingDataSourceConfig(), + httpProperties: HttpProperties(), + testingInterval: _interval, + httpClientFactory: (properties) => ld_common.HttpClient( + client: MockClient( + (request) async => throw http.ClientException('reset')), + httpProperties: properties)); + dataSource.events.listen((_) {}); + dataSource.start(); + async.flushMicrotasks(); + dataSource.stop(); + }); + + final warnings = verify(() => adapter.log(captureAny())) + .captured + .cast() + .where((record) => record.level == LDLogLevel.warn); + expect(warnings, hasLength(1)); + expect(warnings.single.message, contains('Will retry in')); + }); + + /// Polls once with a response of [status], and returns the error records. + List pollFailureErrors(int status) { + final adapter = _MockLogAdapter(); + fakeAsync((async) { + final dataSource = PollingDataSource( + credential: 'dummy-key', + context: LDContextBuilder().kind('user', 'test').build(), + endpoints: ServiceEndpoints(), + logger: LDLogger(adapter: adapter, level: LDLogLevel.debug), + dataSourceConfig: PollingDataSourceConfig(), + httpProperties: HttpProperties(), + testingInterval: _interval, + httpClientFactory: (properties) => ld_common.HttpClient( + client: MockClient((request) async => http.Response('', status)), + httpProperties: properties)); + dataSource.events.listen((_) {}); + dataSource.start(); + async.flushMicrotasks(); + dataSource.stop(); + }); + return verify(() => adapter.log(captureAny())) + .captured + .cast() + .where((record) => record.level == LDLogLevel.error) + .toList(); + } + + for (final status in [401, 403]) { + test('a $status logs an error with the hint', () { + final errors = pollFailureErrors(status); + expect(errors.single.message, contains(_credentialHint)); + expect(errors.single.message, contains('Will retry in')); + }); + } + + test('a 404 logs an error without the hint', () { + final errors = pollFailureErrors(404); + expect(errors.single.message, isNot(contains('Check that'))); + expect(errors.single.message, contains('Will retry in')); + }); + + test('a 401 keeps polling after the extended initial delay', () { + fakeAsync((async) { + final harness = _Harness(async, [401, 200]); + harness.dataSource.start(); + async.flushMicrotasks(); + + expect(harness.requestTimes, hasLength(1)); + expect(harness.statuses.single.statusCode, 401); + expect(harness.statuses.single.shutdown, isFalse); + + async.elapse(const Duration(minutes: 10)); + // The extended initial delay is 5 minutes, less up to half as jitter. + expect( + harness.waitBefore(1), + allOf(greaterThanOrEqualTo(const Duration(seconds: 150)), + lessThanOrEqualTo(const Duration(minutes: 5)))); + }); + }); + + test('a success after a 401 restores the poll interval', () { + fakeAsync((async) { + final harness = _Harness(async, [401, 200, 200]); + harness.dataSource.start(); + async.elapse(const Duration(minutes: 10)); + + expect(harness.waitBefore(2), _oneInterval); + }); + }); + + test('a normal failure waits the poll interval', () { + fakeAsync((async) { + final harness = _Harness(async, [503]); + harness.dataSource.start(); + async.flushMicrotasks(); + expect(harness.statuses.single.statusCode, 503); + + async.elapse(const Duration(minutes: 3)); + for (var i = 1; i < 5; i++) { + expect(harness.waitBefore(i), _oneInterval); + } + }); + }); + + test('one success after a 401 keeps the extended state', () { + fakeAsync((async) { + final harness = _Harness(async, [401, 200, 503, 200]); + harness.dataSource.start(); + async.elapse(const Duration(minutes: 30)); + + // The second extended attempt has a base delay of 10 minutes. + expect( + harness.waitBefore(3), + allOf(greaterThanOrEqualTo(const Duration(minutes: 5)), + lessThanOrEqualTo(const Duration(minutes: 10)))); + }); + }); + + test('two successes in a row reset the state', () { + fakeAsync((async) { + final harness = _Harness(async, [401, 200, 200, 503, 200]); + harness.dataSource.start(); + async.elapse(const Duration(minutes: 10)); + + expect(harness.waitBefore(4), _oneInterval); + }); + }); + + test('the next poll waits one interval from when the previous poll ends', + () async { + const interval = Duration(milliseconds: 300); + const responseTime = Duration(milliseconds: 200); + final clock = Stopwatch()..start(); + final requestTimes = []; + final completionTimes = []; + final dataSource = PollingDataSource( + credential: 'dummy-key', + context: LDContextBuilder().kind('user', 'test').build(), + endpoints: ServiceEndpoints(), + logger: LDLogger(level: LDLogLevel.none), + dataSourceConfig: PollingDataSourceConfig(), + httpProperties: HttpProperties(), + testingInterval: interval, + httpClientFactory: (properties) => ld_common.HttpClient( + client: MockClient((request) async { + requestTimes.add(clock.elapsed); + await Future.delayed(responseTime); + completionTimes.add(clock.elapsed); + return http.Response('{}', 200); + }), + httpProperties: properties)); + dataSource.events.listen((_) {}); + + dataSource.start(); + await Future.delayed(const Duration(milliseconds: 900)); + dataSource.stop(); + + expect(requestTimes.length, greaterThanOrEqualTo(2)); + // Allow for timer resolution, but stay well above the 100 ms that a + // start-to-start cadence gives. + expect(requestTimes[1] - completionTimes[0], + greaterThanOrEqualTo(const Duration(milliseconds: 280))); + }); + + test('stop interrupts a pending wait', () { + fakeAsync((async) { + final harness = _Harness(async, [401]); + harness.dataSource.start(); + async.flushMicrotasks(); + + harness.dataSource.stop(); + expect(async.pendingTimers, isEmpty); + + async.elapse(const Duration(hours: 2)); + expect(harness.requestTimes, hasLength(1)); + }); + }); + + test('no status is reported for a poll that ends after stop', () { + fakeAsync((async) { + final response = Completer(); + final events = []; + final dataSource = PollingDataSource( + credential: 'dummy-key', + context: LDContextBuilder().kind('user', 'test').build(), + endpoints: ServiceEndpoints(), + logger: LDLogger(level: LDLogLevel.none), + dataSourceConfig: PollingDataSourceConfig(), + httpProperties: HttpProperties(), + testingInterval: _interval, + httpClientFactory: (properties) => ld_common.HttpClient( + client: MockClient((request) => response.future), + httpProperties: properties)); + dataSource.events.listen(events.add); + + dataSource.start(); + async.flushMicrotasks(); + dataSource.stop(); + response.complete(http.Response('', 401)); + async.flushMicrotasks(); + + expect(events, isEmpty); + expect(async.pendingTimers, isEmpty); + }); + }); +} diff --git a/packages/common_client/test/data_sources/polling_data_source_test.dart b/packages/common_client/test/data_sources/polling_data_source_test.dart index a2ec0d56..8a47c910 100644 --- a/packages/common_client/test/data_sources/polling_data_source_test.dart +++ b/packages/common_client/test/data_sources/polling_data_source_test.dart @@ -95,7 +95,7 @@ void main() { polling.start(); }); - test('permanent failure is reported for a 404', () { + test('a 404 is reported as an interruption', () { var methodCalled = false; final innerClient = MockClient((request) async { methodCalled = true; @@ -110,7 +110,9 @@ void main() { expectLater( statusManager.changes, emits(DataSourceStatus( - state: DataSourceState.shutdown, + // An interruption during initialization keeps the state at + // initializing. + state: DataSourceState.initializing, stateSince: DateTime(1), lastError: DataSourceStatusErrorInfo( kind: ErrorKind.errorResponse, @@ -119,6 +121,7 @@ void main() { statusCode: 404)))); polling.start(); + addTearDown(polling.stop); }); test('it includes the content-type header for REPORT requests', () {