search

seedvault-app / seedvault

A backup application for the Android Open Source Project.
1.26k stars 74 forks source link

Automatic backups happen despite backup disabled #416

Open foss- opened 2 years ago

foss- commented 2 years ago

LineageOS 19.1 2022-06-06 Seedvault 12-3.0

Ran Seedvault backup once. Now want to use it only on demand when started manually. However I get daily error messages about failed backup runs.

Backup my apps: off Backup my files: off

Error message: Backup error: A device backup failed to run. Fix.

Clicking on Fix opens Seedvault settings.

logcat, 1 year

The USB drive used in initial backup is not plugged in. Seedvault seems to be complaining about that. But I don't understand how to stop it from thinking I want automatic backups.

grote commented 2 years ago

Does it still happen after turning Backup my apps on and off again?

foss- commented 2 years ago

Done, lets wait and I'll report back. UPDATE: just received another failed backup info. And they keep repeating on a daily basis.

foss- commented 2 years ago

Is there anything else that can be provided to help moving this forward?

ghost commented 2 years ago

Would be nice to see an option to enable/disable automated backups.

grote commented 2 years ago

Can you try re-setting your backup location? It is on a flash drive, right?

If that doesn't help, please provide logs when doing this resetting and ideally right after you get an error.

foss- commented 2 years ago

Backup location was a USB drive. How is backup location reset? Tapping Backup location shows some backup options but no reset option.

grote commented 2 years ago

Just re-select the same drive after inserting it.

foss- commented 2 years ago

Logcat after seeing error is in reports first post. Connected the USB drive and re-selected it under backup location. Disconnected drive and now waiting to see if the issue is persisting. Logcat while doing reset (1 year): https://bin.disroot.org/?baacc8f40a812c50#FgbGESvFTSLisVjUSVTZdRmHSfwVfaqiw32ZdSC77GFV Reset was done 06-29 09:46:10

grote commented 2 years ago

Potentially relevant part:

06-29 09:46:13.967 31025 31025 D ExternalStorage: After updating volumes, found 2 active roots
06-29 09:46:13.968  2303  2303 D StorageNotification: Notifying about public volume: VolumeInfo{public:8,98}:
06-29 09:46:13.968  2303  2303 D StorageNotification:     type=PUBLIC diskId=disk:8,96 partGuid= mountFlags=0 mountUserId=0 
06-29 09:46:13.968  2303  2303 D StorageNotification:     state=UNMOUNTED 
06-29 09:46:13.968  2303  2303 D StorageNotification:     fsType=vfat fsUuid=C85D-1413 fsLabel=UNTITLED 
06-29 09:46:13.968  2303  2303 D StorageNotification:     path=/mnt/media_rw/C85D-1413 internalPath=/mnt/media_rw/C85D-1413 
06-29 09:46:13.979  2303  2303 D StorageNotification: Notifying about public volume: VolumeInfo{public:8,98}:
06-29 09:46:13.979  2303  2303 D StorageNotification:     type=PUBLIC diskId=disk:8,96 partGuid= mountFlags=0 mountUserId=0 
06-29 09:46:13.979  2303  2303 D StorageNotification:     state=BAD_REMOVAL 
06-29 09:46:13.979  2303  2303 D StorageNotification:     fsType=vfat fsUuid=C85D-1413 fsLabel=UNTITLED 
06-29 09:46:13.979  2303  2303 D StorageNotification:     path=/mnt/media_rw/C85D-1413 internalPath=/mnt/media_rw/C85D-1413 
06-29 09:46:13.982 31025 31025 D ExternalStorage: After updating volumes, found 2 active roots
06-29 09:46:13.983 31025 31039 W DocumentsProvider: Failed during query
06-29 09:46:13.983 31025 31039 W DocumentsProvider: java.io.FileNotFoundException: No root for C85D-1413
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at com.android.externalstorage.ExternalStorageProvider.getRootFromDocId(ExternalStorageProvider.java:447)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at com.android.externalstorage.ExternalStorageProvider.getFileForDocId(ExternalStorageProvider.java:411)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at com.android.externalstorage.ExternalStorageProvider.getFileForDocId(ExternalStorageProvider.java:406)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at com.android.internal.content.FileSystemProvider.getFileForDocId(FileSystemProvider.java:684)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at com.android.internal.content.FileSystemProvider.includeFile(FileSystemProvider.java:598)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at com.android.internal.content.FileSystemProvider.queryDocument(FileSystemProvider.java:371)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at android.provider.DocumentsProvider.query(DocumentsProvider.java:924)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at android.content.ContentProvider$Transport.query(ContentProvider.java:272)
06-29 09:46:13.983 31025 31039 W DocumentsProvider:     at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:107)

However, both logcats miss log output by Seedvault which makes this hard to debug.

foss- commented 2 years ago

What do I need to provide to help out? Have you tried reproducing on your side by setting up and removing a USB drive? I am still waiting for the error to happen currently but since it is triggered daily iirc I should know more in a bit less than 24h.

foss- commented 2 years ago

I think there was no notification about backups for a while. Just updated LineageOS nightly and was greeted with the known notification about backup error after the reboot.

grote commented 2 years ago

The Android backup API has no way to stop automatic backups, but we hack around it. This seems for some reason not to work in your case. Maybe only stops working after rebooting the device?

foss- commented 2 years ago

Wondering if non automatic backups would be a better default then along with an option to enable automatic backups. Indeed after rebooting the device I get the frequent bacakup errors with no way to stop automatic backup.

foss- commented 2 years ago

Still seeing daily alerts / notifications. The situation would not be as problematic, if it was a dedicated app for which I could customize notifications. But since seedvault is baked into the system, I think that is not possible or at least I couldn't find an option.

grote commented 2 years ago

As a workaround, you could disable app backups completely, that should stop the notifications and then only enable when you actually plugged your drive in and want to do a backup.

Maybe the system isn't recognizing your flash drive as a removable drive!?

From the log above it seems there's something wrong with the drive, e.g. it is in state BAD_REMOVAL . Did you try running fsck on it?

foss- commented 2 years ago

As a workaround, you could disable app backups completely, that should stop the notifications and then only enable when you actually plugged your drive in and want to do a backup.

Would love to disable backups completely but I am unable to find an option to do that.

From the log above it seems there's something wrong with the drive, e.g. it is in state BAD_REMOVAL . Did you try running fsck on it?

Not knowingly. Maybe I unplugged before doing some removal dance first? I am not very experienced with usage of LineageOS and removable USB drives, so might have done something stupid while unplugging. But happy to completely disable backup until I need it again.

grote commented 2 years ago

Would love to disable backups completely but I am unable to find an option how to do that.

In the "App backup" category, there's no setting for "Backup my apps"?

foss- commented 2 years ago

For unknown reasons Backup my apps was on again. Disabled it now, but I think this will not prevent the error notifications from showing. Lets see in the coming days.

Note that per the initial report that setting was off and backup error notifications were still happening: Backup my apps: off Backup my files: off

foss- commented 2 years ago

Notifications about backup errors still incoming despite both options being set to off.

grote commented 2 years ago

Wow! Do you have maybe a work-profile or different user set up?

foss- commented 2 years ago

Not yet. You think it's worth setting up a second user to see if the behavior is reproducible? Edit: So you think this is not a general problem but device specific or even limited to my setup? Was also wondering if this happened to all users, would expect to see more reports about this. However I am still not sure how to handle this and am getting disturbed during work multiple times per day.

grote commented 2 years ago

You think it's worth setting up a second user to see if the behavior is reproducible?

No, I just wonder why the system is scheduling backup runs when backup is disabled, so I was thinking that they maybe come from another user or work profile.

foss- commented 2 years ago

Oh right, I can rule that out. So you believe this is not a general problem but specific to my setup or device?

Is there any way to reset or nuke SeedVault to get to a pristine state, hopefully eradicating whatever is currently hanging or got the wrong flag or tag stuck?

syborgxx commented 2 years ago

Yesterday I upgraded form LOS 18.1 to 19.1 - phone Pixel 4a5g. With both "Backup my apps" and "Backup my files" disabled I get the "Backup Error" message after every boot and when it tries to run an automatic backup.

My workaround is to "Force Stop" Seedvault after booting.

foss- commented 2 years ago

My workaround is to "Force Stop" Seedvault after booting.

Care to share how that would be done?

syborgxx commented 2 years ago

Go to Settings then search for seedvault. Click on the result and "Force stop."

foss- commented 2 years ago

Go to Settings then search for seedvault. Click on the result and "Force stop."

This does not prevent the notifications about failed backups for me.

syborgxx commented 2 years ago

Try freezing Seedvault with Titanium Backup.

On August 7, 2022 6:03:09 AM PDT, foss- @.***> wrote:

Go to Settings then search for seedvault. Click on the result and "Force stop."

This does not prevent the notifications about failed backups for me.

-- Reply to this email directly or view it on GitHub: https://github.com/seedvault-app/seedvault/issues/416#issuecomment-1207403963 You are receiving this because you commented.

Message ID: @.***> -- Sent from my Android device with K-9 Mail. Please excuse my brevity.

grote commented 2 years ago

Maybe this is a LineageOS specific issue as all users who reported this are on it. If backup my apps and files backup is off, seedvault should never run and never post notifications.

To further debug this, the output of those adb commands would be helpful:

adb shell bmgr activated
adb shell bmgr list transports
foss- commented 2 years ago

Thanks for following up on this issue - much appreciated.

Requested output:

grote commented 2 years ago

Thanks a lot for this output.

What does adb shell bmgr enabled give you?

So in the seedvault UI, "Backup my apps" is toggled off for sure (for the main user, no work profile)? And even when toggling this on and off again, running adb shell bmgr activated says that the backup manager is activated?

You could still manually try to adb shell bmgr activate false, but this really shouldn't be needed.

foss- commented 2 years ago 
Exception caught:
java.lang.SecurityException: No permission to configure backup activity
    at android.os.Parcel.createExceptionOrNull(Parcel.java:2426)
    at android.os.Parcel.createException(Parcel.java:2410)
    at android.os.Parcel.readException(Parcel.java:2393)
    at android.os.Parcel.readException(Parcel.java:2335)
    at android.app.backup.IBackupManager$Stub$Proxy.setBackupServiceActive(IBackupManager.java:3460)
    at com.android.commands.bmgr.Bmgr.doActivateService(Bmgr.java:898)
    at com.android.commands.bmgr.Bmgr.run(Bmgr.java:115)
    at com.android.commands.bmgr.Bmgr.main(Bmgr.java:90)
    at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method)
    at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:355)
Caused by: android.os.RemoteException: Remote stack trace:
    at com.android.server.backup.BackupManagerService.enforcePermissionsOnUser(BackupManagerService.java:425)
    at com.android.server.backup.BackupManagerService.setBackupServiceActive(BackupManagerService.java:442)
    at android.app.backup.IBackupManager$Stub.onTransact(IBackupManager.java:1693)
    at android.os.Binder.execTransactInternal(Binder.java:1179)
    at android.os.Binder.execTransact(Binder.java:1143)

foss- commented 1 year ago

This is still in NeedInfo. Anything else I can provide to help resolve this issue?

grote commented 1 year ago

Ok we have some more logs when turning "Backup my apps on/off":

system_server:

10-19 14:07:04.662  1409  3829 I BackupManagerService: [UserID:0] Backup enabled => false
10-19 14:07:04.662  1409  3829 D BackupManagerService: user:0 writeBackupEnableState enable:false
10-19 14:07:04.667  1409  1409 V BackupManagerService: Running a device init; 2 pending
10-19 14:07:04.667  1409  1409 V BackupManagerService: [UserID:0] initializeTransport(): [com.android.localtransport/.LocalTransport, com.stevesoltys.seedvault.transport.ConfigurableBackupTransport]
10-19 14:07:04.668  1409  1409 V BackupManagerService: [UserID:0] Acquired wakelock:*backup*-0-3580
10-19 14:07:04.668  1409  3580 I BackupManagerService: Initializing (wiping) backup transport storage: com.android.localtransport/.LocalTransport
10-19 14:07:04.680  1409  1409 I TransportClient: LocalTransportService#14: Notifying [PerformInitializeTask.run()] transport = IBackupTransport
10-19 14:07:04.683  1409  3580 I BackupManagerService: Device init successful
10-19 14:07:04.692  1409  3580 V BackupManagerConstants: getKeyValueBackupIntervalMilliseconds(...) returns 14400000
10-19 14:07:04.692  1409  3580 V BackupManagerConstants: getKeyValueBackupFuzzMilliseconds(...) returns 600000
10-19 14:07:04.692  1409  3580 V BackupManagerConstants: getKeyValueBackupRequiredNetworkType(...) returns 1
10-19 14:07:04.692  1409  3580 V BackupManagerConstants: getKeyValueBackupRequireCharging(...) returns true
10-19 14:07:04.692  1409  3580 V KeyValueBackupJob: Scheduling k/v pass in 249 minutes
10-19 14:07:04.694  1409  3580 I BackupManagerService: Initializing (wiping) backup transport storage: com.stevesoltys.seedvault.transport.ConfigurableBackupTransport
10-19 14:07:04.706  1409  1409 I TransportClient: ConfigurableBackupTransportService#15: Notifying [PerformInitializeTask.run()] transport = IBackupTransport
10-19 14:07:04.730  1409  3580 E BackupManagerService: Transport error in initializeDevice()
10-19 14:07:04.732  1409  3580 W BackupManagerService: Init failed on com.stevesoltys.seedvault.transport.ConfigurableBackupTransport resched in 2592000000
10-19 14:07:04.736  1409  3580 V BackupManagerService: [UserID:0] Released wakelock:*backup*-0-3580

seedvault:

10-19 14:07:04.702 27135 27135 D ConfigurableBackupTransportService: Service created.
10-19 14:07:04.704 27135 27135 D ConfigurableBackupTransportService: Transport bound.
10-19 14:07:04.707 27135 28718 I BackupCoordinator: Initialize Device!
10-19 14:07:04.719 27135 28718 E DocumentsStorage: Error finding file blocking
10-19 14:07:04.719 27135 28718 E DocumentsStorage: java.io.IOException
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$getLoadedCursor$2.invokeSuspend(DocumentsStorage.kt:283)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$getLoadedCursor$2.invoke(Unknown Source:8)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt$getLoadedCursor$2.invoke(Unknown Source:4)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturnIgnoreTimeout(Undispatched.kt:102)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at kotlinx.coroutines.TimeoutKt.setupTimeout(Timeout.kt:78)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at kotlinx.coroutines.TimeoutKt.access$setupTimeout(Timeout.kt:1)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at kotlinx.coroutines.TimeoutKt.withTimeout(Timeout.kt:31)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.getLoadedCursor(DocumentsStorage.kt:281)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.getLoadedCursor$default(DocumentsStorage.kt:280)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.listFilesBlocking(DocumentsStorage.kt:206)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.findFileBlocking(DocumentsStorage.kt:250)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.createOrGetDirectory(DocumentsStorage.kt:176)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage$rootBackupDir$1.invokeSuspend(DocumentsStorage.kt:69)

10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getCurrentSetDir(DocumentsStorage.kt:89)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getSetDir(DocumentsStorage.kt:117)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsStorage.getSetDir$default(DocumentsStorage.kt:116)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderStoragePlugin.initializeDevice(DocumentsProviderStoragePlugin.kt:46)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.transport.backup.BackupCoordinator.initializeDevice(BackupCoordinator.kt:124)
10-19 14:07:04.719 27135 28718 E DocumentsStorage:  at com.stevesoltys.seedvault.transport.ConfigurableBackupTransport$initializeDevice$1.invokeSuspend(ConfigurableBackupTransport.kt:115)

10-19 14:07:04.721 27135 28718 W DocumentsContract: Failed to create document
10-19 14:07:04.721 27135 28718 W DocumentsContract: android.os.ParcelableException: java.io.FileNotFoundException: No root for C85D-1337

10-19 14:07:04.722 27135 28718 E DocumentsStorage: Error creating root backup dir.

It seems that even when turning backups off, the system tells us to initialize our transport which fails in this case since it is on removable storage. Or maybe it happens, because it was briefly turned on?

I am not sure what we can do about this except maybe failing the init differently.

grote commented 1 year ago

A workaround could be to not show an error notification when backup is actually disabled. However, this wouldn't help us to understand and resolve the root cause.