Purging of old backup - Simple cut-off is not happening

[Daniel Mladek]

Hi there,

our Simple Backup Suite is not simply purging old backups. That how simple the description of the issue we're having with SBackup could be.

I spent a few hours researching on the internet if it is known issue, and only indication could be that the backup destination is not native linux FS (it's NTFS in fact), and only a couple of previously reported issues: 126278, 71698 - both issues have been already closed.

DETAILED DESCRIPTION
++++++++++++++++++++
We have "Ubuntu Trusty 14.04.5 LTS" as a build server for our Android projects.
(This version is mandated by AOSP requirements (https://source.android.com/setup/build/requirements).

We have SBackup Suite for Admins configured in place and scheduled to perform:
 a full backup at least once every 7 days
 using GZIP as compression format

Schedule: Custom: 0 22 * * *

With a purging enabled for:
 Simple cut-off: Erase all backup older than 10 days.

Destination is a mounted USB drive (NTFS unfortunately): /mnt/backups_and_builds/git_backup
/dev/sda1 on /mnt/backups_and_builds type fuseblk (rw,nosuid,nodev,allow_other,default_permissions,blksize=4096)

   Device Boot Start End Blocks Id System
/dev/sda1 2048 3907024895 1953511424 7 HPFS/NTFS/exFAT

Yesterday's full backup failed (again) due to insufficient space on the disk.
2018-05-09 22:14:04,142 - INFO: Summary of backup
2018-05-09 22:14:04,142 - INFO: Number of directories: 106424.
2018-05-09 22:14:04,143 - INFO: Total number of files: 8231456.
2018-05-09 22:14:04,143 - INFO: Number of symlinks: 7094.
2018-05-09 22:14:04,143 - INFO: Number of files included in snapshot: 8231456.
2018-05-09 22:14:04,144 - INFO: Number of new files (also included): 0.
2018-05-09 22:14:04,144 - INFO: Number of files skipped in incremental snapshot: 0.
2018-05-09 22:14:04,145 - INFO: Number of items forced to be excluded: 6.
2018-05-09 22:14:04,145 - INFO: Number of items to be excluded by config: 0.
2018-05-09 22:14:04,145 - INFO: Maximum free size required is '310748 MiB 735 KiB 593'.
2018-05-09 22:14:04,146 - INFO: Available disk size is '82248 MiB 268 KiB'.
2018-05-09 22:14:04,146 - ERROR: An error occurred during the backup: Not enough free space in the target directory for the planned backup (free: 82248 MiB 268 KiB, required: 310748 MiB 735 KiB 593).

The reason why there was no space left on the disk is that purging of old backups doesn't work as the list of old backup reached 15:
xxxxx@mcs-Ubuntu:~$ ll /mnt/backups_and_builds/git_backup/
total 1560
drwxrwxrwx 1 root root 1536000 May 9 22:00 ./
drwxrwxrwx 1 root root 4096 Apr 22 21:21 ../
drwx------ 1 root root 4096 Apr 26 03:22 2018-04-25_22.00.11.927348.mcs-Ubuntu.ful/
drwx------ 1 root root 4096 Apr 26 23:32 2018-04-26_22.00.08.250440.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 Apr 27 23:25 2018-04-27_22.00.07.487993.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 Apr 28 23:25 2018-04-28_22.00.08.383888.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 Apr 29 23:28 2018-04-29_22.00.06.820683.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 Apr 30 23:30 2018-04-30_22.00.08.240341.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 1 23:39 2018-05-01_22.00.08.232810.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 3 03:43 2018-05-02_22.00.07.980758.mcs-Ubuntu.ful/
drwx------ 1 root root 4096 May 3 23:48 2018-05-03_22.00.07.042217.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 4 23:26 2018-05-04_22.00.08.945832.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 5 23:25 2018-05-05_22.00.07.219102.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 6 23:26 2018-05-06_22.00.08.145880.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 7 23:27 2018-05-07_22.00.08.746766.mcs-Ubuntu.inc/
drwx------ 1 root root 4096 May 8 23:29 2018-05-08_22.00.08.245251.mcs-Ubuntu.inc/
drwx------ 1 root root 0 May 9 22:14 2018-05-09_22.00.07.699726.mcs-Ubuntu.ful/
xxxxl@mcs-Ubuntu:~$ ls -Al /mnt/backups_and_builds/git_backup/|wc
     16 137 1254

Not sure what we are doing wrong, but either there must by some fuzzy conditional logic between the days of full backup and the number of old backup to keep, unfortunately this is not explained anywhere.
Or, as someone mentioned in a forum, that backing up to non linux FS could cause problems, then this is definitely the one, but again - I couldn't find it anywhere documented.

ACTUAL BEHAVIOUR
++++++++++++++++
None of the 15 existing backups has been deleted.
Not sure if an attempt was made (where to look for what kind of log?).

EXPECTED BEHAVIOUR
++++++++++++++++++
- For our configuration, expectation is that in the backup folder there will be left 10 old backups left (and 5 oldest be deleted), prior a backup is executed (or after, but it needs to be clear when from the documentation)
- after a new backup is created, there will be only 11 backups in the backup location maximum.

- Documentations better explains how Purging works and all the conditions which needs to be met for it to work (e.g. relationship between full, incremental backup and the number of days you'd like to keep your backup or min age of the backup snapshots (full or inc) to delete.
- The SBackup Suite can have the debug logging turned on (and documented) - dunno how to achieve that, so it can be troubleshoot why it didn't delete old backups.
- Simply, Simple Backup Suite does remove older backup then X amount of days specified in the Purging tab (or its config file)

ADDITIONAL REQUIRED INFO:
+++++++++++++++++++++++++
xxxx@mcs-Ubuntu:~$ lsb_release -rd
Description: Ubuntu 14.04.5 LTS
Release: 14.04

xxxxx@mcs-Ubuntu:~$ apt-cache policy sbackup
sbackup:
  Installed: 0.11.6-0ubuntu1
  Candidate: 0.11.6-0ubuntu1
  Version table:
 *** 0.11.6-0ubuntu1 0
        500 http://us.archive.ubuntu.com/ubuntu/ trusty/universe amd64 Packages
        100 /var/lib/dpkg/status

[Daniel Mladek (delphym)]

At the end of a sbackup.log there is a record that "Simple purge" has been attempted (without any status what it actually did):

2018-05-13 16:45:25,339 - INFO: Leading '/' from member names were removed.
2018-05-13 16:45:25,350 - INFO: TAR returned a message: Total bytes written: 370298880 (354MiB, 768KiB/s)
2018-05-13 16:45:25,351 - INFO: TAR has been finished successfully.
2018-05-13 16:45:30,078 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-13 16:45:30,082 - INFO: Simple purge - remove freestanding snapshots older than 10 days.
2018-05-13 16:45:30,177 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-13 16:45:30,181 - INFO: Backup process finished.
2018-05-13 16:45:30,186 - INFO: Terminating GIO File Access Manager.
2018-05-13 16:45:30,186 - INFO: Processing of profile successfully finished (no errors)

I was also wondering what is the definition of the "freestanding" snapshot...

[Daniel Mladek (delphym)]

To workaround this issue, I wrote a simple shell script located at:
https://gist.github.com/delphym/62e99ef7ba936879580c66c6a9685ef3#file-clean_old_backups-sh

Someone might find it helpful.

[Daniel Mladek (delphym)]

Interesting observation:
The last night I've change the value of *Simple cut-off:* from 10 to 7, so now it looks like:
Simple cut-off: Erase all backup older than 7 days.

The output of the sbackup in the log is also interesting:
2018-05-16 22:30:00,509 - INFO: TAR returned a message: Total bytes written: 372029440 (355MiB, 723KiB/s)
2018-05-16 22:30:00,509 - INFO: TAR has been finished successfully.
2018-05-16 22:30:05,150 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:05,155 - INFO: Simple purge - remove freestanding snapshots older than 7 days.
2018-05-16 22:30:05,497 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:05,644 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:05,914 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:06,084 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:06,195 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:06,346 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:09,212 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:09,222 - INFO: Corrupt snapshot `2018-05-09_22.00.07.699726.mcs-Ubuntu.corrupt` found. Skipped.
2018-05-16 22:30:09,227 - INFO: Backup process finished.
2018-05-16 22:30:09,235 - INFO: Terminating GIO File Access Manager.
2018-05-16 22:30:09,235 - INFO: Processing of profile successfully finished (no errors)

But the most interesting stuff is that it deleted some of the old backups.
Before this backup was executed there were:
#of ALL backups:15 #of CORRUPTED:1 #of FUL:2 #of INC:12
After this backup finished we have ended up with:
#of ALL backups:9 #of CORRUPTED:1 #of FULL:1 #of INC:7

Tha last scheduled backup created another INC backup, and then the purge triggered. It seems that there is some hidden fuzzy undescribed/undocumented logic for what that purge number means.
Definitely not the straightforward as it declares "erase all older than " $n "days".

[Oumar Aziz OUATTARA (wattazoum)]

Hi,

I was one of the main developers of Sbackup.
I have devoted myself to other projects for quite some time now (leaving sbackup to others).
Developers interested in this project come and go depending on their free time.
This explains the time it took for you to have and answer to your questions.

I want to praise you for the effort you put on analyzing the issue.

In your example, the way you expected Sbackup to work is to do the action described bellow:

2018-04-25_22.00.11.927348.mcs-Ubuntu.ful/ <------ CUTOFF
2018-04-26_22.00.08.250440.mcs-Ubuntu.inc/ <------ CUTOFF
2018-04-27_22.00.07.487993.mcs-Ubuntu.inc/ <------ CUTOFF
2018-04-28_22.00.08.383888.mcs-Ubuntu.inc/ <------ CUTOFF
2018-04-29_22.00.06.820683.mcs-Ubuntu.inc/ <------ CUTOFF
2018-04-30_22.00.08.240341.mcs-Ubuntu.inc/
2018-05-01_22.00.08.232810.mcs-Ubuntu.inc/
2018-05-02_22.00.07.980758.mcs-Ubuntu.ful/
2018-05-03_22.00.07.042217.mcs-Ubuntu.inc/
2018-05-04_22.00.08.945832.mcs-Ubuntu.inc/
2018-05-05_22.00.07.219102.mcs-Ubuntu.inc/
2018-05-06_22.00.08.145880.mcs-Ubuntu.inc/
2018-05-07_22.00.08.746766.mcs-Ubuntu.inc/
2018-05-08_22.00.08.245251.mcs-Ubuntu.inc/
2018-05-09_22.00.07.699726.mcs-Ubuntu.ful/

However, doing this would leave 2 *orphans backups*

2018-04-30_22.00.08.240341.mcs-Ubuntu.inc/
2018-05-01_22.00.08.232810.mcs-Ubuntu.inc/

What I call orphan backup here is a backup you would not be able to use (because you would not be able to revert a folder from it. Every Incremental backup has to have a parent (Full backup). So even with the Simple cutoff fonctionnality, we don't want you to lose the 2 incremental backups that would have been left on the disk. So Sbackup will only remove all the backups that are before the parent of the 2 inc backup.
This explain the situation you got.

I agree however that is not described in the documentation. I would welcome any suggestion on the way to describe it in a user friendly way.

[Daniel Mladek (delphym)]

Hi wattazoum,

Thank you so much for looking into this issue and explaining how the Sbackup works.

Well, I've slowly arrived to similar conclusion and yes, you're right about our configuration was kind of clashing.

(Just inherited how it was setup and my aim is to improve it). With no description/documentation it was a bit challenge to guess what would be the real behaviour of the "Simple cut-off" option. Frustrated, I based my understanding on the explicit name of the option even though I understand it would leave us with those orphants. Also, I'd rather have it working in more smarter and safer way, which seems it does....except keeps disk full.

You're right, my expectation would put the whole backup in the risk, OTOH I would know what to expect.

I'll try to come up with some wordings for the documentation and tooltips, as the behaviour seems to be alright. So, hopefully everyone could configure Sbackup in the right way.

Cheers,
-d

[Daniel Mladek (delphym)]

It's a bit tricky to come up with simple description. IMHO examples are the best way how to demonstrate the functionality, so, please find below what I would include in the documentation/help for the Simple Backup Suite.

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Purging
Is the instrument to keep your backup lean and prevents your data storage from overfilling in conjunction with your overall backup strategy. It's triggered at the end of a successful backup execution. The removal of old backups can be configured in two ways:
- Simple cut-off: Erase all backups older than "n" days.
  To prevent unwanted data lost in the case when using INCREMENTAL backups, Sbackup will only remove all the backups that are before the parent (FULL) of the INCREMENTAL (child) backups. In other words,
  the result of modulo operation of the "n" days and the frequency of FULL backup should be 0 to achieve desired effect.
  Example 1 (incorrect setting):
   Do FULL backup once every 7 days ("f"=7)
   Simple cut-off: Erase backups older than 10 days ("n"=10)
     n mod f = 3 ... which is NOT 0.
   In this case, only backups older then 14 days shall be purged (14 mod 7 = 0), because if it would done that simple cut-off, it would leave 2 INCREMENTAL (orphans) backups without their FULL (parent) backup
  2018-05-01.Ubuntu.ful/ <------ CUTOFF
  2018-05-02.Ubuntu.inc/ <------ CUTOFF
  2018-05-03.Ubuntu.inc/ <------ CUTOFF
  2018-05-04.Ubuntu.inc/ <------ CUTOFF
  2018-05-05.Ubuntu.inc/ <------ CUTOFF
  2018-05-06.Ubuntu.inc/
  2018-05-07.Ubuntu.inc/
  2018-05-08.Ubuntu.ful/
  2018-05-09.Ubuntu.inc/
  2018-05-10.Ubuntu.inc/
  2018-05-11.Ubuntu.inc/
  2018-05-12.Ubuntu.inc/
  2018-05-13.Ubuntu.inc/
  2018-05-14.Ubuntu.inc/
  2018-05-15.Ubuntu.ful/
  Example 2 (correct setup):
   Do FULL backup once every 7 days ("f"=7)
   Simple cut-off: Erase backups older than 7 days ("n"=7)
     n mod f = 0
   which means, in this case, it will keep backups up to 2 weeks. Once the 3rd FULL backup will be completed, it shall purge the backups from the 1st to 7th of May.
- Logarithmic
 ....as existing...
~~~~~~~~~~~~~~~~~~~~~~~~~~~
 as not sure again what it would be the behavior.
 Perhaps in the case of using INCREMENTAL backups, it should keep nearest FULL backup.