Infinite looping while backing up APKs

[elem089]

Hi, I mentioned this a while ago as a side-note in a different issue (#696). This morning it happened again:
SeedVault is set for me to run backups every third day, and only while the device is being charged.
Every now and again I realize that the backup is caught in an infinite loop: looking at the notifications I observe that always the same few apks are being backup up, again and again. In that situation the device heats up significantly (some battery-monitoring app is telling something like 39°C).
This loop can be stopped by pulling the charger, the backup stopps immediately then (leaving the last notification in place, btw.; looks as if SeedVault wouldn't terminate properly, but I may be wrong).
This time I exported a log right after I had stopped the backup. I don't understand much of it, but the looping is obvious (line 11125 onwards).
Let me know if you need more info.

seedvault-14-4.0-1719898242473.zip

[grote]

Thanks for the log. There's a log of strange stuff happening. I'll quote the relevant bits:

Looks like our forground service gets stopped, because it has no types.

07-02 07:19:23.220  1314 10449 W ForegroundServiceTypeLoggerModule: FGS stop call for: 10130 has no types!
07-02 07:19:23.230  1314  2868 W JobScheduler: Job didn't exist in JobStore: 9ea5446 #u0a130/16181 com.stevesoltys.seedvault/androidx.work.impl.background.systemjob.SystemJobService

07-02 07:19:28.741  1314  4019 I ActivityManager: Background started FGS: Allowed [callingPackage: com.stevesoltys.seedvault; callingUid: 10130; uidState: TRNB; uidBFSL: n/a; intent: Intent { act=ACTION_START_FOREGROUND cmp=com.stevesoltys.seedvault/androidx.work.impl.foreground.SystemForegroundService (has extras) }; code:SYSTEM_ALLOW_LISTED; tempAllowListReason:<,reasonCode:SYSTEM_ALLOW_LISTED,duration:9223372036854775807,callingUid:-1>; targetSdkVersion:34; callerTargetSdkVersion:34; startForegroundCount:0; bindFromPackage:null: isBindService:false]

07-02 07:19:40.888  1314  2261 W ForegroundServiceTypeLoggerModule: FGS stop call for: 10130 has no types!

What gets stopped is com.stevesoltys.seedvault/androidx.work.impl.foreground.SystemForegroundService so that comes from WorkManager. Our Worker uses FOREGROUND_SERVICE_TYPE_DATA_SYNC which still works for me. Also, in the manifest this service has android:foregroundServiceType="dataSync", so no idea why it claims there's no type. The system loops between starting and killing the service for a long time.

@elem089 what ROM is this on and which version?

---

This seems unrelated to the issue but may hint at a problem with your OS:

07-02 07:29:47.645  1314  2209 E ResilientAtomicFile: Failed to verity-protect shortcut package item
07-02 07:29:47.645  1314  2209 E ResilientAtomicFile: java.io.IOException: Failed to enable fs-verity on FD(726): Inappropriate ioctl for device

---

Then suddenly, there's backup activity going on:

07-02 07:29:55.144 25293 25345 E ApkBackupManager: Error while writing APK for jp.co.canon.bsd.ad.pixmaprint
07-02 07:29:55.144 25293 25345 E ApkBackupManager: java.io.IOException: could not find nor create
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.createOrGetFile(DocumentsStorage.kt:166)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.plugins.saf.DocumentsStorageKt.createOrGetFile$default(DocumentsStorage.kt:156)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.plugins.saf.DocumentsProviderStoragePlugin.getOutputStream(DocumentsProviderStoragePlugin.kt:99)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackupManager$backUpApk$2.invokeSuspend(ApkBackupManager.kt:107)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackupManager$backUpApk$2.invoke(Unknown Source:8)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackupManager$backUpApk$2.invoke(Unknown Source:4)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackup.backupApkIfNecessary(ApkBackup.kt:119)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackupManager.backUpApk(ApkBackupManager.kt:105)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackupManager.backUpApks(ApkBackupManager.kt:72)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.ApkBackupManager.backup(ApkBackupManager.kt:49)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.AppBackupWorker.doBackup(AppBackupWorker.kt:142)
07-02 07:29:55.144 25293 25345 E ApkBackupManager: 	at com.stevesoltys.seedvault.worker.AppBackupWorker.doWork(AppBackupWorker.kt:123)

@elem089 what backup destination to you back up to. It seems, it fails completely to create/get files on that type of destination, maybe related to that storage error above?

---

Now our job got cancelled and we request a new backup which may yet be another loop:

07-02 07:30:07.354 25293 25343 E AppBackupWorker: Error backing up APKs: 
07-02 07:30:07.354 25293 25343 E AppBackupWorker: kotlinx.coroutines.JobCancellationException: Job was cancelled; job=JobImpl{Cancelling}@2cc6cce
07-02 07:30:07.354 25293 25343 I AppBackupWorker: Requesting app data backup... (stopped: true)
07-02 07:30:07.354 25293 25343 D AppBackupWorker: Have requested backup.

07-02 07:30:07.355 25293 25341 E AppBackupWorker: Error backing up APKs: 
07-02 07:30:07.355 25293 25341 E AppBackupWorker: kotlinx.coroutines.JobCancellationException: Job was cancelled; job=JobImpl{Cancelling}@4984d01
07-02 07:30:07.355 25293 25341 I AppBackupWorker: Requesting app data backup... (stopped: true)
07-02 07:30:07.355 25293 25341 D AppBackupWorker: Have requested backup.

07-02 07:30:07.356 25293 25344 E AppBackupWorker: Error backing up APKs: 
07-02 07:30:07.356 25293 25344 E AppBackupWorker: kotlinx.coroutines.JobCancellationException: Job was cancelled; job=JobImpl{Cancelling}@43e3832
07-02 07:30:07.356 25293 25344 I AppBackupWorker: Requesting app data backup... (stopped: true)
07-02 07:30:07.356 25293 25344 D AppBackupWorker: Have requested backup.

07-02 07:30:07.356 25293 25337 E AppBackupWorker: Error backing up APKs: 
07-02 07:30:07.356 25293 25337 E AppBackupWorker: kotlinx.coroutines.JobCancellationException: Job was cancelled; job=JobImpl{Cancelling}@dbe0adf
07-02 07:30:07.356 25293 25337 I AppBackupWorker: Requesting app data backup... (stopped: true)
07-02 07:30:07.356 25293 25337 D AppBackupWorker: Have requested backup.

A re-try is expected, but that it happens so soon isn't. There should be some back-off.
We are using setBackoffCriteria(BackoffPolicy.EXPONENTIAL, 5, TimeUnit.MINUTES) for scheduled work, but not for manually triggered work. @elem089 how this this backup started? Normally by the system after the three days since last run were up and you charged?

[elem089]

what ROM is this on and which version?

Device is OnePlus 6 (enchilada), ROM is LineageOS21 >> https://xdaforums.com/t/rom-official-enchilada-14-lineageos-21.4656607/

what backup destination to you back up to. It seems, it fails completely to create/get files on that type of destination, maybe related to that storage error above?

backups are going to local storage (on device).
What's strange about this is that I had those problems a while ago (see my remark on issue 696), then it worked for a while. And this morning it reappeared for an unknown reason. All I do with the backups is that I copy the entire folder (.SeedVaultAndroidBackup) over to my PC through an USB connection, a simple read only process

how this this backup started? Normally by the system after the three days since last run were up and you charged?

yes, exactly.
There was an exception though: on Saturday morning (i.e. 3 days ago) I started the backup manually because else it would have started in the afternoon and I wanted to be sure that it would run in the morning

[grote]

I started the backup manually

Ok, so we either need to add backoff here as well or not retry on failures.

Device is OnePlus 6 (enchilada), ROM is LineageOS21

There's something wrong with your storage. You could try to copy things around with the Files app that came pre-installed. It should have similar issues. If your storage is faulty or throws these kinds of errors, there's not much Seedvault can do unfortunately.

[elem089]

There's something wrong with your storage. You could try to copy things around with the Files app that came pre-installed. It should have similar issues. If your storage is faulty or throws these kinds of errors, there's not much Seedvault can do unfortunately.

Things can break, of course. But in fact I'm doing a lot of copying around on the device's storage and never had any trouble.
What I could try to do is to do a complete reset of SeedVault then start from scratch with a new local .SeedVaultAndroidBackup folder if you feel that this could make sense. Let me know what you think

[grote]

I'm doing a lot of copying around on the device's storage and never had any trouble.

With the Files app, or adb or what mechanism? Here, I am talking specifically about the Storage Access Framework which the pre-installed Files app also uses.

What I could try to do is to do a complete reset of SeedVault then start from scratch with a new local .SeedVaultAndroidBackup folder if you feel that this could make sense.

Worth a try:

• force stop seedvault
• delete /sdcard/.SeedVaultAndroidBackup manually and make sure it is really gone
• launch seedvault and go to "Backup location" immediately and re-select your internal storage there
• export logs as soon as this process is complete
• try a manual backup
• export logs as soon as this is complete

[elem089]

With the Files app, or adb or what mechanism? Here, I am talking specifically about the Storage Access Framework which the pre-installed Files app also uses.

I'm most of the time using Total Commander but also the internal Files app that comes with LOS. For backing up stuff to my Windows PC I'm using the standard USB file transfer mechanism. Only very rarely I use adb pull or push commands

Worth a try: ...

Yup, that's what I was thinking about. Maybe not today though ;)

[elem089]

did as you wrote. Interesting: the new backup is ~25% smaller than the last backup before the reset.

First log (right after setting the location):
seedvault-14-4.0-1719935382004.zip

2nd log from after first manual backup:

seedvault-14-4.0-1719936301004.zip