Silent skipping of file during xfsrestore

Silent skipping of file during xfsrestore

[Will Dormann]

Hi folks,

I recently did a restore of a xfsdump backup and I noticed that an
important file was missing after the restore completed.  I tried going
back in using interactive mode to see what was up:

-----

 -> ls /etc/mythtv
            4032 session-settings
         4127166 session-settings~
        50343916 config.xml
         4884092 mysql.txt~

 -> add /etc/mythtv

 -> extract

 --------------------------------- end dialog
---------------------------------

xfsrestore: mkdir etc
xfsrestore: mkdir etc/mythtv
xfsrestore: dump session label: ""
xfsrestore: dump session id: f132cc65-5bd4-4a58-a810-52398fe99326
xfsrestore: stream 0, object 0, file 0
xfsrestore: restoring non-directory files
xfsrestore: media file 0 in object 0 of stream 0
xfsrestore: restoring etc/mythtv/session-settings (4032 221708883)
xfsrestore: restoring regular file ino 4032 etc/mythtv/session-settings
xfsrestore: truncating etc/mythtv/session-settings from 0 to 1170
xfsrestore: restoring etc/mythtv/session-settings~ (4127166 4079738789)
xfsrestore: restoring regular file ino 4127166 etc/mythtv/session-settings~
xfsrestore: truncating etc/mythtv/session-settings~ from 0 to 1169
xfsrestore: restoring etc/mythtv/mysql.txt~ (4884092 1828724895)
xfsrestore: restoring regular file ino 4884092 etc/mythtv/mysql.txt~
xfsrestore: truncating etc/mythtv/mysql.txt~ from 0 to 99
xfsrestore: restore complete: 125 seconds elapsed
xfsrestore: Restore Status: SUCCESS
root@jerky:/mnt/rescue#


-----


Note that the file "config.xml" is present in the directory listing, but
when the restore completes with a SUCCESS status, that file is *not*
present.

My backup command is:
xfsdump -e -l0 - / | pigz > $backupdir/mythbuntu.dgz

My restore command is:
pigz -d -c mythbuntu.dgz | xfsrestore -p 10 -r - /mnt/restore


I don't see any special attributes set on /etc/mythtv/config.xml:
$ lsattr /etc/mythtv/config.xml
---------------- /etc/mythtv/config.xml

And even so, if a file is excluded, I'd figure that it wouldn't show up
in the xfsrestore directory listing, right?


So what can cause a file to silently be skipped during restore?   I'm
running the latest xfsdump/xfsrestore provided by Ubuntu 14.04, which is
3.1.1.   I notice the same symptoms from my recovery environment, which
is SystemRescueCD 4.2.0


Thanks!
-WD

Re: Silent skipping of file during xfsrestore

[Dave Chinner]

On Sun, Nov 27, 2016 at 08:49:13PM -0500, Will Dormann wrote:
> Hi folks,
> 
> I recently did a restore of a xfsdump backup and I noticed that an
> important file was missing after the restore completed.  I tried going
> back in using interactive mode to see what was up:
> 
> -----
> 
>  -> ls /etc/mythtv
>             4032 session-settings
>          4127166 session-settings~
>         50343916 config.xml
>          4884092 mysql.txt~
> 
>  -> add /etc/mythtv
> 
>  -> extract
> 
>  --------------------------------- end dialog
> ---------------------------------
> 
> xfsrestore: mkdir etc
> xfsrestore: mkdir etc/mythtv
> xfsrestore: dump session label: ""
> xfsrestore: dump session id: f132cc65-5bd4-4a58-a810-52398fe99326
> xfsrestore: stream 0, object 0, file 0
> xfsrestore: restoring non-directory files
> xfsrestore: media file 0 in object 0 of stream 0
> xfsrestore: restoring etc/mythtv/session-settings (4032 221708883)
> xfsrestore: restoring regular file ino 4032 etc/mythtv/session-settings
> xfsrestore: truncating etc/mythtv/session-settings from 0 to 1170
> xfsrestore: restoring etc/mythtv/session-settings~ (4127166 4079738789)
> xfsrestore: restoring regular file ino 4127166 etc/mythtv/session-settings~
> xfsrestore: truncating etc/mythtv/session-settings~ from 0 to 1169
> xfsrestore: restoring etc/mythtv/mysql.txt~ (4884092 1828724895)
> xfsrestore: restoring regular file ino 4884092 etc/mythtv/mysql.txt~
> xfsrestore: truncating etc/mythtv/mysql.txt~ from 0 to 99
> xfsrestore: restore complete: 125 seconds elapsed
> xfsrestore: Restore Status: SUCCESS
> root@jerky:/mnt/rescue#
> 
> 
> -----
> 
> 
> Note that the file "config.xml" is present in the directory listing, but
> when the restore completes with a SUCCESS status, that file is *not*
> present.
> 
> My backup command is:
> xfsdump -e -l0 - / | pigz > $backupdir/mythbuntu.dgz
> 
> My restore command is:
> pigz -d -c mythbuntu.dgz | xfsrestore -p 10 -r - /mnt/restore
> 
> 
> I don't see any special attributes set on /etc/mythtv/config.xml:
> $ lsattr /etc/mythtv/config.xml
> ---------------- /etc/mythtv/config.xml
> 
> And even so, if a file is excluded, I'd figure that it wouldn't show up
> in the xfsrestore directory listing, right?
> 
> 
> So what can cause a file to silently be skipped during restore?

Usually nothing. This is typical of xfsdump skipping a file due to
some unexpected occurrence during backup. It's in the dump
inventory as the directory was processed, but if somthing changed
during the dump process (e.g. file gets replaced due to atomic
overwrite via rename) then it may not end up being in the dump.

> I'm
> running the latest xfsdump/xfsrestore provided by Ubuntu 14.04, which is
> 3.1.1.   I notice the same symptoms from my recovery environment, which
> is SystemRescueCD 4.2.0

That's /old/. Try running the latest (3.1.6 IIRC) and see if that
fixes the issue.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: Silent skipping of file during xfsrestore

[Will Dormann]

Hi Dave,

On 11/27/16 8:59 PM, Dave Chinner wrote:
>> So what can cause a file to silently be skipped during restore?
> 
> Usually nothing. This is typical of xfsdump skipping a file due to
> some unexpected occurrence during backup. It's in the dump
> inventory as the directory was processed, but if somthing changed
> during the dump process (e.g. file gets replaced due to atomic
> overwrite via rename) then it may not end up being in the dump.

This file pretty much never gets written to after the first install of
the system, so I wouldn't suspect anything like that would have happened.


>> I'm
>> running the latest xfsdump/xfsrestore provided by Ubuntu 14.04, which is
>> 3.1.1.   I notice the same symptoms from my recovery environment, which
>> is SystemRescueCD 4.2.0
> 
> That's /old/. Try running the latest (3.1.6 IIRC) and see if that
> fixes the issue.


I tried running xfsrestore 3.1.6 on the existing 3.1.1 dump, and I got
the same symptoms:

---

 -> ls /etc/mythtv
            4032 session-settings
         4127166 session-settings~
        50343916 config.xml
         4884092 mysql.txt~

 -> add /etc/mythtv/config.xml

 -> extract

 --------------------------------- end dialog
---------------------------------

/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: mkdir etc
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: mkdir etc/mythtv
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: dump session label: ""
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: dump session id:
f132cc65-5bd4-4a58-a810-52398fe99326
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: stream 0, object 0, file 0
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: restoring non-directory files
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: media file 0 in object 0
of stream 0
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: restore complete: 207
seconds elapsed
/home/wd/in/xfsdump-3.1.6/restore/xfsrestore: Restore Status: SUCCESS



---

If the latest xfsrestore indicates that a file is in a backup, but then
doesn't actually restore it when asked, isn't that still indicative of a
problem?  That is, if xfsrestore indicates that a file is in a backup,
shouldn't it be restoring something?


I tried creating a new dump with 3.1.6, and subsequently restoring with
3.1.6, and it did succeed in restoring config.xml.

However, that may possibly have nothing to do with any sort of fix.
Because I couldn't restore config.xml when I did my system restore, I
had to create a new copy of it from a file-level backup.  Therefore, the
original problematic file isn't present anywhere other than my existing
xfsdump backups.



-WD

Re: Silent skipping of file during xfsrestore

[Dave Chinner]

On Mon, Nov 28, 2016 at 12:00:06AM -0500, Will Dormann wrote:
> Hi Dave,
> 
> On 11/27/16 8:59 PM, Dave Chinner wrote:
> >> So what can cause a file to silently be skipped during restore?
> > 
> > Usually nothing. This is typical of xfsdump skipping a file due to
> > some unexpected occurrence during backup. It's in the dump
> > inventory as the directory was processed, but if somthing changed
> > during the dump process (e.g. file gets replaced due to atomic
> > overwrite via rename) then it may not end up being in the dump.
> 
> This file pretty much never gets written to after the first install of
> the system, so I wouldn't suspect anything like that would have happened.
> 
> 
> >> I'm
> >> running the latest xfsdump/xfsrestore provided by Ubuntu 14.04, which is
> >> 3.1.1.   I notice the same symptoms from my recovery environment, which
> >> is SystemRescueCD 4.2.0
> > 
> > That's /old/. Try running the latest (3.1.6 IIRC) and see if that
> > fixes the issue.
> 
> 
> I tried running xfsrestore 3.1.6 on the existing 3.1.1 dump, and I got
> the same symptoms:

Yes, that's expected - the file is missing from the dump, indicating
a problem exncountered by xfsdump, not xfsrestore.

> If the latest xfsrestore indicates that a file is in a backup, but then
> doesn't actually restore it when asked, isn't that still indicative of a
> problem?  That is, if xfsrestore indicates that a file is in a backup,
> shouldn't it be restoring something?

I think you misunderstand how the inventory and dump process
works. The dump process first builds the inventory inode map that it
needs to back up, then goes and backs up what it mapped in the
inventory.  The filesystem can change between the inventory build
an dump trying to backup the file, and if the file does not match
the inventory for some reason (e.g. different inode generation
number) it will skip it. The file does not get removed from the
inventory, though, because that's already been written to the dump
file.

There have also been situations where kernel bugs have meant xfsdump
missed files. e.g. off-by-ones in bulkstat continuation code. These
bugs had identical symptoms to what you are reporting, but given a
new dump worked this is probably not the issue....

> I tried creating a new dump with 3.1.6, and subsequently restoring with
> 3.1.6, and it did succeed in restoring config.xml.

Yup, no surprise there, either.

> However, that may possibly have nothing to do with any sort of fix.
> Because I couldn't restore config.xml when I did my system restore, I
> had to create a new copy of it from a file-level backup.  Therefore, the
> original problematic file isn't present anywhere other than my existing
> xfsdump backups.

Yup, in general, problems with dump contents seen with xfs_restore
are most likely going to be a dump issue and can only be rectified
by running new backups.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: Silent skipping of file during xfsrestore

[Will Dormann]

On 11/28/16 3:21 AM, Dave Chinner wrote:
> I think you misunderstand how the inventory and dump process
> works. The dump process first builds the inventory inode map that it
> needs to back up, then goes and backs up what it mapped in the
> inventory.  The filesystem can change between the inventory build
> an dump trying to backup the file, and if the file does not match
> the inventory for some reason (e.g. different inode generation
> number) it will skip it. The file does not get removed from the
> inventory, though, because that's already been written to the dump
> file.


Got it.  Thanks.   At the end of the backup, wouldn't xfsdump know what
files were not able to be backed up, though?   In my case, I had a level
0 backup, and also a level 1 backup.   The problematic file wasn't
present / able-to-be-restored in either backup set.

That is, if somebody does a level 0 backup, and a file isn't properly
backed up for whatever reason, that file is flagged as "not backed up".
That would allow it to be subsequently backed up in a
higher-level-number backup.   Note that in my case, I tried restoring
from the most-recent level 1 backup, the most-recent level 0 backup, and
an older level 0 backup as well.  None were able to restore the file.

If this isn't possible, then I suspect that an xfsdump/xfsrestore of a
(running?) system perhaps isn't as robust as I had hoped.  In
particular, that you might not have all of the files that you need, but
you won't know until you actually go to use the system you restored.



Thanks
-WD

Re: Silent skipping of file during xfsrestore

[Dave Chinner]

On Mon, Nov 28, 2016 at 08:17:00AM -0500, Will Dormann wrote:
> On 11/28/16 3:21 AM, Dave Chinner wrote:
> > I think you misunderstand how the inventory and dump process
> > works. The dump process first builds the inventory inode map that it
> > needs to back up, then goes and backs up what it mapped in the
> > inventory.  The filesystem can change between the inventory build
> > an dump trying to backup the file, and if the file does not match
> > the inventory for some reason (e.g. different inode generation
> > number) it will skip it. The file does not get removed from the
> > inventory, though, because that's already been written to the dump
> > file.
> 
> 
> Got it.  Thanks.   At the end of the backup, wouldn't xfsdump know what
> files were not able to be backed up, though?   In my case, I had a level
> 0 backup, and also a level 1 backup.   The problematic file wasn't
> present / able-to-be-restored in either backup set.

In many cases, yes it does. Certain types of issues end up with
inodes being placed in the "orphanage" - this happens if dump finds
open but unlinked inodes that weren't unlinked at the time the inode
map was built. The orphange updates only occur if the inode can be
read - if it's completely gone, it is simply skipped and restore
doesn't care.

Remember - xfsdump was designed to write direct to tape media - it
effectively generates a write-once stream of information, so once it
is written it can't be rewritten. It's an unfortunate side effect
of this "tape algorithm" that we see all sorts of weird behaviours
and limitations when we come across unexpected states.

> That is, if somebody does a level 0 backup, and a file isn't properly
> backed up for whatever reason, that file is flagged as "not backed up".
> That would allow it to be subsequently backed up in a
> higher-level-number backup.   Note that in my case, I tried restoring
> from the most-recent level 1 backup, the most-recent level 0 backup, and
> an older level 0 backup as well.  None were able to restore the file.

If it was supposed to be in the level 0 dump, and it wasn't, then
unless it was modified again before the level 1 dump it won't be in
that dump file, either.

> If this isn't possible, then I suspect that an xfsdump/xfsrestore of a
> (running?) system perhaps isn't as robust as I had hoped. 

It has never been 100% robust when run on a live filesystem that is
being modified as the backup is running. If you want robust, exact
point in time backups, then snapshot the filesystem and run the
backup from the snapshot. Then remove the snapshot once the backup
completes....

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: Silent skipping of file during xfsrestore

[Will Dormann]

On 11/28/16 4:33 PM, Dave Chinner wrote:
> On Mon, Nov 28, 2016 at 08:17:00AM -0500, Will Dormann wrote:
>> If this isn't possible, then I suspect that an xfsdump/xfsrestore of a
>> (running?) system perhaps isn't as robust as I had hoped. 
> 
> It has never been 100% robust when run on a live filesystem that is
> being modified as the backup is running. If you want robust, exact
> point in time backups, then snapshot the filesystem and run the
> backup from the snapshot. Then remove the snapshot once the backup
> completes....


Good to know!  In the past I had done offline backups, but I had
eventually figured that xfsdump + mysqldump might get me what I want
without rebooting.

Given that I don't have any LVM to provide snapshots, the best bet may
be to have an offline backup for guaranteed, bare-metal restores.  And
xfsdump/mysqldump for more-handy online backups / restores.


Thanks for the help.


-WD

Re: Silent skipping of file during xfsrestore

[Will Dormann]

On 11/28/16 3:21 AM, Dave Chinner wrote:
> I think you misunderstand how the inventory and dump process
> works. The dump process first builds the inventory inode map that it
> needs to back up, then goes and backs up what it mapped in the
> inventory.  The filesystem can change between the inventory build
> an dump trying to backup the file, and if the file does not match
> the inventory for some reason (e.g. different inode generation
> number) it will skip it. The file does not get removed from the
> inventory, though, because that's already been written to the dump
> file.
> 
> There have also been situations where kernel bugs have meant xfsdump
> missed files. e.g. off-by-ones in bulkstat continuation code. These
> bugs had identical symptoms to what you are reporting, but given a
> new dump worked this is probably not the issue....


Another possible scenario that I'm wondering whether it's plausible:

My XFS filesystem was mildly corrupted (e.g. because of power failure or
other trouble).  But not in a way that was checked/noticed/corrected
automatically on system boot, or even had a noticeable effect on the
system other than the missing file on xfsrestore?

The system is back up and running, seemingly-fine.  But perhaps
obviously, my main concern here is to avoid this kind of scenario in the
future.   e.g., is there something I'm missing in my backup routine?
Silent failures on backup/restore are not very reassuring.



Thanks!
-WD

Re: Silent skipping of file during xfsrestore

[Eric Sandeen]

On 11/28/16 10:10 AM, Will Dormann wrote:

> Another possible scenario that I'm wondering whether it's plausible:
> 
> My XFS filesystem was mildly corrupted (e.g. because of power failure or
> other trouble).  But not in a way that was checked/noticed/corrected
> automatically on system boot, or even had a noticeable effect on the
> system other than the missing file on xfsrestore?

There is no explicit check on boot for xfs, so nothing would happen there.

If the fs were corrupted, it likely would have been noticed by the kernel
when xfsdump was traversing the filesystem.  If the filesystem didn't
shut down, and you didn't see anything in kernel messages, then there
is likely no corruption.  You could always unmount & check manually
w/ xfs_repair (possibly with -n) to confirm.

> The system is back up and running, seemingly-fine.  But perhaps
> obviously, my main concern here is to avoid this kind of scenario in the
> future.   e.g., is there something I'm missing in my backup routine?
> Silent failures on backup/restore are not very reassuring.

Can you check timestamps on the file to be sure that your assumption
that it's not getting written is correct?  I know cups likes to write
and rewrite config files even if no changes occur, for example.

-Eric

> 
> 
> Thanks!
> -WD
> --
> To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

Re: Silent skipping of file during xfsrestore

[Will Dormann]

On 11/28/16 11:32 AM, Eric Sandeen wrote:
> There is no explicit check on boot for xfs, so nothing would happen there.

Yeah, I thought that was the case.  Just wanted to make sure.


> Can you check timestamps on the file to be sure that your assumption
> that it's not getting written is correct?  I know cups likes to write
> and rewrite config files even if no changes occur, for example.

The problem is that I wiped the target partition clean before doing the
xfsrestore.   So the only copy that could be present anywhere is in the
xfsdump backups.    Is it possible to check the timestamp / metadata of
a file from within xfsrestore?

If not, then I don't think it will be possible to tell what about that
file may have been problematic.  The data in the file is pretty static,
and it's basically the database information that MythTV uses.  That is,
the hostname, username, and password for the MySQL database, and that's
about it.  Those things don't change.  There is also no open handle for
that file when the system is running.  It's just read in once on system
startup.

I replaced the file with a file-level backup that I had from over 3
years ago, and the system is now fine.  My faith in xfsdump is what I'm
still trying to repair.  :)


-WD

Re: Silent skipping of file during xfsrestore

[Eric Sandeen]

On 11/28/16 10:43 AM, Will Dormann wrote:
> On 11/28/16 11:32 AM, Eric Sandeen wrote:
>> There is no explicit check on boot for xfs, so nothing would happen there.
> 
> Yeah, I thought that was the case.  Just wanted to make sure.
> 
> 
>> Can you check timestamps on the file to be sure that your assumption
>> that it's not getting written is correct?  I know cups likes to write
>> and rewrite config files even if no changes occur, for example.
> 
> The problem is that I wiped the target partition clean before doing the
> xfsrestore.   So the only copy that could be present anywhere is in the
> xfsdump backups.    Is it possible to check the timestamp / metadata of
> a file from within xfsrestore?
> 
> If not, then I don't think it will be possible to tell what about that
> file may have been problematic.  The data in the file is pretty static,
> and it's basically the database information that MythTV uses.  That is,
> the hostname, username, and password for the MySQL database, and that's
> about it.  Those things don't change.  There is also no open handle for
> that file when the system is running.  It's just read in once on system
> startup.
> 
> I replaced the file with a file-level backup that I had from over 3
> years ago, and the system is now fine.  My faith in xfsdump is what I'm
> still trying to repair.  :)

Yep, understood.  I guess that's why part of a good backup strategy is to
test your backups.  ;)

Maybe watch the existing config file on your rebuilt box to see if timestamps
change; otherwise I don't really know what to say about why it was skipped,
if there's nothing in the xfsdump logs from before.

-Eric

> 
> -WD
>