diff --git a/app/src/main/java/to/bitkit/repositories/BackupRepo.kt b/app/src/main/java/to/bitkit/repositories/BackupRepo.kt index b3ea6df740..e359c3fe41 100644 --- a/app/src/main/java/to/bitkit/repositories/BackupRepo.kt +++ b/app/src/main/java/to/bitkit/repositories/BackupRepo.kt @@ -51,6 +51,7 @@ import to.bitkit.di.IoDispatcher import to.bitkit.di.json import to.bitkit.env.Env import to.bitkit.ext.formatPlural +import to.bitkit.ext.isPaykitTemporarilyUnavailable import to.bitkit.ext.nowMillis import to.bitkit.ext.runSuspendCatching import to.bitkit.models.ActiveOnchainAttemptBackup @@ -144,6 +145,8 @@ class BackupRepo @Inject constructor( private val runningBackups = ConcurrentHashMap.newKeySet() // Tracks active jobs since app start private val failedBackupRequired = ConcurrentHashMap() + private val temporaryFailureRetries = ConcurrentHashMap() + private val temporaryFailureSince = ConcurrentHashMap() private var isObserving = false private var lastNotificationTime = 0L @@ -499,8 +502,9 @@ class BackupRepo @Inject constructor( val hasFailedBackups = BackupCategory.entries.any { category -> val status = backupStatuses[category] ?: BackupItemStatus() + val pendingSince = temporaryFailureSince[category]?.coerceAtMost(status.required) ?: status.required val isPendingAndOverdue = status.isRequired && - currentTime - status.required > FAILED_BACKUP_CHECK_TIME + currentTime - pendingSince > FAILED_BACKUP_CHECK_TIME return@any isPendingAndOverdue } @@ -554,6 +558,8 @@ class BackupRepo @Inject constructor( } runningBackups -= category failedBackupRequired -= category + temporaryFailureRetries -= category + temporaryFailureSince -= category } Logger.info("Backup succeeded for: '$category'", context = TAG) } @@ -594,10 +600,25 @@ class BackupRepo @Inject constructor( } runningBackups -= category } - if (e is WalletBackupSnapshotChanged) { - Logger.debug("Deferred changing backup snapshot for: '$category'", context = TAG) - } else { - Logger.error("Backup failed for: '$category'", e, context = TAG) + when { + e is WalletBackupSnapshotChanged -> + Logger.debug("Deferred changing backup snapshot for: '$category'", context = TAG) + e.isPaykitTemporarilyUnavailable() -> retryAfterTemporaryFailure(category, backupRequired, e) + else -> Logger.error("Backup failed for: '$category'", e, context = TAG) + } + } + + private fun retryAfterTemporaryFailure(category: BackupCategory, backupRequired: Long, e: Throwable) { + val attempt = temporaryFailureRetries.merge(category, 1, Int::plus) ?: 1 + temporaryFailureSince.putIfAbsent(category, backupRequired) + val retryDelay = (TEMPORARY_FAILURE_RETRY_DELAY * (1 shl (attempt - 1).coerceAtMost(MAX_RETRY_SHIFT))) + .coerceAtMost(TEMPORARY_FAILURE_RETRY_MAX_DELAY) + Logger.warn("Retrying backup for: '$category' in '$retryDelay'", e, context = TAG) + scope.launch { + delay(retryDelay) + if (!failedBackupRequired.remove(category, backupRequired) || !isObserving) return@launch + val status = cacheStore.backupStatuses.first()[category] ?: return@launch + if (status.shouldBackup(category)) scheduleBackup(category) } } @@ -1117,6 +1138,15 @@ class BackupRepo @Inject constructor( private const val SYNC_STATUS_DEBOUNCE = 500L // 500ms debounce for sync status updates private val VSS_TIMESTAMP_TIMEOUT = 60.seconds + /** First wait before retrying a backup that failed on a temporary Paykit error, doubled per retry. */ + private val TEMPORARY_FAILURE_RETRY_DELAY = 10.seconds + + /** Longest wait between retries, past the Paykit shared-state lock's write cooldown. */ + private val TEMPORARY_FAILURE_RETRY_MAX_DELAY = 5.minutes + + /** Caps the doubling so the shift cannot overflow before the max delay applies. */ + private const val MAX_RETRY_SHIFT = 6 + /** * How long a pending restore gates ordinary uploads for. Longer than any restore in practice, * short enough that a restore that never returns cannot hold the gate for the session. diff --git a/app/src/test/java/to/bitkit/repositories/BackupRepoTest.kt b/app/src/test/java/to/bitkit/repositories/BackupRepoTest.kt index f32da1cd04..4ca0837392 100644 --- a/app/src/test/java/to/bitkit/repositories/BackupRepoTest.kt +++ b/app/src/test/java/to/bitkit/repositories/BackupRepoTest.kt @@ -3,7 +3,9 @@ package to.bitkit.repositories import android.content.Context import com.synonym.bitkitcore.ActivityTags import com.synonym.bitkitcore.PreActivityMetadata +import com.synonym.paykit.PaykitException import com.synonym.vssclient.VssItem +import kotlin.time.Duration.Companion.minutes import kotlinx.coroutines.CompletableDeferred import kotlinx.coroutines.launch import kotlinx.coroutines.flow.first @@ -14,6 +16,7 @@ import kotlinx.coroutines.flow.MutableSharedFlow import kotlinx.coroutines.flow.MutableStateFlow import kotlinx.coroutines.flow.update import kotlinx.coroutines.test.advanceTimeBy +import kotlinx.coroutines.test.currentTime import kotlinx.coroutines.test.runCurrent import kotlinx.serialization.json.JsonObject import kotlinx.serialization.json.jsonObject @@ -22,6 +25,7 @@ import org.junit.Test import org.mockito.kotlin.any import org.mockito.kotlin.anyOrNull import org.mockito.kotlin.argumentCaptor +import org.mockito.kotlin.atLeastOnce import org.mockito.kotlin.doSuspendableAnswer import org.mockito.kotlin.eq import org.mockito.kotlin.mock @@ -30,6 +34,7 @@ import org.mockito.kotlin.times import org.mockito.kotlin.verify import org.mockito.kotlin.verifyBlocking import org.mockito.kotlin.whenever +import to.bitkit.R import to.bitkit.data.AppCacheData import to.bitkit.data.AppDb import to.bitkit.data.BlocktankRefundAddress @@ -1053,6 +1058,104 @@ class BackupRepoTest : BaseUnitTest() { } } + @Test + fun `wallet backup retries after a busy Paykit shared state`() = test { + whenever(clock.now()).thenReturn(Instant.fromEpochMilliseconds(3_000)) + whenever { privatePaykitRepo.backupSnapshot() } + .thenReturn(Result.failure(PaykitException.SharedStateBusy("shared_state_busy", "locked"))) + .thenReturn(Result.success(PrivatePaykitBackupSnapshot(null, 0))) + val backupStatuses = MutableStateFlow( + mapOf( + BackupCategory.WALLET to BackupItemStatus( + synced = 1_000, + required = 2_000, + ), + ) + ) + val allowWalletClear = CompletableDeferred().apply { complete(Unit) } + stubBackupStatuses(backupStatuses, allowWalletClear) {} + stubBackupObservers() + + try { + sut.startObservingBackups() + runCurrent() + advanceTimeBy(5_000) + runCurrent() + verify(privatePaykitRepo, times(1)).backupSnapshot() + verify(vssBackupClient, never()).putObject(eq(BackupCategory.WALLET.name), any()) + + advanceTimeBy(20_000) + runCurrent() + + verify(privatePaykitRepo, times(2)).backupSnapshot() + verify(vssBackupClient).putObject(eq(BackupCategory.WALLET.name), any()) + assertFalse(backupStatuses.value.getValue(BackupCategory.WALLET).isRequired) + } finally { + sut.stopObservingBackups() + } + } + + @Test + fun `busy wallet backup retries after observation pauses and resumes`() = test { + whenever(clock.now()).thenReturn(Instant.fromEpochMilliseconds(3_000)) + whenever { privatePaykitRepo.backupSnapshot() } + .thenReturn(Result.failure(PaykitException.SharedStateBusy("shared_state_busy", "locked"))) + .thenReturn(Result.success(PrivatePaykitBackupSnapshot(null, 0))) + val backupStatuses = MutableStateFlow( + mapOf(BackupCategory.WALLET to BackupItemStatus(synced = 1_000, required = 2_000)) + ) + val allowWalletClear = CompletableDeferred().apply { complete(Unit) } + stubBackupStatuses(backupStatuses, allowWalletClear) {} + stubBackupObservers() + + try { + sut.startObservingBackups() + runCurrent() + advanceTimeBy(5_000) + runCurrent() + sut.stopObservingBackups() + advanceTimeBy(20_000) + runCurrent() + verify(vssBackupClient, never()).putObject(eq(BackupCategory.WALLET.name), any()) + + sut.startObservingBackups() + runCurrent() + advanceTimeBy(5_000) + runCurrent() + + verify(vssBackupClient).putObject(eq(BackupCategory.WALLET.name), any()) + } finally { + sut.stopObservingBackups() + } + } + + @Test + fun `busy wallet backup still warns once it stays pending past the failure window`() = test { + val startedAt = currentTime + whenever(clock.now()).thenAnswer { Instant.fromEpochMilliseconds(3_000 + currentTime - startedAt) } + whenever { privatePaykitRepo.backupSnapshot() } + .thenReturn(Result.failure(PaykitException.SharedStateBusy("shared_state_busy", "locked"))) + whenever(context.getString(R.string.settings__backup__failed_title)).thenReturn("Backup failed") + whenever(context.getString(R.string.settings__backup__failed_message)).thenReturn("Retrying") + val backupStatuses = MutableStateFlow( + mapOf(BackupCategory.WALLET to BackupItemStatus(synced = 1_000, required = 2_000)) + ) + val allowWalletClear = CompletableDeferred().apply { complete(Unit) } + stubBackupStatuses(backupStatuses, allowWalletClear) {} + stubBackupObservers() + + try { + sut.startObservingBackups() + runCurrent() + advanceTimeBy(31.minutes.inWholeMilliseconds) + runCurrent() + + verify(context, atLeastOnce()).getString(R.string.settings__backup__failed_title) + } finally { + sut.stopObservingBackups() + } + } + @Test fun `start observing backs up stale required status after clearing running flag`() = test { val backupStatuses = MutableStateFlow( diff --git a/changelog.d/next/1550.fixed.md b/changelog.d/next/1550.fixed.md new file mode 100644 index 0000000000..8c5c5b164d --- /dev/null +++ b/changelog.d/next/1550.fixed.md @@ -0,0 +1 @@ +Wallet backups that run while Paykit is busy now retry on their own instead of waiting for the next change or restart.