seedvault
seedvault copied to clipboard
"Backup running" notification sometimes remains after backup is complete
The "Backup running" notification should always be removed when a backup is no longer running.
My last backup "failed" and notified me as such, but even now, a half an hour after the failure notification, there is still a notification present that says "Backup running" for Cromite.
I have occasionally seen this behavior (for various apps) even after an overall successful backup, too.
It can be confusing not knowing which to believe! :smile:
The relevant lines might be the ones with NotificationBackupObserver?
Logcat snippet
06-18 10:06:52.070 1010168 20318 20332 I NotificationBackupObserver: Completed. Target: org.calyxos.ripple, status: 0
06-18 10:06:52.075 1010168 20318 20332 I FullBackup: Perform full backup for org.cromite.cromite.
06-18 10:06:52.079 1010168 20318 20332 I BackupCoordinator: Get backup quota for org.cromite.cromite. Is full backup: true.
06-18 10:06:52.079 1010168 20318 20332 I BackupCoordinator: Reported quota of 9223372036854775807 bytes.
06-18 10:06:52.538 1010168 20318 20332 I FullBackup: Check full backup size of 26632192 bytes.
06-18 10:06:52.545 1010168 20318 20332 D FullBackup: Initializing OutputStream for org.cromite.cromite.
06-18 10:06:52.549 1010168 20318 21201 I NotificationBackupObserver: Showing progress notification for org.calyxos.ripple 233/253
06-18 10:06:52.550 1010168 20318 21201 I NotificationBackupObserver: 233/253 - Cromite (org.cromite.cromite)
[...]
06-18 10:07:07.122 1010168 20318 20416 E FullBackup: Error handling backup data for org.cromite.cromite:
06-18 10:07:07.122 1010168 20318 20416 E FullBackup: java.io.IOException: Pipe closed
[...]
06-18 10:11:52.249 1000 1581 14419 D BackupManagerService: Timeout message received for token=5b634c50
06-18 10:11:52.546 1000 1581 14419 D BackupManagerService: Timeout message received for token=432d53c
06-18 10:11:52.546 1000 1581 14419 V LifecycleOperationStorage: [UserID:10] Cancel: token=432d53c
06-18 10:11:52.546 1000 1581 14419 W PFTBT : Full backup cancel of org.cromite.cromite
06-18 10:11:52.553 1010168 20318 20416 I BackupCoordinator: Cancel full backup of org.cromite.cromite because of UNKNOWN_ERROR
06-18 10:11:52.554 1010331 25347 25347 I Process : Sending signal. PID: 25347 SIG: 9
06-18 10:11:52.627 1000 1581 4506 I ActivityManager: Process org.cromite.cromite (pid 25347) has died: bkup TRNB
06-18 10:11:52.628 shell 10848 1587 D BinderSender: onProcessDied: pid=25347, uid=1010331
06-18 10:11:52.628 shell 10848 13061 D BinderSender: onUidGone: uid=1010331, disabled=false
06-18 10:11:52.628 shell 10848 13061 V BinderSender: Uid 1010331 dead
06-18 10:11:52.629 root 864 864 I Zygote : Process 25347 exited due to signal 9 (Killed)
06-18 10:11:52.629 1000 1581 1809 I libprocessgroup: Removed cgroup /sys/fs/cgroup/uid_1010331/pid_25347
06-18 10:11:52.629 1000 1581 1791 D DisplayManagerService: Drop pending events for gone uid 1010331
06-18 10:11:53.079 1000 1581 14228 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:53.080 1000 1581 14223 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:53.081 1000 1581 4506 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:53.082 1000 1581 4506 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:53.082 1000 1581 4506 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:53.086 1000 1581 4506 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:54.545 1000 1581 14223 E AppOps : Operation not found: uid=1041 pkg=audioserver(null) op=WAKE_LOCK
06-18 10:11:55.059 1046 1145 3541 D BufferPoolAccessor2.0: evictor expired: 1, evicted: 0
06-18 10:11:56.060 media 1117 6242 D BufferPoolAccessor2.0: evictor expired: 1, evicted: 0
06-18 10:11:56.907 10167 3490 3503 I ndroid.systemui: Background concurrent mark compact GC freed 92MB AllocSpace bytes, 195(3136KB) LOS objects, 70% free, 39MB/135MB, paused 3.052ms,6.968ms total 714.982ms
06-18 10:11:56.959 1000 1581 2049 D ActivityManager: freezing 21437 com.google.android.gms
06-18 10:11:56.961 1000 1581 2049 D ActivityManager: freezing 24296 org.tasks
06-18 10:11:56.964 1000 1581 2049 D ActivityManager: freezing 24322 com.android.externalstorage
06-18 10:11:56.965 1000 1581 2049 D ActivityManager: freezing 24788 com.android.providers.calendar
06-18 10:11:57.060 media 1117 6242 D BufferPoolAccessor2.0: bufferpool2 0xe47c3748 : 0(0 size) total buffers - 0(0 size) used buffers - 78/86 (recycle/alloc) - 8/166 (fetch/transfer)
06-18 10:11:57.060 media 1117 6242 D BufferPoolAccessor2.0: evictor expired: 1, evicted: 1
06-18 10:11:57.060 1046 1145 3541 D BufferPoolAccessor2.0: bufferpool2 0xb4000072c866aa58 : 0(0 size) total buffers - 0(0 size) used buffers - 77/81 (recycle/alloc) - 4/80 (fetch/transfer)
06-18 10:11:57.060 1046 1145 3541 D BufferPoolAccessor2.0: evictor expired: 1, evicted: 1
06-18 10:11:57.278 10167 3490 3505 W System : A resource failed to call close.
06-18 10:11:57.278 10167 3490 3505 W System : A resource failed to call close.
06-18 10:12:01.780 1010168 20318 20355 D WebDavStorage: getOutputStream (redacted)
06-18 10:12:01.798 1010168 20318 20416 I FullBackup: Cancel full backup
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: Error cancelling full backup for org.cromite.cromite
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: java.io.IOException: at.bitfire.dav4jvm.exception.NotFoundException: HTTP 404
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.plugins.webdav.WebDavStoragePlugin.removeData(WebDavStoragePlugin.kt:159)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.transport.backup.FullBackup.clearBackupData(FullBackup.kt:189)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.transport.backup.FullBackup.cancelFullBackup(FullBackup.kt:196)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.transport.backup.BackupCoordinator.cancelFullBackup(BackupCoordinator.kt:307)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.transport.ConfigurableBackupTransport$cancelFullBackup$1.invokeSuspend(ConfigurableBackupTransport.kt:207)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:280)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.transport.ConfigurableBackupTransport.cancelFullBackup(ConfigurableBackupTransport.kt:206)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at android.app.backup.BackupTransport$TransportImpl.cancelFullBackup(BackupTransport.java:910)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.android.internal.backup.IBackupTransport$Stub.onTransact(IBackupTransport.java:786)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at android.os.Binder.execTransactInternal(Binder.java:1505)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at android.os.Binder.execTransact(Binder.java:1444)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: Caused by: at.bitfire.dav4jvm.exception.NotFoundException: HTTP 404
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at at.bitfire.dav4jvm.DavResource.checkStatus(DavResource.kt:583)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at at.bitfire.dav4jvm.DavResource.checkStatus(DavResource.kt:565)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at at.bitfire.dav4jvm.DavResource.delete(DavResource.kt:441)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at at.bitfire.dav4jvm.DavResource.delete$default(DavResource.kt:429)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: at com.stevesoltys.seedvault.plugins.webdav.WebDavStoragePlugin.removeData(WebDavStoragePlugin.kt:152)
06-18 10:12:03.024 1010168 20318 20416 W FullBackup: ... 17 more
06-18 10:12:03.052 1000 1581 24858 W PFTBT : Error -1000 backing up org.cromite.cromite
06-18 10:12:03.056 1010168 20318 20416 I BackupCoordinator: Request full backup time. Returned 0
06-18 10:12:03.057 1000 1581 24858 I PFTBT : Transport suggested backoff=0
06-18 10:12:03.057 1000 1581 24858 W PFTBT : Transport failed; aborting backup: -1000
06-18 10:12:03.057 1010168 20318 20416 I NotificationBackupObserver: Completed. Target: org.cromite.cromite, status: -1000
06-18 10:12:03.058 1000 1581 24858 W ActivityManager: Unbinding backup agent with no active backup
06-18 10:12:03.058 1000 1581 24858 W ActivityManager: Process/uid not found attempting kill of org.cromite.cromite / 1010331
06-18 10:12:03.058 1000 1581 24858 I PFTBT : Full backup completed with status: -1000
06-18 10:12:03.058 1010168 20318 20416 I NotificationBackupObserver: Backup finished 234/253. Status: -1000
06-18 10:12:03.061 1000 1581 25341 E BackupManagerService: Error backing up org.cromite.cromite: write failed: EPIPE (Broken pipe)
06-18 10:12:03.066 1010168 20318 20318 I BackupStateManager: appBackupRunning: false, filesBackupRunning: false, workInfoState: ENQUEUED
06-18 10:12:03.067 1010168 20318 20318 D ConfigurableBackupTransportService: Service destroyed.