Unproper cleaning of .directory pool

orogor · February 3, 2018, 10:01pm

Got a few hundred of them, so apparently it s cleaning too much

2018-02-03 22:50:52: ERROR: Error opening file "/data/urbackup2/pascalou/171009-2223/mame/snap/ws89.png"

ls -l  "/data/urbackup2/pascalou/171009-2223/mame/snap/ws89.png"
ls: cannot access '/data/urbackup2/pascalou/171009-2223/mame/snap/ws89.png': No such file or directory

ls -l  "/data/urbackup2/pascalou/171009-2223/mame/snap"
lrwxrwxrwx 1 urbackup urbackup 75 Oct 21 21:19 /data/urbackup2/pascalou/171009-2223/mame/snap -> /data/urbackup2/pascalou/.directory_pool/Pc/PcnDBKPn0d150861354232735166256

ls -l  /data/urbackup2/pascalou/.directory_pool/Pc/PcnDBKPn0d150861354232735166256
ls: cannot access '/data/urbackup2/p    ascalou/.directory_pool/Pc/PcnDBKPn0d150861354232735166256': No such file or directory

In that case it s not the first or las which is missing

 ls -l /data/urbackup2/pascalou/*/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170217-1917/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170429-1704/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170430-1709/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170502-2146/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170503-2151/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170726-1405/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/170830-1716/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/171104-1723/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/171106-0022/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/171108-2248/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/171111-1246/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/171112-2117/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/171114-1942/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/180201-2203/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/180202-2212/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/180203-0853/mame/snap/ws89.png
-rwxr-x--- 12 urbackup urbackup 9836 Oct 16  2008 /data/urbackup2/pascalou/current/mame/snap/ws89.png

the color is missing , but the set of 3 symlink in the middle is broken
ls -ld /data/urbackup2/pascalou/*/mame/snap
drwxr-x— 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/170217-1917/mame/snap
lrwxrwxrwx 1 urbackup urbackup 75 Apr 16 2017 /data/urbackup2/pascalou/170429-1704/mame/snap -> /data/urbackup2/pascalou/.directory_pool/Sa/SaDGEet7wJ149233821616459840917
lrwxrwxrwx 1 urbackup urbackup 75 Apr 16 2017 /data/urbackup2/pascalou/170430-1709/mame/snap -> /data/urbackup2/pascalou/.directory_pool/Sa/SaDGEet7wJ149233821616459840917
drwxr-x— 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/170502-2146/mame/snap
drwxr-x— 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/170503-2151/mame/snap
drwxr-x— 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/170726-1405/mame/snap
drwxr-x— 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/170830-1716/mame/snap
lrwxrwxrwx 1 urbackup urbackup 75 Oct 21 21:19 /data/urbackup2/pascalou/171009-2223/mame/snap -> /data/urbackup2/pascalou/.directory_pool/Pc/PcnDBKPn0d150861354232735166256
lrwxrwxrwx 1 urbackup urbackup 75 Oct 21 21:19 /data/urbackup2/pascalou/171012-0957/mame/snap -> /data/urbackup2/pascalou/.directory_pool/Pc/PcnDBKPn0d150861354232735166256
lrwxrwxrwx 1 urbackup urbackup 75 Oct 21 21:19 /data/urbackup2/pascalou/171016-1426/mame/snap -> /data/urbackup2/pascalou/.directory_pool/Pc/PcnDBKPn0d150861354232735166256
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/171104-1723/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/171106-0022/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/171108-2248/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/171111-1246/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/171112-2117/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/171114-1942/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/180201-2203/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/180202-2212/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/180203-0853/mame/snap
drwx------ 2 urbackup urbackup 3796 Sep 15 2015 /data/urbackup2/pascalou/current/mame/snap

#=================================#
2018-02-03 23:01:30: ERROR: Error opening file “/data/urbackup2/pascalou/171009-2223/.symlink_/etc/lvm/archive/vg-system_00045-1167515360.vg”

ls -l "/data/urbackup2/pascalou/171009-2223/.symlink_/etc/lvm/archive/vg-system_00045-1167515360.vg"
ls: cannot access '/data/urbackup2/pascalou/171009-2223/.symlink_/etc/lvm/archive/vg-system_00045-1167515360.vg': No such file or directory

ls -l "/data/urbackup2/pascalou/171009-2223/.symlink_/etc/lvm/archive"
lrwxrwxrwx 1 urbackup urbackup 75 Oct 21 19:08 /data/urbackup2/pascalou/171009-2223/.symlink_/etc/lvm/archive -> /data/urbackup2/pascalou/.directory_pool/Tz/Tzm2NsKUwq150860570232727326683

ls -l  /data/urbackup2/pascalou/.directory_pool/Tz/Tzm2NsKUwq150860570232727326683
ls: cannot access '/data/urbackup2/pascalou/.directory_pool/Tz/Tzm2NsKUwq150860570232727326683': No such file or directory

uroni · February 4, 2018, 10:55am

If you have a snapshot from before remove_unknown could you have a look if it wasn’t already broken before? (for a few of them) You had a post here in the forums a while ago where there were already broken backups.

And yes, with a log of remove_unknown you could have a look at the log with the pool id (something like PcnDBKPn0d150861354232735166256) to see if it was deleted by remove_unknown.

orogor · February 4, 2018, 12:24pm

Don’t have the snapshot either. I’ve been way too sloppy on this.

I saved the console output for verify hashes and remove unknown, so it s about 2000 lines for each.
That wasn’t that much interesting. considering i dont have the logs or snapshot to compare.
I looped throught the folder deleted by the the remove unknown that were still in the log s, and couldn’t find an occurrence of them in the verify hashes logs (that may due a lot to not enough logs to do the matching … or not).

However what’s interesting is that i searched for broken symlinks, there s only 2 types of them :
.symlink_void_file and .symlink_void_dir.
Symlinks in the directory pool that point to another directory pool folder.

These kinds of symlinks always match this in the remove-unknown logs : adding a reference, then missing folder

broken symlink :
lrwxrwxrwx 1 urbackup urbackup 81 Oct 13 09:57 ./pascalou[home]/.directory_pool/YN/YNPZ4eEDZj150779477131916395150/bpy1ky4i.default/ImapMail/imap.laposte.net/projects.sbd -> /data/urbackup2/pascalou[home]/.directory_pool/qQ/qQzQTHM4Lf150788142932003053611

remove unknown logs
2018-02-02 19:17:57: WARNING: Adding missing directory reference of pool qQzQTHM4Lf150788142932003053611 to “/data/urbackup2/pascalou[home]/171011-0942/.hashes/home/orogor/.thunderbird/bpy1ky4i.default/ImapMail/imap.laposte.net/projects.sbd”
2018-02-02 19:17:57: ERROR: Cannot open “/data/urbackup2/pascalou[home]/.directory_pool/qQ/qQzQTHM4Lf150788142932003053611”: No such file or directory (2)

So far i canceled the verify hash , the find command for broken link is still running, but i coudn’t match it to something deleted by remove unknown

orogor · February 4, 2018, 1:47pm

Ok , canceled the search for broken links, couldn t find one which matched a pool deleted by remove unknown

uroni · February 4, 2018, 2:17pm

Ok, so I think the new remove unknown didn’t break anything and the new version probably has a fix such that the corruption should not occur again (with new backups).

orogor · February 4, 2018, 2:51pm

Ok, currenty installing a vm, will see if i can corrupt them with test files, if anything happens that’ll be esier to reproduce.