Hello,
It looks like cleanup phase doesn’t remove old incremental (and maybe full) correctly since upgrading from 2.3 to 2.4 :
Debian 9 / urbackup 2.4.11 / zfs 0.7.12-2
Here’s the urbackupsrv -u root remove-unknown
output :
2019-12-12 14:00:40: Going to remove all unknown files and directories in the urbackup storage directory. Waiting 20 seconds…
2019-12-12 14:01:00: Shutting down all database instances…
2019-12-12 14:01:00: Opening urbackup server database…
2019-12-12 14:01:00: Testing if backup destination can handle subvolumes and snapshots…
Testing for btrfs…
ERROR: not a btrfs filesystem: /media/backups/testA54hj5luZtlorr494
TEST FAILED: Creating test btrfs subvolume failed
Testing for zfs…
ZFS TEST OK
2019-12-12 14:01:01: Backup destination does handle subvolumes and snapshots. Snapshots enabled for image backups.
2019-12-12 14:01:01: Cleaning up 0 percent
2019-12-12 14:01:01: Cleaning up 0 bytes on backup storage
2019-12-12 14:01:01: Database cache size is 200 MB
2019-12-12 14:01:01: Starting cleanup…
2019-12-12 14:01:01: Freeing database connections…
2019-12-12 14:01:01: Enough free space now.
2019-12-12 14:01:01: Enough free space now.
2019-12-12 14:01:01: Client with id=28 has 6 full image backups max=6
2019-12-12 14:01:01: Client with id=28 has 13 incremental image backups max=5
2019-12-12 14:01:01: Deleting incremental image backup ( id=18697, backuptime=2019-11-25 21:34:55, path=/media/backups/SV407/191125-2234_Image_G/Image_G_191125-2234.raw, letter=G: ) from client “SV407” ( id=28 ) …
2019-12-12 14:01:01: Deleting image backup ( id=18697, path=/media/backups/SV407/191125-2234_Image_G/Image_G_191125-2234.raw ) …
Destroying subvol backups/images/SV407/191125-2234_Image_G failed. Promoting dependencies…
Searching for origin backups/images/SV407/191125-2234_Image_G@191125-2234_Image_G
Origin is backups/images/SV407/191127-0101_Image_G
2019-12-12 14:01:03: Client with id=26 has 6 full image backups max=6
2019-12-12 14:01:03: Client with id=26 has 13 incremental image backups max=5
2019-12-12 14:01:03: Deleting incremental image backup ( id=18706, backuptime=2019-11-26 00:21:19, path=/media/backups/SV403/191126-0121_Image_G/Image_G_191126-0121.raw, letter=G: ) from client “SV403” ( id=26 ) …
2019-12-12 14:01:03: Deleting image backup ( id=18706, path=/media/backups/SV403/191126-0121_Image_G/Image_G_191126-0121.raw ) …
Destroying subvol backups/images/SV403/191126-0121_Image_G failed. Promoting dependencies…
Searching for origin backups/images/SV403/191126-0121_Image_G@191126-0121_Image_G
Origin is backups/images/SV403/191126-2234_Image_G
2019-12-12 14:01:05: Client with id=30 has 6 full image backups max=6
2019-12-12 14:01:05: Client with id=30 has 13 incremental image backups max=5
2019-12-12 14:01:05: Deleting incremental image backup ( id=18691, backuptime=2019-11-25 21:30:47, path=/media/backups/SV413/191125-2230_Image_G/Image_G_191125-2230.raw, letter=G: ) from client “SV413” ( id=30 ) …
2019-12-12 14:01:05: Deleting image backup ( id=18691, path=/media/backups/SV413/191125-2230_Image_G/Image_G_191125-2230.raw ) …
Destroying subvol backups/images/SV413/191125-2230_Image_G failed. Promoting dependencies…
Searching for origin backups/images/SV413/191125-2230_Image_G@191125-2230_Image_G
Origin is backups/images/SV413/191126-2234_Image_G
2019-12-12 14:01:07: Client with id=29 has 6 full image backups max=6
2019-12-12 14:01:07: Client with id=29 has 13 incremental image backups max=5
2019-12-12 14:01:07: Deleting incremental image backup ( id=18695, backuptime=2019-11-25 21:34:53, path=/media/backups/SV409/191125-2234_Image_G/Image_G_191125-2234.raw, letter=G: ) from client “SV409” ( id=29 ) …
2019-12-12 14:01:07: Deleting image backup ( id=18695, path=/media/backups/SV409/191125-2234_Image_G/Image_G_191125-2234.raw ) …
Destroying subvol backups/images/SV409/191125-2234_Image_G failed. Promoting dependencies…
Searching for origin backups/images/SV409/191125-2234_Image_G@191125-2234_Image_G
Origin is backups/images/SV409/191126-2234_Image_G
2019-12-12 14:01:09: Client with id=27 has 6 full image backups max=6
2019-12-12 14:01:09: Client with id=27 has 13 incremental image backups max=5
2019-12-12 14:01:09: Deleting incremental image backup ( id=18696, backuptime=2019-11-25 21:34:54, path=/media/backups/SV405/191125-2234_Image_G/Image_G_191125-2234.raw, letter=G: ) from client “SV405” ( id=27 ) …
2019-12-12 14:01:09: Deleting image backup ( id=18696, path=/media/backups/SV405/191125-2234_Image_G/Image_G_191125-2234.raw ) …
Destroying subvol backups/images/SV405/191125-2234_Image_G failed. Promoting dependencies…
Searching for origin backups/images/SV405/191125-2234_Image_G@191125-2234_Image_G
Origin is backups/images/SV405/191126-2230_Image_G
2019-12-12 14:01:12: Client with id=31 has 1 full image backups max=6
2019-12-12 14:01:12: Client with id=31 has 0 incremental image backups max=5
2019-12-12 14:01:12: Deleting old logs…
2019-12-12 14:01:12: Done deleting old logs
2019-12-12 14:01:12: Cleaning history…
2019-12-12 14:01:12: Rewriting daily history…
2019-12-12 14:01:12: Reading history…
2019-12-12 14:01:12: 295 history items read
2019-12-12 14:01:12: Deleting history…
2019-12-12 14:01:12: Writing history…
2019-12-12 14:01:12: Rewriting monthly history…
2019-12-12 14:01:12: Reading history…
2019-12-12 14:01:12: 120 history items read
2019-12-12 14:01:12: Deleting history…
2019-12-12 14:01:12: Writing history…
2019-12-12 14:01:12: Rewriting yearly history…
2019-12-12 14:01:12: Reading history…
2019-12-12 14:01:12: 5 history items read
2019-12-12 14:01:12: Deleting history…
2019-12-12 14:01:12: Writing history…
2019-12-12 14:01:12: Done cleaning history
2019-12-12 14:01:12: Cleaning deleted backups history…
2019-12-12 14:01:12: Done cleaning deleted backups history.
2019-12-12 14:01:12: Cleaning up client lists…
2019-12-12 14:01:12: Done cleaning up client lists.
2019-12-12 14:01:12: Cleaning up old client access tokens…
2019-12-12 14:01:12: Done cleaning up old client access tokens.
2019-12-12 14:01:12: Updating statistics…
2019-12-12 14:01:12: Updating image stats…
2019-12-12 14:01:12: Updating file statistics…
2019-12-12 14:01:12: Done updating statistics.
2019-12-12 14:01:12: Enough free space now.
2019-12-12 14:01:12: Cleanup successfull.
2019-12-12 14:01:12: Removing unknown for client “SV403”
2019-12-12 14:01:12: Removing unknown for client “SV405”
2019-12-12 14:01:12: Removing unknown for client “SV407”
2019-12-12 14:01:12: Removing unknown for client “SV409”
2019-12-12 14:01:12: Removing unknown for client “SV413”
2019-12-12 14:01:12: Removing unknown for client “SV417”
2019-12-12 14:01:12: Removing dangling file entries…
2019-12-12 14:01:12: Deleted 0 file entries
2019-12-12 14:01:12: Successfully removed all unknown files in backup directory.
Running again :
2019-12-12 14:03:04: Going to remove all unknown files and directories in the urbackup storage directory. Waiting 20 seconds…
2019-12-12 14:03:24: Shutting down all database instances…
2019-12-12 14:03:24: Opening urbackup server database…
2019-12-12 14:03:24: Testing if backup destination can handle subvolumes and snapshots…
Testing for btrfs…
ERROR: not a btrfs filesystem: /media/backups/testA54hj5luZtlorr494
TEST FAILED: Creating test btrfs subvolume failed
Testing for zfs…
ZFS TEST OK
2019-12-12 14:03:24: Backup destination does handle subvolumes and snapshots. Snapshots enabled for image backups.
2019-12-12 14:03:24: Cleaning up 0 percent
2019-12-12 14:03:24: Cleaning up 0 bytes on backup storage
2019-12-12 14:03:24: Database cache size is 200 MB
2019-12-12 14:03:24: Starting cleanup…
2019-12-12 14:03:24: Freeing database connections…
2019-12-12 14:03:24: Enough free space now.
2019-12-12 14:03:24: Enough free space now.
2019-12-12 14:03:24: Client with id=28 has 6 full image backups max=6
2019-12-12 14:03:24: Client with id=28 has 12 incremental image backups max=5
2019-12-12 14:03:24: Deleting incremental image backup ( id=18726, backuptime=2019-11-27 00:01:56, path=/media/backups/SV407/191127-0108_Image_C/Image_C_191127-0108.raw, letter=C: ) from client “SV407” ( id=28 ) …
2019-12-12 14:03:24: Deleting image backup ( id=18725, path=/media/backups/SV407/191127-0102_Image_SYSVOL/Image_SYSVOL_191127-0102.raw ) …
2019-12-12 14:03:25: Deleting image backup ( id=18726, path=/media/backups/SV407/191127-0108_Image_C/Image_C_191127-0108.raw ) …
Destroying subvol backups/images/SV407/191127-0108_Image_C failed. Promoting dependencies…
Searching for origin backups/images/SV407/191127-0108_Image_C@191127-0108_Image_C
Origin is backups/images/SV407/191127-2236_Image_C
2019-12-12 14:03:28: Client with id=26 has 6 full image backups max=6
2019-12-12 14:03:28: Client with id=26 has 12 incremental image backups max=5
2019-12-12 14:03:28: Deleting incremental image backup ( id=18721, backuptime=2019-11-26 21:34:31, path=/media/backups/SV403/191126-2240_Image_C/Image_C_191126-2240.raw, letter=C: ) from client “SV403” ( id=26 ) …
2019-12-12 14:03:28: Deleting image backup ( id=18718, path=/media/backups/SV403/191126-2235_Image_SYSVOL/Image_SYSVOL_191126-2235.raw ) …
2019-12-12 14:03:29: Deleting image backup ( id=18721, path=/media/backups/SV403/191126-2240_Image_C/Image_C_191126-2240.raw ) …
Destroying subvol backups/images/SV403/191126-2240_Image_C failed. Promoting dependencies…
Searching for origin backups/images/SV403/191126-2240_Image_C@191126-2240_Image_C
Origin is backups/images/SV403/191127-2236_Image_C
2019-12-12 14:03:32: Client with id=30 has 6 full image backups max=6
2019-12-12 14:03:32: Client with id=30 has 12 incremental image backups max=5
2019-12-12 14:03:32: Deleting incremental image backup ( id=18719, backuptime=2019-11-26 21:34:00, path=/media/backups/SV413/191126-2238_Image_C/Image_C_191126-2238.raw, letter=C: ) from client “SV413” ( id=30 ) …
2019-12-12 14:03:32: Deleting image backup ( id=18715, path=/media/backups/SV413/191126-2235_Image_SYSVOL/Image_SYSVOL_191126-2235.raw ) …
2019-12-12 14:03:32: Deleting image backup ( id=18719, path=/media/backups/SV413/191126-2238_Image_C/Image_C_191126-2238.raw ) …
Destroying subvol backups/images/SV413/191126-2238_Image_C failed. Promoting dependencies…
Searching for origin backups/images/SV413/191126-2238_Image_C@191126-2238_Image_C
Origin is backups/images/SV413/191127-2238_Image_C
2019-12-12 14:03:35: Client with id=29 has 6 full image backups max=6
2019-12-12 14:03:35: Client with id=29 has 12 incremental image backups max=5
2019-12-12 14:03:35: Deleting incremental image backup ( id=18723, backuptime=2019-11-26 21:34:31, path=/media/backups/SV409/191126-2245_Image_C/Image_C_191126-2245.raw, letter=C: ) from client “SV409” ( id=29 ) …
2019-12-12 14:03:35: Deleting image backup ( id=18717, path=/media/backups/SV409/191126-2235_Image_SYSVOL/Image_SYSVOL_191126-2235.raw ) …
2019-12-12 14:03:36: Deleting image backup ( id=18723, path=/media/backups/SV409/191126-2245_Image_C/Image_C_191126-2245.raw ) …
Destroying subvol backups/images/SV409/191126-2245_Image_C failed. Promoting dependencies…
Searching for origin backups/images/SV409/191126-2245_Image_C@191126-2245_Image_C
Origin is backups/images/SV409/191127-2246_Image_C
2019-12-12 14:03:39: Client with id=27 has 6 full image backups max=6
2019-12-12 14:03:39: Client with id=27 has 12 incremental image backups max=5
2019-12-12 14:03:39: Deleting incremental image backup ( id=18722, backuptime=2019-11-26 21:30:04, path=/media/backups/SV405/191126-2241_Image_C/Image_C_191126-2241.raw, letter=C: ) from client “SV405” ( id=27 ) …
2019-12-12 14:03:39: Deleting image backup ( id=18710, path=/media/backups/SV405/191126-2231_Image_SYSVOL/Image_SYSVOL_191126-2231.raw ) …
2019-12-12 14:03:40: Deleting image backup ( id=18722, path=/media/backups/SV405/191126-2241_Image_C/Image_C_191126-2241.raw ) …
Destroying subvol backups/images/SV405/191126-2241_Image_C failed. Promoting dependencies…
Searching for origin backups/images/SV405/191126-2241_Image_C@191126-2241_Image_C
Origin is backups/images/SV405/191127-2241_Image_C
2019-12-12 14:03:42: Client with id=31 has 1 full image backups max=6
2019-12-12 14:03:42: Client with id=31 has 0 incremental image backups max=5
2019-12-12 14:03:42: Deleting old logs…
2019-12-12 14:03:42: Done deleting old logs
2019-12-12 14:03:42: Cleaning history…
2019-12-12 14:03:42: Rewriting daily history…
2019-12-12 14:03:42: Reading history…
2019-12-12 14:03:42: 295 history items read
2019-12-12 14:03:42: Deleting history…
2019-12-12 14:03:42: Writing history…
2019-12-12 14:03:42: Rewriting monthly history…
2019-12-12 14:03:42: Reading history…
2019-12-12 14:03:42: 120 history items read
2019-12-12 14:03:42: Deleting history…
2019-12-12 14:03:42: Writing history…
2019-12-12 14:03:42: Rewriting yearly history…
2019-12-12 14:03:42: Reading history…
2019-12-12 14:03:42: 5 history items read
2019-12-12 14:03:42: Deleting history…
2019-12-12 14:03:42: Writing history…
2019-12-12 14:03:43: Done cleaning history
2019-12-12 14:03:43: Cleaning deleted backups history…
2019-12-12 14:03:43: Done cleaning deleted backups history.
2019-12-12 14:03:43: Cleaning up client lists…
2019-12-12 14:03:43: Done cleaning up client lists.
2019-12-12 14:03:43: Cleaning up old client access tokens…
2019-12-12 14:03:43: Done cleaning up old client access tokens.
2019-12-12 14:03:43: Updating statistics…
2019-12-12 14:03:43: Updating image stats…
2019-12-12 14:03:43: Updating file statistics…
2019-12-12 14:03:43: Done updating statistics.
2019-12-12 14:03:43: Enough free space now.
2019-12-12 14:03:43: Cleanup successfull.
2019-12-12 14:03:43: Removing unknown for client “SV403”
2019-12-12 14:03:43: Removing unknown for client “SV405”
2019-12-12 14:03:43: Removing unknown for client “SV407”
2019-12-12 14:03:43: Removing unknown for client “SV409”
2019-12-12 14:03:43: Removing unknown for client “SV413”
2019-12-12 14:03:43: Removing unknown for client “SV417”
2019-12-12 14:03:43: Removing dangling file entries…
2019-12-12 14:03:43: Deleted 0 file entries
2019-12-12 14:03:43: Successfully removed all unknown files in backup directory.
It looks like a bug which make it processed volume per volume at once only …
Best regards,