seedvault-app / seedvault

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

Nextxcloud backup fails after some progress #637

Closed xlash123 closed 3 months ago

xlash123 commented 3 months ago

I've been having problems with getting the Nextcloud backup to work. The backup appears to be working, but after a few minutes, I get a "Backup failed" notification. The data does get stored successfully on Nextcloud, and I don't see any failed uploads in my Nextcloud client app.

Looking at the logs dump from Seedvault, I am not seeing an obvious error. I did two tests, and the backup stopped at the same place. In both cases, the backup stopped right after processing the package com.qualcomm.qcrilmsgtunnel. Below is an excerpt of my second run leading up to said package and what came after.

Details

``` 03-29 11:39:41.778 26204 26392 I FullBackup: Perform full backup for com.pcapdroid.mitm. 03-29 11:39:41.780 26204 26392 D ApkBackup: Package com.pcapdroid.mitm with version 18 already has a backup (18) with the same signature. Not backing it up. 03-29 11:39:41.780 26204 26392 I BackupCoordinator: Get backup quota for com.pcapdroid.mitm. Is full backup: true. 03-29 11:39:41.780 26204 26392 I BackupCoordinator: Reported quota of 52428800 bytes. 03-29 11:39:41.783 1771 15563 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10348; state: DISABLED 03-29 11:39:41.784 1771 15563 D CompatibilityChangeReporter: Compat change id reported: 177438394; UID 10348; state: DISABLED 03-29 11:39:41.784 1771 15563 D CompatibilityChangeReporter: Compat change id reported: 135772972; UID 10348; state: DISABLED 03-29 11:39:41.784 1771 15563 D CompatibilityChangeReporter: Compat change id reported: 135754954; UID 10348; state: ENABLED 03-29 11:39:41.785 1771 15563 D BackupManagerService: [UserID:0] awaiting agent for ApplicationInfo{ee0cd8e com.pcapdroid.mitm} 03-29 11:39:41.785 1771 1842 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10348; state: ENABLED 03-29 11:39:41.802 1771 1842 I ActivityManager: Start proc 15564:com.pcapdroid.mitm/u0a348 for backup {android/FullBackupAgent} 03-29 11:39:41.829 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 168419799; UID 10348; state: DISABLED 03-29 11:39:41.829 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 273564678; UID 10348; state: DISABLED 03-29 11:39:41.858 1771 4993 D BackupManagerService: [UserID:0] agentConnected pkg=com.pcapdroid.mitm agent=android.os.BinderProxy@f6646a2 03-29 11:39:41.858 1771 15563 I BackupManagerService: [UserID:0] got agent android.app.IBackupAgent$Stub$Proxy@b5d9f33 03-29 11:39:41.901 26204 26392 I FullBackup: Check full backup size of 17318912 bytes. 03-29 11:39:41.903 1771 15581 I file_backup_helper: Name: apps/com.pcapdroid.mitm/_manifest 03-29 11:39:41.904 26204 26392 D FullBackup: Initializing OutputStream for com.pcapdroid.mitm. 03-29 11:39:41.904 1771 15581 I FullBackup_native: measured [/data/cache/backup_stage/_manifest] at 2560 03-29 11:39:41.904 1771 15581 I BackupRestoreController: Getting widget state for user: 0 03-29 11:39:41.904 1771 15581 D BackupManagerService: Calling doFullBackup() on com.pcapdroid.mitm 03-29 11:39:43.202 26204 26392 I NotificationBackupObserver: Showing progress notification for com.oasisfeng.island.fdroid 180/263 03-29 11:39:43.204 26204 26392 I BackupNotificationManager: 263/345 - 76% - PCAPdroid mitm 03-29 11:39:44.075 1771 2390 E WifiVendorHal: getWifiLinkLayerStats_1_6_Internal(l.1199) failed {.code = ERROR_INVALID_ARGS, .description = } 03-29 11:39:44.733 1771 2748 I ActivityManager: Killing 13461:dummydomain.yetanothercallblocker/u0a373 (adj 975): empty #17 03-29 11:39:44.743 1771 1843 I libprocessgroup: Successfully killed process cgroup uid 10373 pid 13461 in 8ms 03-29 11:39:44.879 26204 27833 I FullBackup: Finish full backup of com.pcapdroid.mitm. 03-29 11:39:44.882 1771 2454 I ActivityManager: Process com.pcapdroid.mitm (pid 15564) has died: bkup TRNB 03-29 11:39:44.882 1771 1843 I libprocessgroup: Successfully killed process cgroup uid 10348 pid 15564 in 0ms 03-29 11:39:45.059 26204 27833 I BackupCoordinator: Request full backup time. Returned 0 03-29 11:39:45.060 1771 11280 I PFTBT : Transport suggested backoff=0 03-29 11:39:45.060 1771 11280 V BackupManagerConstants: getBackupFinishedNotificationReceivers(...) returns 03-29 11:39:45.060 26204 27833 I NotificationBackupObserver: Completed. Target: com.pcapdroid.mitm, status: 0 03-29 11:39:45.060 1771 11280 I PFTBT : Unbinding agent in com.pcapdroid.mitm 03-29 11:39:45.060 1771 11280 W ActivityManager: Unbinding backup agent with no active backup 03-29 11:39:45.060 1771 11280 I PFTBT : Initiating full-data transport backup of com.qti.phone token: 409790635 03-29 11:39:45.062 26204 27833 I FullBackup: Perform full backup for com.qti.phone. 03-29 11:39:45.065 26204 27833 D ApkBackup: Package com.qti.phone is vanilla system app. Not backing it up. 03-29 11:39:45.065 26204 27833 I BackupCoordinator: Get backup quota for com.qti.phone. Is full backup: true. 03-29 11:39:45.065 26204 27833 I BackupCoordinator: Reported quota of 52428800 bytes. 03-29 11:39:45.068 1771 15594 D BackupManagerService: [UserID:0] awaiting agent for ApplicationInfo{4cb718b com.qti.phone} 03-29 11:39:45.071 1771 2454 D BackupManagerService: [UserID:0] agentConnected pkg=com.qti.phone agent=android.os.BinderProxy@98905f 03-29 11:39:45.071 1771 15594 I BackupManagerService: [UserID:0] got agent android.app.IBackupAgent$Stub$Proxy@56c9aac 03-29 11:39:45.085 26204 27833 I FullBackup: Check full backup size of 0 bytes. 03-29 11:39:45.086 26204 27833 I BackupCoordinator: Cancel full backup of com.qti.phone because of NO_DATA 03-29 11:39:45.086 26204 27833 I FullBackup: Cancel full backup 03-29 11:39:45.086 1771 11280 W PFTBT : Error -1002 backing up com.qti.phone 03-29 11:39:45.089 26204 27833 I BackupCoordinator: Request full backup time. Returned 0 03-29 11:39:45.089 1771 11280 I PFTBT : Transport suggested backoff=0 03-29 11:39:45.089 1771 11280 I PFTBT : Transport rejected backup of com.qti.phone, skipping 03-29 11:39:45.090 1771 11280 I PFTBT : Unbinding agent in com.qti.phone 03-29 11:39:45.090 26204 27833 I NotificationBackupObserver: Completed. Target: com.qti.phone, status: -1002 03-29 11:39:45.090 26204 27833 I NotificationBackupObserver: Showing progress notification for com.pcapdroid.mitm 181/263 03-29 11:39:45.090 1771 11280 W ActivityManager: Unbinding backup agent with no active backup 03-29 11:39:45.090 1771 11280 I PFTBT : Initiating full-data transport backup of com.qualcomm.qcrilmsgtunnel token: 409790635 03-29 11:39:45.091 26204 27833 I BackupNotificationManager: 264/345 - 77% - com.qti.phone 03-29 11:39:45.092 26204 27375 I FullBackup: Perform full backup for com.qualcomm.qcrilmsgtunnel. 03-29 11:39:45.095 26204 27375 D ApkBackup: Package com.qualcomm.qcrilmsgtunnel is vanilla system app. Not backing it up. 03-29 11:39:45.095 26204 27375 I BackupCoordinator: Get backup quota for com.qualcomm.qcrilmsgtunnel. Is full backup: true. 03-29 11:39:45.095 26204 27375 I BackupCoordinator: Reported quota of 52428800 bytes. 03-29 11:39:45.105 1771 15595 D BackupManagerService: [UserID:0] awaiting agent for ApplicationInfo{b5eb598 com.qualcomm.qcrilmsgtunnel} 03-29 11:39:45.119 1771 2454 I ActivityManager: Process com.qti.phone (pid 4426) has died: pers PER 03-29 11:39:45.119 1771 1843 I libprocessgroup: Successfully killed process cgroup uid 10155 pid 4426 in 0ms 03-29 11:39:45.120 1771 2454 W ActivityManager: Scheduling restart of crashed service com.qti.phone/.ExtTelephonyService in 0ms for persistent 03-29 11:39:45.120 1771 2454 W ActivityManager: Scheduling restart of crashed service com.qualcomm.qti.telephonyservice/.QtiTelephonyService in 0ms for persistent 03-29 11:39:45.120 1771 2454 W ActivityManager: Scheduling restart of crashed service com.qualcomm.qcrilmsgtunnel/.QcrilMsgTunnelService in 0ms for persistent 03-29 11:39:45.121 1771 2454 W ActivityManager: Re-adding persistent process ProcessRecord{b572d12 4426:com.qti.phone/u0a155} 03-29 11:39:45.121 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10155; state: DISABLED 03-29 11:39:45.121 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 177438394; UID 10155; state: DISABLED 03-29 11:39:45.121 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 135772972; UID 10155; state: DISABLED 03-29 11:39:45.121 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 135754954; UID 10155; state: ENABLED 03-29 11:39:45.122 1771 1842 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10155; state: ENABLED 03-29 11:39:45.125 1771 1841 W BackupManagerService: agentDisconnected: the backup agent for com.qualcomm.qti.telephonyservice died: cancel current operations 03-29 11:39:45.126 1771 15595 I BackupManagerService: [UserID:0] got agent null 03-29 11:39:45.126 1771 15595 W BackupManagerService: Unable to bind to full agent for com.qualcomm.qcrilmsgtunnel 03-29 11:39:45.127 1771 15596 V LifecycleOperationStorage: [UserID:0] Cancel: token=186ce8ab 03-29 11:39:45.128 26204 27833 I BackupCoordinator: Cancel full backup of com.qualcomm.qcrilmsgtunnel because of UNKNOWN_ERROR 03-29 11:39:45.142 1771 1842 I ActivityManager: Start proc 15597:com.qti.phone/u0a155 for restart com.qti.phone 03-29 11:39:45.204 1771 2454 D CompatibilityChangeReporter: Compat change id reported: 161145287; UID 10155; state: DISABLED 03-29 11:39:45.211 677 677 I hwservicemanager: getTransport: Cannot find entry vendor.qti.data.factory@2.4::IFactory/default in either framework or device VINTF manifest. 03-29 11:39:45.254 26204 27833 I FullBackup: Cancel full backup 03-29 11:39:46.752 1771 11280 W PFTBT : Error -1003 backing up com.qualcomm.qcrilmsgtunnel 03-29 11:39:46.752 1771 15596 W system_server: Long monitor contention with owner full-transport-requested (11280) at void com.android.server.backup.fullbackup.PerformFullTransportBackupTask.run()(PerformFullTransportBackupTask.java:511) waiters=0 in void com.android.server.backup.fullbackup.PerformFullTransportBackupTask.handleCancel(boolean) for 1.623s 03-29 11:39:46.753 26204 27833 I BackupCoordinator: Request full backup time. Returned 0 03-29 11:39:46.753 1771 11280 I PFTBT : Transport suggested backoff=0 03-29 11:39:46.754 1771 11280 W PFTBT : Application failure for package: com.qualcomm.qcrilmsgtunnel 03-29 11:39:46.754 26204 27833 I NotificationBackupObserver: Completed. Target: com.qualcomm.qcrilmsgtunnel, status: -1003 03-29 11:39:46.754 26204 27833 I NotificationBackupObserver: Showing progress notification for com.qti.phone 182/263 03-29 11:39:46.754 1771 11280 W ActivityManager: Unbinding backup agent with no active backup 03-29 11:39:46.754 1771 11280 I PFTBT : Unbinding agent in com.qualcomm.qcrilmsgtunnel 03-29 11:39:46.754 26204 27833 I BackupNotificationManager: 265/345 - 77% - com.qualcomm.qcrilmsgtunnel 03-29 11:39:46.754 1771 11280 W ActivityManager: Unbinding backup agent with no active backup 03-29 11:39:46.754 1771 11280 I PFTBT : Initiating full-data transport backup of com.qualcomm.qti.cne token: 409790635 03-29 11:39:46.755 1771 11280 I PFTBT : Full backup completed with status: -2003 03-29 11:39:46.755 26204 27833 I NotificationBackupObserver: Backup finished 183/263. Status: -2003 03-29 11:39:46.758 1771 11280 I PFTBT : Full data backup pass finished. 03-29 11:39:46.762 1771 11280 V BackupManagerService: [UserID:0] Released wakelock:*backup*-0-3862 03-29 11:39:46.772 26204 26204 D ConfigurableBackupTransportService: Service destroyed. 03-29 11:39:46.793 1771 2748 I ActivityManager: Process com.qti.phone (pid 15597) has died: pers PER 03-29 11:39:46.794 1771 1843 I libprocessgroup: Successfully killed process cgroup uid 10155 pid 15597 in 0ms 03-29 11:39:46.794 1771 2748 W ActivityManager: Scheduling restart of crashed service com.qti.phone/.ExtTelephonyService in 0ms for persistent 03-29 11:39:46.794 1771 2748 W ActivityManager: Scheduling restart of crashed service com.qualcomm.qti.telephonyservice/.QtiTelephonyService in 0ms for persistent 03-29 11:39:46.794 1771 2748 W ActivityManager: Scheduling restart of crashed service com.qualcomm.qcrilmsgtunnel/.QcrilMsgTunnelService in 0ms for persistent 03-29 11:39:46.794 1771 2748 W ActivityManager: Re-adding persistent process ProcessRecord{b572d12 15597:com.qti.phone/u0a155} 03-29 11:39:46.795 1771 2748 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10155; state: DISABLED 03-29 11:39:46.795 1771 2748 D CompatibilityChangeReporter: Compat change id reported: 177438394; UID 10155; state: DISABLED 03-29 11:39:46.795 1771 2748 D CompatibilityChangeReporter: Compat change id reported: 135772972; UID 10155; state: DISABLED 03-29 11:39:46.795 1771 2748 D CompatibilityChangeReporter: Compat change id reported: 135754954; UID 10155; state: ENABLED 03-29 11:39:46.796 1771 1842 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10155; state: ENABLED 03-29 11:39:46.811 1771 1842 I ActivityManager: Start proc 15619:com.qti.phone/u0a155 for restart com.qti.phone 03-29 11:39:46.896 677 677 I hwservicemanager: getTransport: Cannot find entry vendor.qti.data.factory@2.4::IFactory/default in either framework or device VINTF manifest. 03-29 11:39:47.090 1771 2390 E WifiVendorHal: getWifiLinkLayerStats_1_6_Internal(l.1199) failed {.code = ERROR_INVALID_ARGS, .description = } 03-29 11:39:47.778 1771 2390 E WifiVendorHal: getWifiLinkLayerStats_1_6_Internal(l.1199) failed {.code = ERROR_INVALID_ARGS, .description = } 03-29 11:39:50.111 1771 2390 E WifiVendorHal: getWifiLinkLayerStats_1_6_Internal(l.1199) failed {.code = ERROR_INVALID_ARGS, .description = } 03-29 11:39:53.126 1771 2390 E WifiVendorHal: getWifiLinkLayerStats_1_6_Internal(l.1199) failed {.code = ERROR_INVALID_ARGS, .description = } 03-29 11:39:55.673 1771 1771 I LineageHealth: Current mChargingStopReason: 0 ```

I've done some digging into past issues, but I don't see one that is in line with my logs.

If needed, I can provide more logs from either of the two runs I did.

Thank you very much for the support!

Versions

Android: 13 (e/OS 1.21-t) Seedvault: 13-3.3 Nextcloud Client: 3.28.0 Nextcloud Server: 28.0.3

grote commented 3 months ago

thakns for the report, looks like duplicate of #491 to me.