diff --git a/app/src/main/java/org/thoughtcrime/securesms/backup/v2/BackupRepository.kt b/app/src/main/java/org/thoughtcrime/securesms/backup/v2/BackupRepository.kt index e04a5cc59e..664990c312 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/backup/v2/BackupRepository.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/backup/v2/BackupRepository.kt @@ -1819,7 +1819,7 @@ object BackupRepository { val forwardSecrecyMetadata = EncryptedBackupReader.readForwardSecrecyMetadata(tempBackupFile.inputStream()) if (forwardSecrecyMetadata == null) { - Log.w(TAG, "Failed to read forward secrecy metadata!") + Log.w(TAG, "[remoteRestore] Downloaded the backup file, but failed to read its forward secrecy metadata!") return RemoteRestoreResult.Failure } @@ -2007,8 +2007,14 @@ object BackupRepository { ).encodeByteString() } + /** + * Reads the forward secrecy metadata out of the header of the remote backup file, or null if the file has none. + * + * Note that the two network steps here can fail with the same error types, so each one logs which step it was. + */ suspend fun getRemoteBackupForwardSecrecyMetadata(): Either { return archiveService.getMessageBackupFileLocation() + .onLeft { Log.w(TAG, "[getRemoteBackupForwardSecrecyMetadata] Failed to get the backup file location: ${it::class.simpleName}", it.cause, true) } .flatMap { location -> val headers = location.cdnCredentials.toMutableMap().apply { this["range"] = "bytes=0-${EncryptedBackupReader.BACKUP_SECRET_METADATA_UPPERBOUND - 1}" @@ -2017,6 +2023,7 @@ object BackupRepository { AppDependencies.signalServiceMessageReceiver .retrieveBackupForwardSecretMetadataBytes(location.cdn, headers, location.path, EncryptedBackupReader.BACKUP_SECRET_METADATA_UPPERBOUND) .toArchiveResult() + .onLeft { Log.w(TAG, "[getRemoteBackupForwardSecrecyMetadata] Got a backup file location on cdn ${location.cdn}, but failed to read the header: ${it::class.simpleName}", it.cause, true) } } .map { bytes -> EncryptedBackupReader.readForwardSecrecyMetadata(ByteArrayInputStream(bytes)) } } diff --git a/app/src/main/java/org/thoughtcrime/securesms/jobs/BackupMessagesJob.kt b/app/src/main/java/org/thoughtcrime/securesms/jobs/BackupMessagesJob.kt index 5037078ea1..01c0895ce6 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/BackupMessagesJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/BackupMessagesJob.kt @@ -252,16 +252,22 @@ class BackupMessagesJob private constructor( } } - if (SignalStore.backup.backupSecretRestoreRequired) { + val svrbReInitRan = SignalStore.backup.backupSecretRestoreRequired + if (svrbReInitRan) { Log.i(TAG, "[svrb-restore] First backup of re-registered account without remote restore, read remote data if available to re-init") val forwardSecrecyMetadata: ByteArray? = when (val result = BackupRepository.getRemoteBackupForwardSecrecyMetadata()) { - is Either.Right -> result.value + is Either.Right -> { + if (result.value == null) { + Log.w(TAG, "[svrb-restore] Read the remote backup header, but it contained no forward secrecy metadata!", true) + } + result.value + } is Either.Left -> when (val error = result.value) { is ArchiveError.CredentialError.Unauthorized, is ArchiveError.EntitlementError.NotEntitled, is ArchiveError.CredentialError.NotFound -> { - Log.i(TAG, "[svrb-restore] No backup data found, continuing.", true) + Log.i(TAG, "[svrb-restore] No backup data found (${error::class.simpleName}), continuing.", true) null } is ArchiveError.CredentialError.ZkVerificationFailed -> { @@ -315,13 +321,16 @@ class BackupMessagesJob private constructor( return Result.fatalFailure(RuntimeException(result.throwable)) } } + } else { + Log.w(TAG, "[svrb-restore] No remote forward secrecy metadata to restore from, skipping the SVRB restore.", true) } + Log.i(TAG, "[svrb-restore] Re-init finished. Have local secret data: ${SignalStore.backup.nextBackupSecretData != null}", true) SignalStore.backup.backupSecretRestoreRequired = false } val backupSecretData = SignalStore.backup.nextBackupSecretData ?: run { - Log.i(TAG, "First SVRB backup! Creating new backup chain.", true) + Log.i(TAG, "First SVRB backup! Creating new backup chain. (reInitRan: $svrbReInitRan)", true) val secretData = SignalNetwork.svrBApi.createNewBackupChain(auth, SignalStore.backup.messageBackupKey) SignalStore.backup.nextBackupSecretData = secretData secretData diff --git a/feature/registration/src/main/java/org/signal/registration/screens/remotebackuprestore/RemoteBackupRestoreViewModel.kt b/feature/registration/src/main/java/org/signal/registration/screens/remotebackuprestore/RemoteBackupRestoreViewModel.kt index d21775234a..f21f930081 100644 --- a/feature/registration/src/main/java/org/signal/registration/screens/remotebackuprestore/RemoteBackupRestoreViewModel.kt +++ b/feature/registration/src/main/java/org/signal/registration/screens/remotebackuprestore/RemoteBackupRestoreViewModel.kt @@ -48,6 +48,9 @@ class RemoteBackupRestoreViewModel( private val _state = MutableStateFlow(RemoteBackupRestoreState(aep)) val state: StateFlow = _state.asStateFlow() + /** Logging only. Each attempt costs an SVRB guess, so it's useful to know how many were spent. */ + private var restoreAttempts = 0 + init { _state .throttleLatest(1.seconds) { it.restoreState != RemoteBackupRestoreState.RestoreState.InProgress } @@ -127,6 +130,8 @@ class RemoteBackupRestoreViewModel( private fun restoreBackup() { viewModelScope.launch { + restoreAttempts++ + Log.i(TAG, "[restoreBackup] Starting restore attempt #$restoreAttempts.") repository.restoreRemoteBackup(_state.value.aep).collect { progress -> when (progress) { is RemoteBackupRestoreProgress.Downloading -> { @@ -187,7 +192,7 @@ class RemoteBackupRestoreViewModel( ) } is RemoteBackupRestoreProgress.PermanentSvrBFailure -> { - Log.w(TAG, "[restoreBackup] Remote restore failed: permanent SVRB failure.") + Log.w(TAG, "[restoreBackup] Remote restore failed: permanent SVRB failure. (attempt #$restoreAttempts)") _state.value = _state.value.copy( restoreState = RemoteBackupRestoreState.RestoreState.PermanentSvrBFailure, restoreProgress = null