File Restore ok from WebGui , but error on log files

Bug
,
1

I’ve found a new issue…I’m trying to restore a complete folder from backup on a cifs attached NAS.

Restore complete without error on gui (green msg, it’s all ok) BUT if i check on log files :

/var/log/restore-data.log:
2018-05-08 13:39:18 - ERROR - Restore failed, see /var/log/restore.log for details - 4864
2018-05-08 13:42:11 - ERROR - Restore failed, see /var/log/restore.log for details - 4864

/var/log/restore.log:
Local and Remote metadata are synchronized, no sync needed.
Last full backup date: Tue May 8 01:00:12 2018
–file-to-restore not found in archive - no files restored.
Local and Remote metadata are synchronized, no sync needed.
Last full backup date: Tue May 8 01:00:12 2018

The weird issue is that restored folder (and its content) are in place (i’ve also verified md5sum against original files to be sure) and safe.

It happens with booth “Restore files in the original path” or “Restore files in new directory” options.
I’ve also tried to restore folders with and without space in their name. Same bevahviour. Also tried with different file sizes, owner/group and so on…

Any ideas? Is there any other log file I could check out to address this issue ?

Regards

Paolo

1 Like
2

Hi, just a quick update:

same behaviour on bash with :

[root@nethserver ~]# restore-file /tmp/test /var/lib/nethserver/home/XXXX

/var/log/restore-data.log:

2018-05-09 07:57:39 - ERROR - Restore failed, see /var/log/restore.log for details - 4864

no usefull infos on /var/log/restore.log:

Local and Remote metadata are synchronized, no sync needed.
Last full backup date: Wed May 9 01:00:14 2018

All restored files and folders (with right permissions) are in place so restore procedure is working well…but why that error on logs ?

Using :
Nethserver 7.4 full updated

Installed Packages:
nethserver-backup-data-1.3.3-1.ns7.noarch
File Server Module

Thx

Paolo

3

Hi, this is what happens under the hood with:

[root@nethserver ~]# restore-file tmp/ /var/lib/nethserver/ibay/disegni/disegno1.jpg

three processes, one parent, two child (from ps aux|grep dup) :

root 8200 1.4 0.4 180524 17840 pts/0 S+ 09:29 0:00 /usr/bin/perl -w /etc/e-smith/events/actions/restore-data-duplicity tmp/ --file-to-restore var/lib/nethserver/ibay/disegni/disegno1.jpg

root 8201 0.0 0.0 113128 1200 pts/0 S+ 09:29 0:00 sh -c /usr/bin/duplicity restore --no-encryption --archive-dir /var/lib/nethserver/backup/duplicity/ --file-to-restore ‘–file-to-restore’ file:///mnt/backup/nethserver tmp//’–file-to-restore’ &>>/var/log/restore.log

root 8202 5.5 0.3 303336 15140 pts/0 D+ 09:29 0:00 python2 /usr/bin/duplicity restore --no-encryption --archive-dir /var/lib/nethserver/backup/duplicity/ --file-to-restore --file-to-restore file:///mnt/backup/nethserver tmp//–file-to-restore

variable ‘–file-to-restore’ should be ‘var/lib/nethserver/ibay/disegni/disegno1.jpg’ and not ‘–file-to-restore’

let me know

4

@giacomo Could you help here?

5

Ok, I got it ! It’s a Bug. Let me explain :

/etc/e-smith/events/actions/restore-data-duplicity

Just add a printout like

print $_."\n";
print $cmd."\n";

on for each @file cycle so restore-data-duplicity become:

} else {
make_path("$position/$directories");
$cmd .= " --file-to-restore ‘$’ $src $position/’$’";
print $_."\n";
print $cmd."\n";
}

launch from shell :

[root@nethserver ~]# /etc/e-smith/events/actions/restore-data-duplicity tmp/ --file-to-restore var/lib/nethserver/ibay/disegni/disegno1.jpg

results :

–file-to-restore
/usr/bin/duplicity restore --no-encryption --archive-dir /var/lib/nethserver/backup/duplicity/ --file-to-restore ‘–file-to-restore’ file:///mnt/backup/nethserver tmp//’–file-to-restore’

var/lib/nethserver/ibay/disegni/disegno1.jpg
/usr/bin/duplicity restore --no-encryption --archive-dir /var/lib/nethserver/backup/duplicity/ --file-to-restore ‘var/lib/nethserver/ibay/disegni/disegno1.jpg’ file:///mnt/backup/nethserver tmp//‘var/lib/nethserver/ibay/disegni/disegno1.jpg’

script considers ‘–file-to-restore’ as an argument (aka filename to restore).

So first script throws out an error to log due to fact that “–file-to-restore” doesn’t exits and finally it restores the correct file.

And this is why I always found correct file restored.

So:
/etc/e-smith/events/actions/restore-data-duplicity takes only filenames as argument (as indicated by -h flag) so if i launch:

/etc/e-smith/events/actions/restore-data-duplicity tmp/ var/lib/nethserver/ibay/disegni/disegno1.jpg

it works great without error.

Problem (imho) is on restore-file script that gives --file-to-restore as argument to restore-data-duplicity perl script:

[root@nethserver ~]# restore-file tmp/ var/lib/nethserver/ibay/disegni/disegno1.jpg
–file-to-restore
/usr/bin/duplicity restore --no-encryption --archive-dir /var/lib/nethserver/backup/duplicity/ --file-to-restore ‘–file-to-restore’ file:///mnt/backup/nethserver tmp//’–file-to-restore’

var/lib/nethserver/ibay/disegni/disegno1.jpg
/usr/bin/duplicity restore --no-encryption --archive-dir /var/lib/nethserver/backup/duplicity/ --file-to-restore ‘var/lib/nethserver/ibay/disegni/disegno1.jpg’ file:///mnt/backup/nethserver tmp//‘var/lib/nethserver/ibay/disegni/disegno1.jpg’

fix proposal:

original:
foreach (@files) {
push(@args, ‘–file-to-restore’);
push(@args, $_);
}

fix:
foreach (@files) {
push(@args, $_);
}

King Regards

Paolo

2 Likes
6

Hi everyone,

any feedback about this issue/fix ?

Thx in advance

Paolo

7

@dev_team What do you think? Could you do something?

1 Like
8

Well thank you for reminding us this Bug!

Great analysis @pfornara, I guess @giacomo is quite busy, but will be back on this soon! Thanks again for your detailed report!

Can you always reproduce the same error with any file name? If so, can it be caused by a recent duplicity update?

Added a card here NethServer 7 · GitHub

1 Like
9

Hi Michael, Davide,

thank you so much for your feedback.

  • I can reproduce this with every folder/file_name; it’s not related to file paths or names.

  • It’s not related to any duplicity upgrade. Please take a look to /etc/e-smith/events/actions/restore-data-duplicity script. It takes only filenames as argument and not “–file-to-restore” flag.

    • /etc/e-smith/events/actions/restore-data-duplicity has already “–file-to-restore” hardcoded inside (lines #99 and #102). So you do not need to pass it as argument.
      Maybe someone has forgotten to remove this flag inside restore-file script during some scripts refactoring in the past.

GUI Fronted give all ok as described in my previous post. So it was hard to find it out on first analysis. But actually I’m doing a huge AD migration so I look on every error on logs side. I noticed it for this reason mainly.

my 2c

regards

paolo

3 Likes
10

You just opened a Pandora’s box! :man_facepalming:

I filed two different bugs:

If you’re willing to test it, let me know about the results!

(Please bear in mind that all packages are automatically published inside 7.5 branch).

1 Like
11

therefore @pfornara wins the “bug hunter” badge :smiley:

5 Likes