search

seedvault-app / seedvault

A backup application for the Android Open Source Project.
1.19k stars 73 forks source link

Restore fails with error: 'No suitable backups found at given location' #682

Open DDvO opened 2 weeks ago

DDvO commented 2 weeks ago

Trying to migrate apps+data to my new phone, the restore step fails. regardless which storage location I tried on the target (local phone storage or webDAV via the DAVx5 app, which provided further challenges, see https://github.com/seedvault-app/seedvault/issues/85#issuecomment-2170765445). After entering the correct 12-word passphrase that I had used to backup up apps+data on my old phone, I am stuck with this error:

No suitable backups found at given location This is most likely due to a wrong recovery code or storage error.

When I then select "Skip restoring apps", I get

No storage backups found Sorry, but there is nothing that can be restored.

The above error messages are very vague, not giving real info what went wrong why, so I can only guess what went wrong. I suspect a Seedvault bug. It turns out that it is there since more than 3 years: https://www.reddit.com/r/LineageOS/comments/lask4q/no_suitable_backups_found_at_given_location_for/

This makes Seedvault unusable for migrating apps+data to a new phone ☹️

grote commented 1 week ago

I suspect a Seedvault bug.

Would you please be so nice and export logs from right after you got those messages?

DDvO commented 1 week ago

I just re-did the restore attempt, which the same result, and here is the log: seedvault-14-4.0-1718651594220.txt. In this case the backup was created using DAVx5.

DDvO commented 1 week ago

Since someone claimed that he got it working using local phone storage for the backup and then copying that to the local storage of the new system, I tried this too, but in my case with the same negative result and the following log: seedvault-14-4.0-1718651988210.txt

DDvO commented 1 week ago

As mentioned, in in case the error message given is too vague! And the log is awkward to obtain and display, and its content are a mess that is mostly useless to regular users.

For effective user-level debugging, Seedvault should provide to-the-point failure information, e.g.

grote commented 1 week ago

relevent bit from seedvault-14-4.0-1718651594220.txt.

06-17 21:12:20.799 32718   337 E RestoreCoordinator: Error while getting restore set 1718570792674
06-17 21:12:20.799 32718   337 E RestoreCoordinator: java.io.IOException: java.io.IOException
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getInputStream(DocumentsStorage.kt:134)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderStoragePlugin$getAvailableBackups$2$1.invokeSuspend(DocumentsProviderStoragePlugin.kt:125)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderStoragePlugin$getAvailableBackups$2$1.invoke(Unknown Source:8)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderStoragePlugin$getAvailableBackups$2$1.invoke(Unknown Source:2)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.transport.restore.RestoreCoordinator.getAvailableMetadata(RestoreCoordinator.kt:80)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.transport.restore.RestoreCoordinator$getAvailableMetadata$1.invokeSuspend(Unknown Source:14)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:32)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:102)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:103)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)
06-17 21:12:20.799 32718   337 E RestoreCoordinator: Caused by: java.io.IOException
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getInputStream(DocumentsStorage.kt:131)
06-17 21:12:20.799 32718   337 E RestoreCoordinator:    ... 16 more
06-17 21:12:20.799 32718   337 I RestoreCoordinator: Got available metadata for tokens: []

Here we really can't say much, it is an I/O error.

Next one : seedvault-14-4.0-1718651988210.txt is different, here we have 3 restore sets and can't decrypt any of them:

06-17 21:19:16.620  2509  2558 E RestoreCoordinator: Error while getting restore set 1718466670667
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: java.io.IOException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: StreamingAeadDecryptingStream
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: segmentNr:0
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: ciphertextSegmentSize:1048576
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: headerRead:true
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: endOfCiphertext:true
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: endOfPlaintext:false
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: decryptionErrorOccured:true
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: ciphertextSgement position:15247 limit:15247
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: plaintextSegment position:0 limit:0
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: segmentNr:0 endOfCiphertext:true
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.loadSegment(StreamingAeadDecryptingStream.java:176)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.read(StreamingAeadDecryptingStream.java:231)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.read(StreamingAeadDecryptingStream.java:208)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.readBytes(IOStreams.kt:136)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.metadata.MetadataReaderImpl.readMetadata(MetadataReader.kt:59)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.transport.restore.RestoreCoordinator.getAvailableMetadata(RestoreCoordinator.kt:81)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.restore.RestoreViewModel$loadRestoreSets$1.invokeSuspend(RestoreViewModel.kt:147)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:103)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: Caused by: javax.crypto.AEADBadTagException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at java.lang.reflect.Constructor.newInstance0(Native Method)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at java.lang.reflect.Constructor.newInstance(Constructor.java:343)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.throwAEADBadTagExceptionIfAvailable(OpenSSLAeadCipher.java:320)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.doFinalInternal(OpenSSLAeadCipher.java:348)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.engineDoFinal(OpenSSLAeadCipher.java:262)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at javax.crypto.Cipher.doFinal(Cipher.java:2369)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.AesGcmHkdfStreaming$AesGcmHkdfStreamDecrypter.decryptSegment(AesGcmHkdfStreaming.java:300)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.loadSegment(StreamingAeadDecryptingStream.java:168)
06-17 21:19:16.620  2509  2558 E RestoreCoordinator:    ... 16 more
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: Error while getting restore set 1718570792674
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: java.io.IOException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: StreamingAeadDecryptingStream
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: segmentNr:0
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: ciphertextSegmentSize:1048576
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: headerRead:true
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: endOfCiphertext:true
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: endOfPlaintext:false
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: decryptionErrorOccured:true
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: ciphertextSgement position:16005 limit:16005
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: plaintextSegment position:0 limit:0
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: segmentNr:0 endOfCiphertext:true
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.loadSegment(StreamingAeadDecryptingStream.java:176)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.read(StreamingAeadDecryptingStream.java:231)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.read(StreamingAeadDecryptingStream.java:208)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.readBytes(IOStreams.kt:136)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.metadata.MetadataReaderImpl.readMetadata(MetadataReader.kt:59)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.transport.restore.RestoreCoordinator.getAvailableMetadata(RestoreCoordinator.kt:81)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.restore.RestoreViewModel$loadRestoreSets$1.invokeSuspend(RestoreViewModel.kt:147)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:103)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator: Caused by: javax.crypto.AEADBadTagException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at java.lang.reflect.Constructor.newInstance0(Native Method)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at java.lang.reflect.Constructor.newInstance(Constructor.java:343)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.throwAEADBadTagExceptionIfAvailable(OpenSSLAeadCipher.java:320)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.doFinalInternal(OpenSSLAeadCipher.java:348)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.engineDoFinal(OpenSSLAeadCipher.java:262)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at javax.crypto.Cipher.doFinal(Cipher.java:2369)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.AesGcmHkdfStreaming$AesGcmHkdfStreamDecrypter.decryptSegment(AesGcmHkdfStreaming.java:300)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.loadSegment(StreamingAeadDecryptingStream.java:168)
06-17 21:19:16.659  2509  2558 E RestoreCoordinator:    ... 16 more
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: Error while getting restore set 1718463896044
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: java.io.IOException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: StreamingAeadDecryptingStream
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: segmentNr:0
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: ciphertextSegmentSize:1048576
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: headerRead:true
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: endOfCiphertext:true
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: endOfPlaintext:false
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: decryptionErrorOccured:true
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: ciphertextSgement position:208 limit:208
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: plaintextSegment position:0 limit:0
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: segmentNr:0 endOfCiphertext:true
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.loadSegment(StreamingAeadDecryptingStream.java:176)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.read(StreamingAeadDecryptingStream.java:231)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.read(StreamingAeadDecryptingStream.java:208)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.copyTo(IOStreams.kt:106)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.copyTo$default(IOStreams.kt:103)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlin.io.ByteStreamsKt.readBytes(IOStreams.kt:136)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.metadata.MetadataReaderImpl.readMetadata(MetadataReader.kt:59)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.transport.restore.RestoreCoordinator.getAvailableMetadata(RestoreCoordinator.kt:81)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.stevesoltys.seedvault.restore.RestoreViewModel$loadRestoreSets$1.invokeSuspend(RestoreViewModel.kt:147)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:103)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator: Caused by: javax.crypto.AEADBadTagException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at java.lang.reflect.Constructor.newInstance0(Native Method)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at java.lang.reflect.Constructor.newInstance(Constructor.java:343)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.throwAEADBadTagExceptionIfAvailable(OpenSSLAeadCipher.java:320)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.doFinalInternal(OpenSSLAeadCipher.java:348)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.android.org.conscrypt.OpenSSLAeadCipher.engineDoFinal(OpenSSLAeadCipher.java:262)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at javax.crypto.Cipher.doFinal(Cipher.java:2369)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.AesGcmHkdfStreaming$AesGcmHkdfStreamDecrypter.decryptSegment(AesGcmHkdfStreaming.java:300)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    at com.google.crypto.tink.subtle.StreamingAeadDecryptingStream.loadSegment(StreamingAeadDecryptingStream.java:168)
06-17 21:19:16.682  2509  2558 E RestoreCoordinator:    ... 16 more
06-17 21:19:16.682  2509  2558 I RestoreCoordinator: Got available metadata for tokens: []
DDvO commented 1 week ago

relevent bit from seedvault-14-4.0-1718651594220.txt.

06-17 21:12:20.799 32718   337 E RestoreCoordinator: Error while getting restore set 1718570792674
06-17 21:12:20.799 32718   337 E RestoreCoordinator: java.io.IOException: java.io.IOException

So here Seedvault should have reported, e.g., "Error while getting restore set 1718570792674" and state for which file it got which type of I/O error.

Here we really can't say much, it is an I/O error.

The directory 1718570792674 is present and does contain 133 app+data files, plus .backup.metadata. I see no reason for an actual I/O error.

The whole directory and all files can be read (e.g., using adb pull -a /sdcard/.SeedVaultAndroidBackup/1718570792674) without any errors.

I can only guess that Seedvault tries to access a wrong file, or access an existing file in a wrong way or access got denied. The app really should report exactly what exactly went wrong on which file.

As mentioned below, on a second try there was no I/O error.

DDvO commented 1 week ago

Next one : seedvault-14-4.0-1718651988210.txt is different, here we have 3 restore sets and can't decrypt any of them:


06-17 21:19:16.620  2509  2558 E RestoreCoordinator: Error while getting restore set 1718466670667
06-17 21:19:16.620  2509  2558 E RestoreCoordinator: java.io.IOException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT

So here Seedvault should have reported, e.g., "Could not decrypt restore set 1718466670667"

06-17 21:19:16.659 2509 2558 E RestoreCoordinator: Error while getting restore set 1718570792674 06-17 21:19:16.659 2509 2558 E RestoreCoordinator: java.io.IOException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT

So here Seedvault should have reported, e.g., "Could not decrypt restore set 1718570792674"

Note that this is the same restore set for which at first an I/O error occurred. Weird.

06-17 21:19:16.682 2509 2558 E RestoreCoordinator: Error while getting restore set 1718463896044 06-17 21:19:16.682 2509 2558 E RestoreCoordinator: java.io.IOException: error:1e000065:Cipher functions:OPENSSL_internal:BAD_DECRYPT

So here Seedvault should have reported, e.g., "Could not decrypt restore set 1718463896044"

I've double-checked that the pass phrase used on the source (backup) and target (restore) system are the same and used the Seedvault option on the target system to verify the pass phrase I entered, which did not give an error.

I wonder why nothing could be decrypted. There must be some Seedvault bug here.

Since AEAD ciphers are used, looks like the passphrase and/or the encrypted contents somehow got modified between the backup and restore attempts or were wrongly use. I'm pretty sure this is not due to a user's mistake with the passphrase nor due to a data transmission issue between source and target system. For being able to better distinguish potential reasons, I suggest adding a checksum/hash to each backup set/directory.

grote commented 1 week ago

I see no reason for an actual I/O error.

Maybe the filesystem is corrupted?

As mentioned below, on a second try there was no I/O error.

Ok, all good then I guess.

So here Seedvault should have reported, e.g., "Could not decrypt restore set 1718466670667"

Isn't this what "This is most likely due to a wrong recovery code or storage error." is saying? We don't expose low lever details to users and what would be the benefit? If it can not decrypt/read any backups and you are proficient enough to mess with the internal files, then you'll find them yourself.

looks like the passphrase and/or the encrypted contents somehow got modified between the backup

faulty filesystem or storage medium? Have you tried using a (different) flash drive for backup/restore?

DDvO commented 1 week ago

I see no reason for an actual I/O error.

Maybe the filesystem is corrupted?

No - as I wrote, the directory can be read (e.g., using adb pull) without issues.

As mentioned below, on a second try there was no I/O error.

Ok, all good then I guess.

Not really - it seems to be a matter of luck.

So here Seedvault should have reported, e.g., "Could not decrypt restore set 1718466670667"

Isn't this what "This is most likely due to a wrong recovery code or storage error." is saying? We don't expose low lever details to users and what would be the benefit? If it can not decrypt/read any backups and you are proficient enough to mess with the internal files, then you'll find them yourself.

Again, as I wrote in the OP, it is NOT sufficient to provide very vague error messages. User should get to-the-point information what exactly went wrong and why. For instance, it's a big difference whether the backup directory cannot be found, or there was a file or directory read error, or the pass phrase does not match.

looks like the passphrase and/or the encrypted contents somehow got modified between the backup

faulty filesystem or storage medium? Have you tried using a (different) flash drive for backup/restore?

Again, the file system is fine.

In my 20+ years of using many different Android phones, I never had issues with the internal file system. Also the current two phones involved here work fine - except that Seedvault exhibits all sorts of weird behavior, which is for sure not the fault of (the system on) the phones. In particular, the good-old Titanium Backup works pretty well.

grote commented 1 week ago

Again, as I wrote in the OP, it is NOT sufficient to provide very vague error messages. User should get to-the-point information what exactly went wrong and why.

Sorry, I can't find the pull request from you that provided this behavior.

In particular, the good-old Titanium Backup works pretty well.

Why don't you stick with that then?