Same backup keeps getting uploaded and deleted every 5 minutes

[BrettEBowman]

I discovered that the addon keeps uploading and then deleting the same backup over and over every 5 minutes.

04/13/2024 18:33:22 [10] Info: Found 1 backups to upload.
04/13/2024 18:33:22 [10] Verbose: Backup size to upload: 0.42GB
04/13/2024 18:33:22 [10] Info: Uploading hass_backup_msp_2024-03-14-21-18 (03/14/2024 21:18:34)
04/13/2024 18:33:22 [10] Info: Fetching Local Backup (Slug:9942b6c5)

04/13/2024 18:34:05 [15] Verbose: Found 4 OneDrive backups that can be removed (Generational Rules)
04/13/2024 18:34:05 [15] Verbose: Potential OneDrive backups for removal: 9942b6c5 (03/14/2024 21:18:34),ee47893a (03/15/2024 21:21:22),b59bac42 (03/16/2024 21:24:00),aa5b4367 (04/11/2024 18:51:05)
04/13/2024 18:34:05 [15] Info: Reached Max Online Backups (6)
04/13/2024 18:34:05 [15] Info: Found 1 backups to delete from OneDrive.
04/13/2024 18:34:05 [15] Info: Deleting item: hass_backup_msp_2024-03-14-21-18.HA_MSP.tar

I don't understand why it keeps thinking that it needs to re-upload the 2024-03-14-21-18 backup file every 5 minutes. I've attached a verbose log file and the settings screen. OneDriveBackup.log OneDriveBackupSettings.pdf

[lavinir]

Thanks for sharing. I think this is an issue with the existing logic for which local backups to upload conflicting with the Generational Backup rules. I will open a bug to investigate this.

[github-actions[bot]]

This issue is stale because it has been open for 30 days with no activity.

[BrettEBowman]

I just re-enabled the add-on (to upload current backup to OneDrive) and verified that I'm still having this problem.

[lavinir]

Yes that is just a automated tagging. This is a bug I still need to fix, just a bit busy with work last few weeks but this will be addressed in the next update.

[github-actions[bot]]

This issue is stale because it has been open for 30 days with no activity.

[deviantintegral]

I'm also seeing this. I think it started happening after more than 4 weeks had passed since setting up generational backups. While I've had that setting since I upgraded (at least several weeks ago), my outbound traffic graphs only show a spike in the last week.

Here's the settings I had in case it helps.

[lavinir]

@deviantintegral I'm not sure if this is the reason or not (you can certainly confirm with the logs) but I am aware of the potential issue here, just have not gotten to publishing a fix for this yet. It's coming.

[deviantintegral]

Yes, I did confirm with the logs. And take your time - this is a great set of work and it's appreciated!

[alexbeer2048]

I'm having the same or a closely related issue. The HA core backup (1.3 GB!!) is uploaded at 10-minute intervals. After observing the bandwidth usage, GUI, logs, and files on OneDrive for a while, I found something interesting that might be helpful in resolving this.

It seems that the file picked for uploading is a different one every 10 minutes. Both files are partial HA core backups. Why there are two, I'm not sure; one was probably created during update.

Both files are uploaded to OneDrive using the same filename, so I guess the sync method always detects a change and then re-uploads the file, overwriting the other version of the file from before, and so on. Not sure if this is relevant, but in the GUI, the two backups switch places every 10 minutes.

Some images: A few moments later ... (10 minutes) This changes back and forth, so 10 minutes later it's back to the first and so on.

On OneDrive it looks like this and every 10 minutes the first file gets modified

Backup folder

07/07/2024 15:50:58 [16] Info: Starting file upload. (Size:1378590720 bytes. Attempt: 1/3)
07/07/2024 15:56:25 [16] Info: Upload completed successfully
07/07/2024 16:00:54 [18] Info: Found 1 backups to upload.
07/07/2024 16:00:54 [18] Info: Uploading core_2024.7.0 (07/06/2024 23:35:48)
07/07/2024 16:00:54 [18] Info: Fetching Local Backup (Slug:e35de7ea)
07/07/2024 16:00:56 [28] Info: Backup (e35de7ea) fetched successfully
07/07/2024 16:00:59 [28] Info: Starting file upload. (Size:1378734080 bytes. Attempt: 1/3)
07/07/2024 16:06:16 [30] Info: Upload completed successfully
07/07/2024 16:10:56 [20] Info: Found 1 backups to upload.
07/07/2024 16:10:56 [28] Info: Uploading core_2024.7.0 (07/06/2024 23:05:36)
07/07/2024 16:10:56 [28] Info: Fetching Local Backup (Slug:a02456ff)
07/07/2024 16:10:58 [22] Info: Backup (a02456ff) fetched successfully
07/07/2024 16:11:01 [22] Info: Starting file upload. (Size:1378590720 bytes. Attempt: 1/3)
07/07/2024 16:16:25 [30] Info: Upload completed successfully
07/07/2024 16:20:57 [25] Info: Found 1 backups to upload.
07/07/2024 16:20:57 [6] Info: Uploading core_2024.7.0 (07/06/2024 23:35:48)
07/07/2024 16:20:57 [6] Info: Fetching Local Backup (Slug:e35de7ea)
07/07/2024 16:20:59 [35] Info: Backup (e35de7ea) fetched successfully
07/07/2024 16:21:02 [14] Info: Starting file upload. (Size:1378734080 bytes. Attempt: 1/3)
07/07/2024 16:26:34 [17] Info: Upload completed successfully
07/07/2024 16:30:59 [35] Info: Found 1 backups to upload.
07/07/2024 16:30:59 [35] Info: Uploading core_2024.7.0 (07/06/2024 23:05:36)
07/07/2024 16:30:59 [35] Info: Fetching Local Backup (Slug:a02456ff)
07/07/2024 16:31:01 [29] Info: Backup (a02456ff) fetched successfully
07/07/2024 16:31:03 [29] Info: Starting file upload. (Size:1378590720 bytes. Attempt: 1/3)
07/07/2024 16:36:23 [20] Info: Upload completed successfully
07/07/2024 16:41:00 [21] Info: Found 1 backups to upload.
07/07/2024 16:41:00 [23] Info: Uploading core_2024.7.0 (07/06/2024 23:35:48)
07/07/2024 16:41:00 [23] Info: Fetching Local Backup (Slug:e35de7ea)
07/07/2024 16:41:02 [18] Info: Backup (e35de7ea) fetched successfully

In the log you can see that the backups e35de7ea and a02456ff are uploaded alternatingly; same filename though core_2024.7.0.rpi5.tar

[lavinir]

Thanks @alexbeer2048 I'm not sure yours is the same issue. Referencing / mixing up two backups is very strange. I think something might be corrupted there. Could you try deleting that backup (copying it over somewhere else if needed) and see if you still encounter any of these issues ?

[github-actions[bot]]

This issue is stale because it has been open for 30 days with no activity.

[deviantintegral]

Still an issue! There a label that can be added to silence the stale bot?

[lavinir]

Don't worry about the bot, I know it's taking a while but the fix will be part of the next update.

[alexbeer2048]

Thanks @alexbeer2048 I'm not sure yours is the same issue. Referencing / mixing up two backups is very strange. I think something might be corrupted there. Could you try deleting that backup (copying it over somewhere else if needed) and see if you still encounter any of these issues ?

@lavinir Sorry for the delayed response. The issue eventually disappeared when a new update for the core module was installed, and the older backups were deleted locally.

However, I now recall something that might still be helpful. I believe there were two backups of the core module because an error occurred during the first attempt to update the module (due to a lost internet connection or something similar) but the backup has already been created. At the second attempt the update succeeded and, as expected, again a backup was created.

While a failed update isn't something very common in HA, it's also not unusual. My theory is that onedrive-backup doesn't treat the two backups as separate because they were from the same module, the same version, and created on the same day. Or at least the resulting filename used for the cloud backup were identical, and there is no check to see if filenames overlap.

As a result, it kept uploading both files, but each time it would overwrite the previously uploaded backup from the other file. This caused the job to never complete, as one backup was always missing at the end.

If my theory is correct, two potential solutions come to mind:

1. Include a few digits of a hash in the cloud filename (e.g. from the filename in the file system which conveniently already is a hash -> e35~~de7ea.tar~~ )
2. Or check if such filename overlaps occur, and in that case, ignore the older files entirely

[github-actions[bot]]

This issue is stale because it has been open for 30 days with no activity.