search

seedvault-app / seedvault

A backup application for the Android Open Source Project.
1.31k stars 75 forks source link

Error during restore of app during setup stops restoration of other apps #305

Closed metronidazole closed 9 months ago

metronidazole commented 3 years ago

During setup of a new install, if an app fails to restore during the restore process then the whole backup stops and the remaining apps are not restored. This is obviously non ideal. There should be some graceful error handling and continue with restore given the importance of avoiding data loss.

grote commented 3 years ago

Expected behavior is to catch errors and still restore as much as possible. When that's not happening, we need logs (logcat) to find out what is going on.

metronidazole commented 3 years ago

@grote

Logcat here https://zerobin.net/?964426de8a21554c#F1IgZaSx9rNeTIJ94Dy+Leo6fYaBmutJJbTj4gmsgaw=

grote commented 3 years ago

Relevant snippets:

08-28 12:42:17.264  3323  4090 E ApkRestore: Error re-installing APK for com.meetup.
08-28 12:42:17.264  3323  4090 E ApkRestore: java.io.IOException: read failed: EIO (I/O error)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at libcore.io.IoBridge.read(IoBridge.java:519)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at java.io.FileInputStream.read(FileInputStream.java:320)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at android.os.ParcelFileDescriptor$AutoCloseInputStream.read(ParcelFileDescriptor.java:1005)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at java.io.FileInputStream.read(FileInputStream.java:289)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at android.os.ParcelFileDescriptor$AutoCloseInputStream.read(ParcelFileDescriptor.java:996)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at com.stevesoltys.seedvault.transport.backup.ApkBackupKt.copyStreamsAndGetHash(ApkBackup.kt:214)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at com.stevesoltys.seedvault.restore.install.ApkRestore.cacheApk(ApkRestore.kt:210)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at com.stevesoltys.seedvault.restore.install.ApkRestore.cacheApk$default(ApkRestore.kt:204)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at com.stevesoltys.seedvault.restore.install.ApkRestore.restore(ApkRestore.kt:85)
08-28 12:42:17.264  3323  4090 E ApkRestore:    at com.stevesoltys.seedvault.restore.install.ApkRestore$restore$1.invokeSuspend(ApkRestore.kt:58)

Here, a missing file seems to cause a runtime exception, one of the fun things SAF does and probably the cause of the issue:

08-28 12:42:17.291  3696  3977 E DatabaseUtils: Writing exception to parcel
08-28 12:42:17.291  3696  3977 E DatabaseUtils: java.lang.IllegalArgumentException: Failed to determine if 680B-081A:.SeedVaultAndroidBackup/d291dc418e343afe.sv is child of 680B-081A:: java.io.FileNotFoundException: Missing file for 680B-081A:.SeedVaultAndroidBackup/d291dc418e343afe.sv at /mnt/media_rw/680B-081A/.SeedVaultAndroidBackup/d291dc418e343afe.sv
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at com.android.internal.content.FileSystemProvider.isChildDocument(FileSystemProvider.java:143)
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at android.provider.DocumentsProvider.enforceTree(DocumentsProvider.java:235)
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at android.provider.DocumentsProvider.query(DocumentsProvider.java:923)
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at android.content.ContentProvider$Transport.query(ContentProvider.java:278)
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:106)
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at android.os.Binder.execTransactInternal(Binder.java:1154)
08-28 12:42:17.291  3696  3977 E DatabaseUtils:     at android.os.Binder.execTransact(Binder.java:1123)
08-28 12:42:17.295  3323  4090 W DocumentFile: Failed query: java.lang.IllegalArgumentException: Failed to determine if 680B-081A:.SeedVaultAndroidBackup/d291dc418e343afe.sv is child of 680B-081A:: java.io.FileNotFoundException: Missing file for 680B-081A:.SeedVaultAndroidBackup/d291dc418e343afe.sv at /mnt/media_rw/680B-081A/.SeedVaultAndroidBackup/d291dc418e343afe.sv

Here a similar problem when trying to get the restore sets:

08-28 12:45:25.342  1234  1234 I TransportClient: ConfigurableBackupTransportService#15: Notifying [BH/MSG_RUN_GET_RESTORE_SETS] transport = IBackupTransport
08-28 12:45:25.351  3696  4199 E DatabaseUtils: Writing exception to parcel
08-28 12:45:25.351  3696  4199 E DatabaseUtils: java.lang.IllegalArgumentException: Failed to determine if 680B-081A:.SeedVaultAndroidBackup is child of 680B-081A:: java.io.FileNotFoundException: No root for 680B-081A
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at com.android.internal.content.FileSystemProvider.isChildDocument(FileSystemProvider.java:143)
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at android.provider.DocumentsProvider.enforceTree(DocumentsProvider.java:235)
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at android.provider.DocumentsProvider.query(DocumentsProvider.java:927)
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at android.content.ContentProvider$Transport.query(ContentProvider.java:278)
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:106)
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at android.os.Binder.execTransactInternal(Binder.java:1154)
08-28 12:45:25.351  3696  4199 E DatabaseUtils:     at android.os.Binder.execTransact(Binder.java:1123)
08-28 12:45:25.351  1234  2826 E BackupManagerService: Error from transport getting set list: Failed to determine if 680B-081A:.SeedVaultAndroidBackup is child of 680B-081A:: java.io.FileNotFoundException: No root for 680B-081A
08-28 12:42:17.396  3323  4090 D RestoreViewModel: java.lang.IllegalArgumentException: Failed to determine if 680B-081A:.SeedVaultAndroidBackup is child of 680B-081A:: java.io.FileNotFoundException: No root for 680B-081A
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at android.database.DatabaseUtils.readExceptionFromParcel(DatabaseUtils.java:172)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at android.database.DatabaseUtils.readExceptionFromParcel(DatabaseUtils.java:142)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at android.content.ContentProviderProxy.query(ContentProviderNative.java:472)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at android.content.ContentResolver.query(ContentResolver.java:1183)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at android.content.ContentResolver.query(ContentResolver.java:1115)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at android.content.ContentResolver.query(ContentResolver.java:1071)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$listFilesBlocking$2.invoke(DocumentsStorage.kt:229)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$listFilesBlocking$2.invoke(Unknown Source:0)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$getLoadedCursor$2.invokeSuspend(DocumentsStorage.kt:305)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$getLoadedCursor$2.invoke(Unknown Source:10)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturnIgnoreTimeout(Undispatched.kt:102)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at kotlinx.coroutines.TimeoutKt.setupTimeout(Timeout.kt:78)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at kotlinx.coroutines.TimeoutKt.access$setupTimeout(Timeout.kt:1)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at kotlinx.coroutines.TimeoutKt.withTimeout(Timeout.kt:31)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.getLoadedCursor(DocumentsStorage.kt:303)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.getLoadedCursor$default(DocumentsStorage.kt:302)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.listFilesBlocking(DocumentsStorage.kt:228)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.findFileBlocking(DocumentsStorage.kt:272)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getSetDir(DocumentsStorage.kt:133)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderRestorePlugin.getApkInputStream(DocumentsProviderRestorePlugin.kt:116)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.restore.install.ApkRestore.cacheApk(ApkRestore.kt:209)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.restore.install.ApkRestore.cacheApk$default(ApkRestore.kt:204)
08-28 12:42:17.396  3323  4090 D RestoreViewModel:  at com.stevesoltys.seedvault.restore.install.ApkRestore.restore(ApkRestore.kt:85)
stevleibelt commented 1 year ago

@grote could you guess how complicated, time consuming and important it would be to implement this feature request?

Thanks for your work so far.

taggart commented 1 year ago

I ran into something similar, in my case there were two apps that were not yet installed and prompted me to install them before restoring their data. When I clicked "tap to install" on one, it attempted to launch aurora store, but got stuck in a spinner of death because aurora store wasn't yet setup. I launched aurora store by hand, clicked through it's initial setup stuff and got it to the point where I could browse apps etc. But the restore process was still stuck with a spinner and "Download Failed" at the bottom. Exiting the restore UI and relaunching caused it to re-install all the apps again. Then the next time around clicking "tap to install" and calling out to aurora worked because it was now setup, but only for the first app. There was no way to return from aurora to the restore UI. Relaunching the restore ui a 3rd time again reinstalled all the apps, and again got to the two that were missing (even the one I had installed on pass 2). I skipped doing "tap to install" for those, and clicked Next instead to proceed(I will fix those by hand). My issue might be different than the original problem in this report, but the solution might be the same: better error handling in the app restore process

There might also be another optimization improvement here: maybe the restore could prompt to ask if apps that are already installed need to be reinstalled.

Is there was way for me to gather a logcat for this after the fact? If not, I suppose I could run the restore again, I haven't yet changed anything on the phone that couldn't be overwritten.